anr-bmbf-pivot / pylibschc Goto Github PK
View Code? Open in Web Editor NEWA python wrapper for libSCHC
Home Page: https://anr-bmbf-pivot.github.io/pylibschc
License: GNU General Public License v3.0
A python wrapper for libSCHC
Home Page: https://anr-bmbf-pivot.github.io/pylibschc
License: GNU General Public License v3.0
Currently (215a328), there is a use after free when trying to determine if a schc_fragmentation_t
, represented by the FragmentationConnection class, is still allocated:
==3139== Invalid read of size 8
==3139== at 0x93CEC0D: __Pyx_PyBool_FromLong (libschc.c:27970)
==3139== by 0x93CEC0D: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_12_allocated (libschc.c:13609)
==3139== by 0x93CEC0D: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_13_allocated (libschc.c:13573)
==3139== by 0x93C879B: __Pyx_PyObject_CallMethO (libschc.c:22503)
==3139== by 0x93C879B: __Pyx_PyObject_CallNoArg (libschc.c:23781)
==3139== by 0x93C879B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task__timer_task_wrapper (libschc.c:14733)
==3139== by 0x93C879B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task_1_timer_task_wrapper (libschc.c:14685)
==3139== by 0x49B0CFE: _PyObject_MakeTpCall (call.c:215)
==3139== by 0x4A1799C: call_function (ceval.c:5888)
==3139== by 0x4A1799C: _PyEval_EvalFrameDefault (ceval.c:4213)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== by 0x4A13A75: do_call_core (ceval.c:5943)
==3139== by 0x4A13A75: _PyEval_EvalFrameDefault (ceval.c:4277)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A179EB: call_function (ceval.c:5888)
==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== by 0x4A11550: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A11550: PyObject_Vectorcall (abstract.h:123)
==3139== by 0x4A11550: call_function (ceval.c:5891)
==3139== by 0x4A11550: _PyEval_EvalFrameDefault (ceval.c:4198)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== Address 0x6acbac0 is 112 bytes inside a block of size 168 free'd
==3139== at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==3139== by 0x93BE825: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_28reset (libschc.c:17588)
==3139== by 0x93BE825: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_29reset (libschc.c:17558)
==3139== by 0x93C7941: __Pyx_PyObject_CallMethO (libschc.c:22503)
==3139== by 0x93C7941: __Pyx_PyObject_CallNoArg (libschc.c:23781)
==3139== by 0x93C7941: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__reassemble (libschc.c:17372)
==3139== by 0x93C2F6E: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_26reassemble (libschc.c:17519)
==3139== by 0x93C2F6E: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_27reassemble (libschc.c:17495)
==3139== by 0x49D6CE4: cfunction_vectorcall_NOARGS (methodobject.c:489)
==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
==3139== by 0x4A179EB: call_function (ceval.c:5888)
==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A179EB: call_function (ceval.c:5888)
==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== Block was alloc'd at
==3139== at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==3139== by 0x93E79E9: schc_get_connection (fragmenter.c:1319)
==3139== by 0x93E9851: schc_fragment_input (fragmenter.c:2367)
==3139== by 0x93DA17E: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__input (libschc.c:16623)
==3139== by 0x93C4F1B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_24input (libschc.c:17085)
==3139== by 0x93C4F1B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_25input (libschc.c:16994)
==3139== by 0x49D6DB6: cfunction_vectorcall_O (methodobject.c:516)
==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
==3139== by 0x4A179EB: call_function (ceval.c:5888)
==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
==3139== by 0x4A179EB: call_function (ceval.c:5888)
==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
At the moment, this is not easily fixable as the free()
happens internally in libSCHC, with pylibschc having no real way to determine this beforehand or after (except with the use after free). Some hook in libSCHC that is triggered just before free, might help fixing this issue.
2023-02-03T20:19:02.0195029Z ##[group]Run tox -e valgrind
2023-02-03T20:19:02.0195357Z tox -e valgrind
2023-02-03T20:19:02.0258522Z shell: /usr/bin/bash -e {0}
2023-02-03T20:19:02.0258818Z env:
2023-02-03T20:19:02.0259132Z pythonLocation: /opt/hostedtoolcache/Python/3.10.9/x64
2023-02-03T20:19:02.0259545Z PKG_CONFIG_PATH: /opt/hostedtoolcache/Python/3.10.9/x64/lib/pkgconfig
2023-02-03T20:19:02.0259947Z Python_ROOT_DIR: /opt/hostedtoolcache/Python/3.10.9/x64
2023-02-03T20:19:02.0260308Z Python2_ROOT_DIR: /opt/hostedtoolcache/Python/3.10.9/x64
2023-02-03T20:19:02.0260682Z Python3_ROOT_DIR: /opt/hostedtoolcache/Python/3.10.9/x64
2023-02-03T20:19:02.0261060Z LD_LIBRARY_PATH: /opt/hostedtoolcache/Python/3.10.9/x64/lib
2023-02-03T20:19:02.0261347Z ##[endgroup]
2023-02-03T20:19:03.3954277Z valgrind: install_deps> python -I -m pip install pytest pytest-asyncio pytest-cov scapy .
2023-02-03T20:19:31.1778733Z .pkg: install_requires> python -I -m pip install Cython 'setuptools>=42' wheel
2023-02-03T20:19:34.3033576Z .pkg: _optional_hooks> python /opt/hostedtoolcache/Python/3.10.9/x64/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-02-03T20:19:34.8747942Z .pkg: get_requires_for_build_sdist> python /opt/hostedtoolcache/Python/3.10.9/x64/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-02-03T20:19:34.8914610Z .pkg: install_requires_for_build_sdist> python -I -m pip install Cython 'setuptools>=42' wheel
2023-02-03T20:19:35.6353074Z .pkg: freeze> python -m pip freeze --all
2023-02-03T20:19:36.1194753Z .pkg: Cython==0.29.33,pip==22.3.1,setuptools==65.6.3,wheel==0.38.4
2023-02-03T20:19:36.1198276Z .pkg: prepare_metadata_for_build_wheel> python /opt/hostedtoolcache/Python/3.10.9/x64/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-02-03T20:19:37.6257302Z .pkg: build_sdist> python /opt/hostedtoolcache/Python/3.10.9/x64/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-02-03T20:19:41.8078848Z valgrind: install_package_deps> python -I -m pip install Cython pydantic
2023-02-03T20:19:42.6637230Z valgrind: install_package> python -I -m pip install --force-reinstall --no-deps /home/runner/work/pylibschc/pylibschc/.tox/.tmp/package/1/pylibschc-0.0.1a0.tar.gz
2023-02-03T20:20:00.7636641Z valgrind: freeze> python -m pip freeze --all
2023-02-03T20:20:01.2866874Z valgrind: attrs==22.2.0,coverage==7.1.0,Cython==0.29.33,exceptiongroup==1.1.0,iniconfig==2.0.0,packaging==23.0,pip==22.3.1,pluggy==1.0.0,pydantic==1.10.4,pylibschc @ file:///home/runner/work/pylibschc/pylibschc/.tox/.tmp/package/1/pylibschc-0.0.1a0.tar.gz,pytest==7.2.1,pytest-asyncio==0.20.3,pytest-cov==4.0.0,scapy==2.5.0,setuptools==65.6.3,tomli==2.0.1,typing_extensions==4.4.0,wheel==0.38.4
2023-02-03T20:20:01.2894030Z valgrind: commands[0]> valgrind --suppressions=/home/runner/work/pylibschc/pylibschc/valgrind-python.supp --leak-check=full --show-leak-kinds=definite --show-error-list=yes --track-origins=yes /home/runner/work/pylibschc/pylibschc/.tox/valgrind/bin/python /home/runner/work/pylibschc/pylibschc/.tox/valgrind/bin/pytest --cov=/home/runner/work/pylibschc/pylibschc/.tox/valgrind/lib/python3.10/site-packages/pylibschc --log-cli-level=DEBUG -k 'not README.rst'
2023-02-03T20:20:01.3055839Z ==3139== Memcheck, a memory error detector
2023-02-03T20:20:01.3068274Z ==3139== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
2023-02-03T20:20:01.3069353Z ==3139== Using Valgrind-3.18.1 and LibVEX; rerun with -h for copyright info
2023-02-03T20:20:01.3070442Z ==3139== Command: /home/runner/work/pylibschc/pylibschc/.tox/valgrind/bin/python /home/runner/work/pylibschc/pylibschc/.tox/valgrind/bin/pytest --cov=/home/runner/work/pylibschc/pylibschc/.tox/valgrind/lib/python3.10/site-packages/pylibschc --log-cli-level=DEBUG -k not\ README.rst
2023-02-03T20:20:01.3072133Z ==3139==
2023-02-03T20:22:00.1034402Z ============================= test session starts ==============================
2023-02-03T20:22:00.1035641Z platform linux -- Python 3.10.9, pytest-7.2.1, pluggy-1.0.0
2023-02-03T20:22:00.1087747Z cachedir: .tox/valgrind/.pytest_cache
2023-02-03T20:22:00.1088231Z rootdir: /home/runner/work/pylibschc/pylibschc, configfile: setup.cfg, testpaths: README.rst, tests/
2023-02-03T20:22:00.1088831Z plugins: cov-4.0.0, asyncio-0.20.3
2023-02-03T20:22:00.1089092Z asyncio: mode=strict
2023-02-03T20:22:00.1089381Z collected 85 items / 1 deselected / 84 selected
2023-02-03T20:22:00.1089570Z
2023-02-03T20:22:02.0617158Z tests/test_bitarray.py::test_bit_array PASSED [ 1%]
2023-02-03T20:22:02.2399877Z tests/test_bitarray.py::test_bit_array_get_bits PASSED [ 2%]
2023-02-03T20:22:02.4003376Z tests/test_bitarray.py::test_bit_array_copy_bits PASSED [ 3%]
2023-02-03T20:22:04.3449237Z tests/test_compressor.py::test_compressor_reassembler_init_error PASSED [ 4%]
2023-02-03T20:22:06.0836071Z tests/test_compressor.py::test_compressor_reassembler_io_type_error PASSED [ 5%]
2023-02-03T20:22:07.3129545Z tests/test_compressor.py::test_compressor_reassembler[uncompressed rule, UP]
2023-02-03T20:22:07.3130909Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:07.3131729Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:07.3363278Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:07.3495059Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:07.3644021Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 03, IPv6 Next Header does not match
2023-02-03T20:22:07.3839692Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_coap_rule_from_header(): invalid CoAP packet
2023-02-03T20:22:07.3993257Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): no rule was found
2023-02-03T20:22:07.4137937Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:07.4273268Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 328 compressed header bits + 0 payload bits + 0 padding bits = 328 bits (41B)
2023-02-03T20:22:07.4402299Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:07.4529621Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:07.4661070Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:07.4819404Z DEBUG pylibschc.libschc:compressor.py:49 14 60 00 00 00 00 00 3B 40 00 00 00
2023-02-03T20:22:07.4972426Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:07.5110771Z DEBUG pylibschc.libschc:compressor.py:49 01 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:07.5243996Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 01
2023-02-03T20:22:07.5647781Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:07.5777806Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:07.5906627Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:07.6039853Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 03, IPv6 Next Header does not match
2023-02-03T20:22:07.6168527Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_coap_rule_from_header(): invalid CoAP packet
2023-02-03T20:22:07.6299907Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): no rule was found
2023-02-03T20:22:07.6459643Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:07.6643183Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 328 compressed header bits + 0 payload bits + 0 padding bits = 328 bits (41B)
2023-02-03T20:22:07.6770720Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:07.6895760Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:07.7023208Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:07.7161432Z DEBUG pylibschc.libschc:compressor.py:49 14 60 00 00 00 00 00 3B 40 00 00 00
2023-02-03T20:22:07.7302034Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:07.7438889Z DEBUG pylibschc.libschc:compressor.py:49 01 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:07.7571467Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 01
2023-02-03T20:22:07.7789453Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:07.7920628Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:07.8057879Z DEBUG pylibschc.libschc:compressor.py:58 no rule was found
2023-02-03T20:22:07.8204377Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 0, payload length 40
2023-02-03T20:22:07.8331600Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:07.8469817Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:07.8599338Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:07.8733261Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:07.8885018Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 00 3B 40 00 00 00 00
2023-02-03T20:22:07.9028626Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:07.9168596Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:07.9299620Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01
2023-02-03T20:22:07.9300572Z
2023-02-03T20:22:07.9442470Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:07.9568189Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:07.9695367Z DEBUG pylibschc.libschc:compressor.py:58 no rule was found
2023-02-03T20:22:07.9829805Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 0, payload length 40
2023-02-03T20:22:07.9957028Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:08.0087439Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:08.0220572Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:08.0349446Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:08.0488258Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 00 3B 40 00 00 00 00
2023-02-03T20:22:08.0627136Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:08.0765698Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:08.0898787Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01
2023-02-03T20:22:08.0899383Z
2023-02-03T20:22:08.7652379Z PASSED [ 7%]
2023-02-03T20:22:09.9785405Z tests/test_compressor.py::test_compressor_reassembler[uncompressed rule, DOWN]
2023-02-03T20:22:09.9786467Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:09.9786997Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:09.9936113Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:10.0066656Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:10.0197130Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 03, IPv6 Next Header does not match
2023-02-03T20:22:10.0331873Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_coap_rule_from_header(): invalid CoAP packet
2023-02-03T20:22:10.0467410Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): no rule was found
2023-02-03T20:22:10.0601993Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:10.0734368Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 328 compressed header bits + 0 payload bits + 0 padding bits = 328 bits (41B)
2023-02-03T20:22:10.0867580Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:10.1003027Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:10.1134462Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:10.1279461Z DEBUG pylibschc.libschc:compressor.py:49 14 60 00 00 00 00 00 3B 40 00 00 00
2023-02-03T20:22:10.1426514Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.1572273Z DEBUG pylibschc.libschc:compressor.py:49 01 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.1712119Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 01
2023-02-03T20:22:10.2119859Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:10.2252747Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:10.2383865Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:10.2519716Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 03, IPv6 Next Header does not match
2023-02-03T20:22:10.2652788Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_coap_rule_from_header(): invalid CoAP packet
2023-02-03T20:22:10.2786262Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): no rule was found
2023-02-03T20:22:10.2918780Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:10.3051903Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 328 compressed header bits + 0 payload bits + 0 padding bits = 328 bits (41B)
2023-02-03T20:22:10.3183561Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:10.3316286Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:10.3448064Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:10.3591188Z DEBUG pylibschc.libschc:compressor.py:49 14 60 00 00 00 00 00 3B 40 00 00 00
2023-02-03T20:22:10.3732554Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.3876332Z DEBUG pylibschc.libschc:compressor.py:49 01 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.4008433Z DEBUG pylibschc.libschc:compressor.py:49 00 00 00 00 01
2023-02-03T20:22:10.4149676Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:10.4279169Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:10.4411710Z DEBUG pylibschc.libschc:compressor.py:58 no rule was found
2023-02-03T20:22:10.4551564Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 0, payload length 40
2023-02-03T20:22:10.4685968Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:10.4817569Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:10.4950432Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:10.5082566Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:10.5223848Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 00 3B 40 00 00 00 00
2023-02-03T20:22:10.5370871Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:10.5512169Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.5647522Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01
2023-02-03T20:22:10.5648510Z
2023-02-03T20:22:10.5790852Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:10.5928837Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:10.6061374Z DEBUG pylibschc.libschc:compressor.py:58 no rule was found
2023-02-03T20:22:10.6190913Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 0, payload length 40
2023-02-03T20:22:10.6321326Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:10.6451049Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:10.6583047Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:10.6712610Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:10.6859635Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 00 3B 40 00 00 00 00
2023-02-03T20:22:10.7006131Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:10.7151052Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:10.7280999Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01
2023-02-03T20:22:10.7281586Z
2023-02-03T20:22:11.3960803Z PASSED [ 8%]
2023-02-03T20:22:13.2887523Z tests/test_compressor.py::test_compressor_reassembler[3rd rule, ICMPv6, UP]
2023-02-03T20:22:13.2888935Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:13.2890421Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:13.3023011Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:13.3152466Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:13.3288931Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6990bf0
2023-02-03T20:22:13.3490705Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:13.3624845Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 160 payload bits + 3 padding bits = 176 bits (22B)
2023-02-03T20:22:13.3794430Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:13.3925102Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:13.4064329Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:13.4220808Z DEBUG pylibschc.libschc:compressor.py:49 03 B4 00 06 81 0F 02 A4 02 32 43 2B
2023-02-03T20:22:13.4359496Z DEBUG pylibschc.libschc:compressor.py:49 63 63 79 02 BB 7B 93 63 21 08
2023-02-03T20:22:13.5180801Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:13.5312302Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:13.5442602Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:13.5573221Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6990bf0
2023-02-03T20:22:13.5707386Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:13.5840322Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 160 payload bits + 3 padding bits = 176 bits (22B)
2023-02-03T20:22:13.5973349Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:13.6109981Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:13.6241789Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:13.6381992Z DEBUG pylibschc.libschc:compressor.py:49 03 B4 00 06 81 0F 02 A4 02 32 43 2B
2023-02-03T20:22:13.6520966Z DEBUG pylibschc.libschc:compressor.py:49 63 63 79 02 BB 7B 93 63 21 08
2023-02-03T20:22:13.6667473Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:13.6796569Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:13.6931029Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x4f2b100
2023-02-03T20:22:13.7059814Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6990fc0
2023-02-03T20:22:13.7194477Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x7965030
2023-02-03T20:22:13.7321480Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6990bf0
2023-02-03T20:22:13.7495289Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 40, payload length 20
2023-02-03T20:22:13.7623088Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:13.7751388Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:13.7878084Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:13.8006690Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:13.8152834Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 14 3A 40 FE 80 00 00
2023-02-03T20:22:13.8295050Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:13.8436803Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:13.8572218Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 02 80 00 D0 21 E0 54 80 46
2023-02-03T20:22:13.8712090Z DEBUG pylibschc.libschc:compressor.py:58 48 65 6C 6C 6F 20 57 6F 72 6C 64 21
2023-02-03T20:22:13.8839587Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:13.8840188Z
2023-02-03T20:22:13.8975564Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:13.9104305Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:13.9289783Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x4f2b100
2023-02-03T20:22:13.9423428Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6990fc0
2023-02-03T20:22:13.9558494Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x7965030
2023-02-03T20:22:13.9684955Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6990bf0
2023-02-03T20:22:13.9815767Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 40, payload length 20
2023-02-03T20:22:13.9955801Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:14.0085458Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:14.0220208Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:14.0353423Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:14.0499410Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 14 3A 40 FE 80 00 00
2023-02-03T20:22:14.0644052Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:14.0792388Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:14.0936810Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 02 80 00 D0 21 E0 54 80 46
2023-02-03T20:22:14.1080317Z DEBUG pylibschc.libschc:compressor.py:58 48 65 6C 6C 6F 20 57 6F 72 6C 64 21
2023-02-03T20:22:14.1215132Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:14.1215561Z
2023-02-03T20:22:14.8412155Z PASSED [ 9%]
2023-02-03T20:22:16.6755321Z tests/test_compressor.py::test_compressor_reassembler[3rd rule, ICMPv6, DOWN]
2023-02-03T20:22:16.6756384Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:16.6756841Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:16.6882433Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:16.7013141Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:16.7152362Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6225e70
2023-02-03T20:22:16.7286732Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:16.7451135Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 160 payload bits + 3 padding bits = 176 bits (22B)
2023-02-03T20:22:16.7630020Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:16.7779551Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:16.7907963Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:16.8051029Z DEBUG pylibschc.libschc:compressor.py:49 03 B4 08 06 79 0F 02 A4 02 32 43 2B
2023-02-03T20:22:16.8192998Z DEBUG pylibschc.libschc:compressor.py:49 63 63 79 02 BB 7B 93 63 21 08
2023-02-03T20:22:16.9073592Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:16.9215663Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Next Header does not match
2023-02-03T20:22:16.9348703Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Next Header does not match
2023-02-03T20:22:16.9478965Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6225e70
2023-02-03T20:22:16.9611242Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:16.9742830Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 160 payload bits + 3 padding bits = 176 bits (22B)
2023-02-03T20:22:16.9876297Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:17.0006126Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:17.0134254Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:17.0280615Z DEBUG pylibschc.libschc:compressor.py:49 03 B4 08 06 79 0F 02 A4 02 32 43 2B
2023-02-03T20:22:17.0420859Z DEBUG pylibschc.libschc:compressor.py:49 63 63 79 02 BB 7B 93 63 21 08
2023-02-03T20:22:17.0573895Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.0712547Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:17.0845185Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x7a071a0
2023-02-03T20:22:17.0977158Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6226240
2023-02-03T20:22:17.1109586Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x5081250
2023-02-03T20:22:17.1242850Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6225e70
2023-02-03T20:22:17.1381440Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 40, payload length 20
2023-02-03T20:22:17.1512974Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.1641440Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:17.1770447Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:17.1903003Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:17.2047815Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 14 3A 40 FE 80 00 00
2023-02-03T20:22:17.2188310Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 02
2023-02-03T20:22:17.2332013Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:17.2481266Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01 81 00 CF 21 E0 54 80 46
2023-02-03T20:22:17.2626120Z DEBUG pylibschc.libschc:compressor.py:58 48 65 6C 6C 6F 20 57 6F 72 6C 64 21
2023-02-03T20:22:17.2753002Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.2753545Z
2023-02-03T20:22:17.2889438Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.3018999Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:17.3149677Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x7a071a0
2023-02-03T20:22:17.3278197Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6226240
2023-02-03T20:22:17.3413122Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x5081250
2023-02-03T20:22:17.3541826Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6225e70
2023-02-03T20:22:17.3670355Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 40, payload length 20
2023-02-03T20:22:17.3800667Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.3968067Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:17.4060007Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:17.4190036Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:17.4333236Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 14 3A 40 FE 80 00 00
2023-02-03T20:22:17.4472635Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 02
2023-02-03T20:22:17.4615180Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:17.4756944Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01 81 00 CF 21 E0 54 80 46
2023-02-03T20:22:17.4894146Z DEBUG pylibschc.libschc:compressor.py:58 48 65 6C 6C 6F 20 57 6F 72 6C 64 21
2023-02-03T20:22:17.5023130Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:17.5023745Z
2023-02-03T20:22:18.2095928Z PASSED [ 10%]
2023-02-03T20:22:20.0794563Z tests/test_compressor.py::test_compressor_reassembler[3rd rule, CoAP, UP]
2023-02-03T20:22:20.0795637Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:20.0796191Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:20.0926007Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Device Prefix does not match
2023-02-03T20:22:20.1058925Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Device Prefix does not match
2023-02-03T20:22:20.1193647Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6dfcdd0
2023-02-03T20:22:20.1331523Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, UDP Device Port does not match
2023-02-03T20:22:20.1459734Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, UDP Device Port does not match
2023-02-03T20:22:20.1601963Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): UDP rule ptr=0x4f97a90
2023-02-03T20:22:20.1791114Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, CoAP Token Length does not match
2023-02-03T20:22:20.1924756Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, CoAP Token Length does not match
2023-02-03T20:22:20.2062158Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): CoAP rule ptr=0x6dfd1a0
2023-02-03T20:22:20.2210310Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:20.2364738Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 0 payload bits + 3 padding bits = 16 bits (2B)
2023-02-03T20:22:20.2493314Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:20.2627289Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:20.2758971Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:20.2891431Z DEBUG pylibschc.libschc:compressor.py:49 03 30
2023-02-03T20:22:20.3969017Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:20.4107371Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Device Prefix does not match
2023-02-03T20:22:20.4238067Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Device Prefix does not match
2023-02-03T20:22:20.4369560Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x6dfcdd0
2023-02-03T20:22:20.4498572Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, UDP Device Port does not match
2023-02-03T20:22:20.4632186Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, UDP Device Port does not match
2023-02-03T20:22:20.4762046Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): UDP rule ptr=0x4f97a90
2023-02-03T20:22:20.4903583Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, CoAP Token Length does not match
2023-02-03T20:22:20.5040044Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, CoAP Token Length does not match
2023-02-03T20:22:20.5177368Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): CoAP rule ptr=0x6dfd1a0
2023-02-03T20:22:20.5304773Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:20.5438441Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 0 payload bits + 3 padding bits = 16 bits (2B)
2023-02-03T20:22:20.5569688Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:20.5701182Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:20.5830199Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:20.5964542Z DEBUG pylibschc.libschc:compressor.py:49 03 30
2023-02-03T20:22:20.6105379Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:20.6235220Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:20.6364570Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x7479040
2023-02-03T20:22:20.6500037Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6dfd1a0
2023-02-03T20:22:20.6673589Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x4f97a90
2023-02-03T20:22:20.6802787Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6dfcdd0
2023-02-03T20:22:20.7035251Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 52, payload length 0
2023-02-03T20:22:20.7159056Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:20.7292748Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:20.7434166Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:20.7564567Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:20.7705623Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 0C 11 40 FE 80 00 00
2023-02-03T20:22:20.7847744Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:20.7988773Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:20.8129879Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 02 13 89 13 88 00 0C 9B C0
2023-02-03T20:22:20.8264167Z DEBUG pylibschc.libschc:compressor.py:58 40 00 00 00
2023-02-03T20:22:20.8264720Z
2023-02-03T20:22:20.8398789Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:20.8530722Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:20.8660789Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x7479040
2023-02-03T20:22:20.8792773Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x6dfd1a0
2023-02-03T20:22:20.8924758Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x4f97a90
2023-02-03T20:22:20.9056982Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x6dfcdd0
2023-02-03T20:22:20.9187769Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 52, payload length 0
2023-02-03T20:22:20.9317489Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:20.9446671Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:20.9572655Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:20.9695366Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:20.9837834Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 0C 11 40 FE 80 00 00
2023-02-03T20:22:20.9977195Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 01
2023-02-03T20:22:21.0121605Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:21.0258366Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 02 13 89 13 88 00 0C 9B C0
2023-02-03T20:22:21.0387352Z DEBUG pylibschc.libschc:compressor.py:58 40 00 00 00
2023-02-03T20:22:21.0387774Z
2023-02-03T20:22:21.7665919Z PASSED [ 11%]
2023-02-03T20:22:23.6340563Z tests/test_compressor.py::test_compressor_reassembler[3rd rule, CoAP, DOWN]
2023-02-03T20:22:23.6342039Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:23.6342864Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:23.6477938Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Device Prefix does not match
2023-02-03T20:22:23.6611554Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Device Prefix does not match
2023-02-03T20:22:23.6742270Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x7360840
2023-02-03T20:22:23.6871936Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, UDP Device Port does not match
2023-02-03T20:22:23.7003140Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, UDP Device Port does not match
2023-02-03T20:22:23.7147184Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): UDP rule ptr=0x6280d00
2023-02-03T20:22:23.7285046Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, CoAP Token Length does not match
2023-02-03T20:22:23.7420769Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, CoAP Token Length does not match
2023-02-03T20:22:23.7558721Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): CoAP rule ptr=0x7360c10
2023-02-03T20:22:23.7694427Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:23.7830267Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 0 payload bits + 3 padding bits = 16 bits (2B)
2023-02-03T20:22:23.7960962Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:23.8093262Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:23.8223503Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:23.8358877Z DEBUG pylibschc.libschc:compressor.py:49 03 30
2023-02-03T20:22:23.9409125Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress():
2023-02-03T20:22:23.9545152Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, IPv6 Device Prefix does not match
2023-02-03T20:22:23.9675115Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, IPv6 Device Prefix does not match
2023-02-03T20:22:23.9808143Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): IPv6 rule ptr=0x7360840
2023-02-03T20:22:23.9937994Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, UDP Device Port does not match
2023-02-03T20:22:24.0075219Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, UDP Device Port does not match
2023-02-03T20:22:24.0207316Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): UDP rule ptr=0x6280d00
2023-02-03T20:22:24.0340827Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 01, CoAP Token Length does not match
2023-02-03T20:22:24.0477529Z DEBUG pylibschc.libschc:compressor.py:49 schc_find_rule_from_header(): skipped rule 02, CoAP Token Length does not match
2023-02-03T20:22:24.0654737Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): CoAP rule ptr=0x7360c10
2023-02-03T20:22:24.0785474Z DEBUG pylibschc.libschc:compressor.py:49
2023-02-03T20:22:24.0914076Z DEBUG pylibschc.libschc:compressor.py:49 schc_compress(): 13 compressed header bits + 0 payload bits + 3 padding bits = 16 bits (2B)
2023-02-03T20:22:24.1045483Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:24.1175698Z DEBUG pylibschc.libschc:compressor.py:49 | SCHC Packet |
2023-02-03T20:22:24.1305899Z DEBUG pylibschc.libschc:compressor.py:49 +---------------------------------+
2023-02-03T20:22:24.1443632Z DEBUG pylibschc.libschc:compressor.py:49 03 30
2023-02-03T20:22:24.1588452Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:24.1716036Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:24.1844568Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x6a6ecf0
2023-02-03T20:22:24.1969913Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x7360c10
2023-02-03T20:22:24.2094243Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x6280d00
2023-02-03T20:22:24.2220599Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x7360840
2023-02-03T20:22:24.2350658Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 52, payload length 0
2023-02-03T20:22:24.2476114Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:24.2600292Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:24.2728420Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:24.2857334Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:24.2997580Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 0C 11 40 FE 80 00 00
2023-02-03T20:22:24.3134723Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 02
2023-02-03T20:22:24.3274847Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:24.3413704Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01 13 88 13 89 00 0C 9B C0
2023-02-03T20:22:24.3546696Z DEBUG pylibschc.libschc:compressor.py:58 40 00 00 00
2023-02-03T20:22:24.3547326Z
2023-02-03T20:22:24.3698387Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:24.3823583Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress():
2023-02-03T20:22:24.3949266Z DEBUG pylibschc.libschc:compressor.py:58 get_compression_rule(): curr rule 0x6a6ecf0
2023-02-03T20:22:24.4088485Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): CoAP rule ptr=0x7360c10
2023-02-03T20:22:24.4211816Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): UDP rule ptr=0x6280d00
2023-02-03T20:22:24.4340795Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): IPv6 rule ptr=0x7360840
2023-02-03T20:22:24.4532733Z DEBUG pylibschc.libschc:compressor.py:58 schc_decompress(): header length: 52, payload length 0
2023-02-03T20:22:24.4675982Z DEBUG pylibschc.libschc:compressor.py:58
2023-02-03T20:22:24.4808373Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:24.4949898Z DEBUG pylibschc.libschc:compressor.py:58 | Original Packet |
2023-02-03T20:22:24.5085347Z DEBUG pylibschc.libschc:compressor.py:58 +---------------------------------+
2023-02-03T20:22:24.5235147Z DEBUG pylibschc.libschc:compressor.py:58 60 00 00 00 00 0C 11 40 FE 80 00 00
2023-02-03T20:22:24.5383822Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 00 00 00 00 00 00 00 00 02
2023-02-03T20:22:24.5530494Z DEBUG pylibschc.libschc:compressor.py:58 FE 80 00 00 00 00 00 00 00 00 00 00
2023-02-03T20:22:24.5678333Z DEBUG pylibschc.libschc:compressor.py:58 00 00 00 01 13 88 13 89 00 0C 9B C0
2023-02-03T20:22:24.5818843Z DEBUG pylibschc.libschc:compressor.py:58 40 00 00 00
2023-02-03T20:22:24.5819494Z
2023-02-03T20:22:25.3288087Z PASSED [ 13%]
2023-02-03T20:22:25.4074176Z tests/test_debug.py::test_pylog_debug
2023-02-03T20:22:25.4075866Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:25.4076781Z DEBUG pylibschc.libschc:test_debug.py:19 This is a test 12345
2023-02-03T20:22:25.4359464Z DEBUG pylibschc.libschc:test_debug.py:33 This is another test for 42 0xff, but now we print: 7357
2023-02-03T20:22:25.5338616Z PASSED [ 14%]
2023-02-03T20:22:25.6490920Z tests/test_debug.py::test_pylog_debug_buffer_overflow
2023-02-03T20:22:25.6492172Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:25.6500575Z DEBUG pylibschc.libschc:test_debug.py:48 0x00 0x01 0x02 0x03 0x04 0x05 0x06 0x07 0x08 0x09 0x0a 0x0b 0x0c 0x0d 0x0e 0x0f 0x10 0x11 0x12 0x13 0x14 0x15 0x16 0x17 0x18 0x19 0x1a 0x1b 0x1c 0x1d 0x1e 0x1f 0x20 0x21 0x22 0x23 0x24 0x25 0x26 0x27 0x28 0x29 0x2a 0x2b 0x2c 0x2d 0x2e 0x2f 0x30 0x31 0x32 0x33 0x34 0x35 0x36 0x37 0x38 0x39 0x3a 0x3b 0x3c 0x3d 0x3e 0x3f 0x40 0x41 0x42 0x43 0x44 0x45 0x46 0x47 0x48 0x49 0x4a 0x4b 0x4c 0x4d 0x4e 0x4f 0x50 0x51 0x52 0x53 0x54 0x55 0x56 0x57 0x58 0x59 0x5a 0x5b 0x5c 0x5d 0x5e 0x5f 0x60 0x61 0x62 0x63 0x64 0x65 0x66 0x67 0x68 0x69 0x6a 0x6b 0x6c 0x6d 0x6e 0x6f 0x70 0x71 0x72 0x73 0x74 0x75 0x76 0x77 0x78 0x79 0x7a 0x7b 0x7c 0x7d 0x7e 0x7f 0x80 0x81 0x82 0x83 0x84 0x85 0x86 0x87 0x88 0x89 0x8a 0x8b 0x8c 0x8d 0x8e 0x8f 0x90 0x91 0x92 0x93 0x94 0x95 0x96 0x97 0x98 0x99 0x9a 0x9b 0x9c 0x9d 0x9e 0x9f 0xa0 0xa1 0xa2 0xa3 0xa4 0xa5 0xa6 0xa7 0xa8 0xa9 0xaa 0xab 0xac 0xad 0xae 0xaf 0xb0 0xb1 0xb2 0xb3 0xb4 0xb5 0xb6 0xb7 0xb8 0xb9 0xba 0xbb 0xbc 0xbd 0xbe 0xbf 0xc0 0xc1 0xc2 0xc3 0xc4 0xc5 0xc6 0xc7 0xc8 0xc9 0xca 0xcb 0xc
2023-02-03T20:22:25.6721612Z DEBUG pylibschc.libschc:test_debug.py:49 0xcd 0xce 0xcf 0xd0 0xd1 0xd2 0xd3 0xd4 0xd5 0xd6 0xd7 0xd8 0xd9 0xda 0xdb 0xdc 0xdd 0xde 0xdf 0xe0 0xe1 0xe2 0xe3 0xe4 0xe5 0xe6 0xe7 0xe8 0xe9 0xea 0xeb 0xec 0xed 0xee 0xef 0xf0 0xf1 0xf2 0xf3 0xf4 0xf5 0xf6 0xf7 0xf8 0xf9 0xfa 0xfb 0xfc 0xfd 0xfe 0xff 0100
2023-02-03T20:22:25.8095510Z PASSED [ 15%]
2023-02-03T20:22:25.9460770Z tests/test_device.py::test_device_init PASSED [ 16%]
2023-02-03T20:22:26.0863528Z tests/test_device.py::test_device_delete PASSED [ 17%]
2023-02-03T20:22:26.2255431Z tests/test_device.py::test_device_get PASSED [ 19%]
2023-02-03T20:22:26.3896945Z tests/test_device.py::test_device_iter PASSED [ 20%]
2023-02-03T20:22:26.6672669Z tests/test_device.py::test_device_compression_rules PASSED [ 21%]
2023-02-03T20:22:26.8022067Z tests/test_device.py::test_device_device_id PASSED [ 22%]
2023-02-03T20:22:26.9957533Z tests/test_device.py::test_device_fragmentation_rules PASSED [ 23%]
2023-02-03T20:22:27.1577426Z tests/test_device.py::test_device_uncompressed_rule PASSED [ 25%]
2023-02-03T20:22:28.4371025Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.NO_ACK-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:22:28.4372494Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:28.4373293Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x5a13850
2023-02-03T20:22:28.4565307Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:28.4699552Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:22:28.5155307Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x59d6b80
2023-02-03T20:22:28.5287738Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x59d6b80 for device 1
2023-02-03T20:22:28.5426830Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x7479580
2023-02-03T20:22:28.5568175Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:22:28.5841030Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:28.5993388Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x5989f70
2023-02-03T20:22:28.6118325Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x59d6b80
2023-02-03T20:22:28.6258740Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x59d6b80
2023-02-03T20:22:29.7894792Z PASSED [ 26%]
2023-02-03T20:22:30.9871379Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.NO_ACK-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:30.9872755Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:30.9873355Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x610bdc0
2023-02-03T20:22:31.0005838Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:31.0144761Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:31.0276699Z DEBUG pylibschc.libschc:fragmenter.py:120 normal fragment
2023-02-03T20:22:31.0441841Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:31.0650577Z DEBUG pylibschc.libschc:fragmenter.py:120 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:31.0801770Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:31.3617066Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x6acba50
2023-02-03T20:22:31.3750374Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6acba50 for device 1
2023-02-03T20:22:31.3878238Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5beaac0
2023-02-03T20:22:31.4007608Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x6370790
2023-02-03T20:22:31.4200727Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:31.4364310Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 0, window is 0
2023-02-03T20:22:31.4507463Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:31.6961902Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:31.7165583Z DEBUG pylibschc.libschc:test_fragmenter.py:113 SEND
2023-02-03T20:22:31.7330440Z DEBUG pylibschc.libschc:test_fragmenter.py:113 last fragment
2023-02-03T20:22:31.7532445Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_fragmentation_header(): padding bits of last tile 6
2023-02-03T20:22:31.7678693Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): original packet length 520 bits, last tile padding 6 bits, extra padding 2 bits
2023-02-03T20:22:31.7859951Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): MIC for device 1 is C7481B99
2023-02-03T20:22:31.8018087Z DEBUG pylibschc.libschc:test_fragmenter.py:113 send_fragment(): sending fragment 2 with length 12 to device 1
2023-02-03T20:22:31.8166700Z DEBUG pylibschc.libschc:test_fragmenter.py:113 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:31.8312567Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_dc_timer(): for 100 ms
2023-02-03T20:22:32.0808151Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 0, window is 0
2023-02-03T20:22:32.0962734Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:32.1204943Z DEBUG pylibschc.libschc:test_fragmenter.py:113 RECV WINDOW
2023-02-03T20:22:32.1368640Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6acba50 for device 1
2023-02-03T20:22:32.1512000Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5beaac0
2023-02-03T20:22:32.1658151Z DEBUG pylibschc.libschc:fragmenter.py:168 2: 0x6370790
2023-02-03T20:22:32.1859103Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:32.1993840Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x7001590
2023-02-03T20:22:32.2139697Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:32.2278202Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 1, window is 0
2023-02-03T20:22:32.2429712Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:32.2631167Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:32.2767364Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:32.2922972Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is C7481B99
2023-02-03T20:22:32.3055497Z DEBUG pylibschc.libschc:fragmenter.py:179 2: 0x6370790
2023-02-03T20:22:32.3320599Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:32.3458819Z DEBUG pylibschc.libschc:fragmenter.py:179 3: 0x7001590
2023-02-03T20:22:32.3607850Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:32.3823013Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is C7481B99
2023-02-03T20:22:32.4089886Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): set head
2023-02-03T20:22:32.4239440Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x5aaaed0
2023-02-03T20:22:32.4380390Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:32.4521515Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x726af00
2023-02-03T20:22:32.4647877Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): trying to free 0x6acba50
2023-02-03T20:22:32.4777535Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): free'd 0x6acba50
2023-02-03T20:22:32.4938168Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_fragment(): end transmission cycle
2023-02-03T20:22:32.5127654Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): trying to free 0x610bdc0
2023-02-03T20:22:32.5245567Z ==3139== Thread 2:
2023-02-03T20:22:32.5246409Z ==3139== Invalid read of size 8
2023-02-03T20:22:32.5247135Z ==3139== at 0x93CEC0D: __Pyx_PyBool_FromLong (libschc.c:27970)
2023-02-03T20:22:32.5247988Z ==3139== by 0x93CEC0D: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_12_allocated (libschc.c:13609)
2023-02-03T20:22:32.5248765Z ==3139== by 0x93CEC0D: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_13_allocated (libschc.c:13573)
2023-02-03T20:22:32.5249580Z ==3139== by 0x93C879B: __Pyx_PyObject_CallMethO (libschc.c:22503)
2023-02-03T20:22:32.5250082Z ==3139== by 0x93C879B: __Pyx_PyObject_CallNoArg (libschc.c:23781)
2023-02-03T20:22:32.5250683Z ==3139== by 0x93C879B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task__timer_task_wrapper (libschc.c:14733)
2023-02-03T20:22:32.5251433Z ==3139== by 0x93C879B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task_1_timer_task_wrapper (libschc.c:14685)
2023-02-03T20:22:32.5252218Z ==3139== by 0x49B0CFE: _PyObject_MakeTpCall (call.c:215)
2023-02-03T20:22:32.5253009Z ==3139== by 0x4A1799C: call_function (ceval.c:5888)
2023-02-03T20:22:32.5253558Z ==3139== by 0x4A1799C: _PyEval_EvalFrameDefault (ceval.c:4213)
2023-02-03T20:22:32.5254066Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5254617Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5255207Z ==3139== by 0x4A13A75: do_call_core (ceval.c:5943)
2023-02-03T20:22:32.5255759Z ==3139== by 0x4A13A75: _PyEval_EvalFrameDefault (ceval.c:4277)
2023-02-03T20:22:32.5256742Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5257372Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5257983Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5258548Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:22:32.5259079Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5260017Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5260481Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5261094Z ==3139== by 0x4A11550: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5261599Z ==3139== by 0x4A11550: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:22:32.5262198Z ==3139== by 0x4A11550: call_function (ceval.c:5891)
2023-02-03T20:22:32.5262836Z ==3139== by 0x4A11550: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5263439Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5274305Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5275368Z ==3139== Address 0x6acbac0 is 112 bytes inside a block of size 168 free'd
2023-02-03T20:22:32.5276311Z ==3139== at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
2023-02-03T20:22:32.5277240Z ==3139== by 0x93BE825: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_28reset (libschc.c:17588)
2023-02-03T20:22:32.5278002Z ==3139== by 0x93BE825: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_29reset (libschc.c:17558)
2023-02-03T20:22:32.5278903Z ==3139== by 0x93C7941: __Pyx_PyObject_CallMethO (libschc.c:22503)
2023-02-03T20:22:32.5279497Z ==3139== by 0x93C7941: __Pyx_PyObject_CallNoArg (libschc.c:23781)
2023-02-03T20:22:32.5280138Z ==3139== by 0x93C7941: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__reassemble (libschc.c:17372)
2023-02-03T20:22:32.5280857Z ==3139== by 0x93C2F6E: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_26reassemble (libschc.c:17519)
2023-02-03T20:22:32.5281756Z ==3139== by 0x93C2F6E: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_27reassemble (libschc.c:17495)
2023-02-03T20:22:32.5282325Z ==3139== by 0x49D6CE4: cfunction_vectorcall_NOARGS (methodobject.c:489)
2023-02-03T20:22:32.5282910Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5292587Z ==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:22:32.5293456Z ==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
2023-02-03T20:22:32.5294108Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:22:32.5294789Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5295452Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5295997Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5296849Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5297656Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:22:32.5298211Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5298827Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5299981Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5300638Z ==3139== Block was alloc'd at
2023-02-03T20:22:32.5301347Z ==3139== at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
2023-02-03T20:22:32.5301909Z ==3139== by 0x93E79E9: schc_get_connection (fragmenter.c:1319)
2023-02-03T20:22:32.5302411Z ==3139== by 0x93E9851: schc_fragment_input (fragmenter.c:2367)
2023-02-03T20:22:32.5312516Z ==3139== by 0x93DA17E: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__input (libschc.c:16623)
2023-02-03T20:22:32.5313410Z ==3139== by 0x93C4F1B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_24input (libschc.c:17085)
2023-02-03T20:22:32.5314327Z ==3139== by 0x93C4F1B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_25input (libschc.c:16994)
2023-02-03T20:22:32.5315129Z ==3139== by 0x49D6DB6: cfunction_vectorcall_O (methodobject.c:516)
2023-02-03T20:22:32.5315902Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5316459Z ==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:22:32.5317175Z ==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
2023-02-03T20:22:32.5317697Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:22:32.5318312Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5318878Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:22:32.5319397Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:22:32.5319952Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:22:32.5320523Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:22:32.5321274Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:22:32.5321720Z ==3139==
2023-02-03T20:22:32.5330956Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:33.6542261Z PASSED [ 27%]
2023-02-03T20:22:34.8917833Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.NO_ACK-BitArray-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:34.8919605Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:34.8920409Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x6a0fdd0
2023-02-03T20:22:34.9057052Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:34.9197100Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:34.9336985Z DEBUG pylibschc.libschc:fragmenter.py:120 normal fragment
2023-02-03T20:22:34.9484615Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:34.9685177Z DEBUG pylibschc.libschc:fragmenter.py:120 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:34.9872682Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:35.0252896Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x6004fe0
2023-02-03T20:22:35.0376422Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6004fe0 for device 1
2023-02-03T20:22:35.0505599Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5be79f0
2023-02-03T20:22:35.0640377Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x6023bb0
2023-02-03T20:22:35.0832527Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:35.0985975Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 0, window is 0
2023-02-03T20:22:35.1129389Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:35.1337122Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:35.1483726Z DEBUG pylibschc.libschc:test_fragmenter.py:113 SEND
2023-02-03T20:22:35.1616984Z DEBUG pylibschc.libschc:test_fragmenter.py:113 last fragment
2023-02-03T20:22:35.1752780Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_fragmentation_header(): padding bits of last tile 6
2023-02-03T20:22:35.1887123Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): original packet length 520 bits, last tile padding 6 bits, extra padding 2 bits
2023-02-03T20:22:35.2023372Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): MIC for device 1 is C7481B99
2023-02-03T20:22:35.2150427Z DEBUG pylibschc.libschc:test_fragmenter.py:113 send_fragment(): sending fragment 2 with length 12 to device 1
2023-02-03T20:22:35.2284863Z DEBUG pylibschc.libschc:test_fragmenter.py:113 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:35.2435711Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_dc_timer(): for 100 ms
2023-02-03T20:22:35.4492170Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 0, window is 0
2023-02-03T20:22:35.4635084Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:35.4834693Z DEBUG pylibschc.libschc:test_fragmenter.py:113 RECV WINDOW
2023-02-03T20:22:35.4984809Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6004fe0 for device 1
2023-02-03T20:22:35.5115800Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5be79f0
2023-02-03T20:22:35.5246712Z DEBUG pylibschc.libschc:fragmenter.py:168 2: 0x6023bb0
2023-02-03T20:22:35.5431987Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:35.5566399Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5216ff0
2023-02-03T20:22:35.5698987Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:35.5829841Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 1, window is 0
2023-02-03T20:22:35.5979799Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:35.6185439Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:35.6313938Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:35.6444963Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is C7481B99
2023-02-03T20:22:35.6576956Z DEBUG pylibschc.libschc:fragmenter.py:179 2: 0x6023bb0
2023-02-03T20:22:35.6771121Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:35.6900269Z DEBUG pylibschc.libschc:fragmenter.py:179 3: 0x5216ff0
2023-02-03T20:22:35.7038555Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:35.7168357Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is C7481B99
2023-02-03T20:22:35.7319537Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): set head
2023-02-03T20:22:35.7454550Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x6023c30
2023-02-03T20:22:35.7580056Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:35.7709459Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x5217040
2023-02-03T20:22:35.7835666Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): trying to free 0x6004fe0
2023-02-03T20:22:35.7967022Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): free'd 0x6004fe0
2023-02-03T20:22:35.8153668Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_fragment(): end transmission cycle
2023-02-03T20:22:35.8306350Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): trying to free 0x6a0fdd0
2023-02-03T20:22:35.8460744Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:35.8608976Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:36.9469034Z PASSED [ 28%]
2023-02-03T20:22:38.1857381Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.ACK_ALWAYS-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:22:38.1859767Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:38.1860821Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x75c6ea0
2023-02-03T20:22:38.1991169Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:38.2118160Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:22:38.2419753Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x788ccd0
2023-02-03T20:22:38.2548720Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x788ccd0 for device 1
2023-02-03T20:22:38.2674894Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x77aca10
2023-02-03T20:22:38.2808649Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:22:38.2949358Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:38.3076898Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x5059480
2023-02-03T20:22:38.3206459Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x788ccd0
2023-02-03T20:22:38.3338509Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x788ccd0
2023-02-03T20:22:39.4795029Z PASSED [ 29%]
2023-02-03T20:22:40.6898480Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.ACK_ALWAYS-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:40.6899673Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:40.6900508Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x704c9b0
2023-02-03T20:22:40.7029626Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:40.7161725Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:40.7297450Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:22:40.7427801Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:40.7608071Z DEBUG pylibschc.libschc:fragmenter.py:120 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:40.7752475Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:40.7956222Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:40.8084385Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:40.8443327Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x744d9d0
2023-02-03T20:22:40.8570119Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x744d9d0 for device 1
2023-02-03T20:22:40.8695246Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d69090
2023-02-03T20:22:40.8821797Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5cf7230
2023-02-03T20:22:40.9009161Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:40.9167470Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:22:40.9350961Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:22:40.9490008Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:40.9700824Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:40.9837813Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:40.9977687Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:22:41.0112452Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:41.0303561Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:41.0456222Z DEBUG pylibschc.libschc:test_fragmenter.py:113 SEND
2023-02-03T20:22:41.0587580Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_fragment(): all-1 window
2023-02-03T20:22:41.0726457Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:22:41.0860959Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:22:41.0992816Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:22:41.1128237Z DEBUG pylibschc.libschc:test_fragmenter.py:113 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:22:41.1272352Z DEBUG pylibschc.libschc:test_fragmenter.py:113 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:41.1418704Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:41.1625808Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:41.1757882Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_retrans_timer(): for 400 ms
2023-02-03T20:22:41.3749003Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 62, window is 0
2023-02-03T20:22:41.3888932Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 0 frag is 62, window count is 0
2023-02-03T20:22:41.4028194Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:41.4232254Z DEBUG pylibschc.libschc:test_fragmenter.py:113 RECV WINDOW
2023-02-03T20:22:41.4356825Z DEBUG pylibschc.libschc:test_fragmenter.py:113 w == window
2023-02-03T20:22:41.4485653Z DEBUG pylibschc.libschc:test_fragmenter.py:113 not all-x
2023-02-03T20:22:41.4619829Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:41.4816149Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:41.4962798Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x744d9d0 for device 1
2023-02-03T20:22:41.5098848Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d69090
2023-02-03T20:22:41.5235663Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5cf7230
2023-02-03T20:22:41.5430044Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:41.5554436Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5cd9f70
2023-02-03T20:22:41.5693965Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:41.5821306Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:22:41.5959311Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:22:41.6128339Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:41.6326771Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:41.6460455Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:41.6602619Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:41.6736938Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:41.6926447Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:41.7056834Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:22:41.7181426Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x5cf7230
2023-02-03T20:22:41.7370094Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:41.7495866Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x5cd9f70
2023-02-03T20:22:41.7636482Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:41.7765434Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:22:41.7918431Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:22:41.8058113Z DEBUG pylibschc.libschc:fragmenter.py:179 17 20
2023-02-03T20:22:41.8236339Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 63, window is 0
2023-02-03T20:22:41.8377678Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 63 frag is 63, window count is 0
2023-02-03T20:22:41.8515063Z DEBUG pylibschc.libschc:test_fragmenter.py:113 END RX
2023-02-03T20:22:41.8709415Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): set head
2023-02-03T20:22:41.8846393Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x60ba3c0
2023-02-03T20:22:41.8980484Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:41.9111756Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x5300610
2023-02-03T20:22:41.9244243Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): trying to free 0x744d9d0
2023-02-03T20:22:41.9383339Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): free'd 0x744d9d0
2023-02-03T20:22:41.9558216Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:22:41.9690977Z DEBUG pylibschc.libschc:fragmenter.py:86 w == w
2023-02-03T20:22:41.9836846Z DEBUG pylibschc.libschc:fragmenter.py:86 no more fragments, MIC ok
2023-02-03T20:22:41.9969775Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:22:42.0111146Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x704c9b0
2023-02-03T20:22:42.0268950Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:42.0422055Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:43.1629029Z PASSED [ 30%]
2023-02-03T20:22:44.3706860Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.ACK_ALWAYS-BitArray-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:44.3708450Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:44.3709419Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x6286ba0
2023-02-03T20:22:44.3856378Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:44.3984967Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:44.4119533Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:22:44.4251717Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:44.4466872Z DEBUG pylibschc.libschc:fragmenter.py:120 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:44.4617853Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:44.4811409Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:44.4945689Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:44.5318455Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x746f570
2023-02-03T20:22:44.5451533Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x746f570 for device 1
2023-02-03T20:22:44.5581223Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x6006310
2023-02-03T20:22:44.5713747Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x746f660
2023-02-03T20:22:44.5903824Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:44.6037580Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:22:44.6168423Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:22:44.6306265Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:44.6512651Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:44.6649165Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:44.6788829Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:22:44.6923945Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:44.7108973Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:44.7259166Z DEBUG pylibschc.libschc:test_fragmenter.py:113 SEND
2023-02-03T20:22:44.7387344Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_fragment(): all-1 window
2023-02-03T20:22:44.7523258Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:22:44.7653855Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:22:44.7797840Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:22:44.7929416Z DEBUG pylibschc.libschc:test_fragmenter.py:113 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:22:44.8074608Z DEBUG pylibschc.libschc:test_fragmenter.py:113 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:44.8218505Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:44.8460990Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:44.8589875Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_retrans_timer(): for 400 ms
2023-02-03T20:22:45.0571288Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 62, window is 0
2023-02-03T20:22:45.0713941Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 0 frag is 62, window count is 0
2023-02-03T20:22:45.0865581Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:45.1071606Z DEBUG pylibschc.libschc:test_fragmenter.py:113 RECV WINDOW
2023-02-03T20:22:45.1210720Z DEBUG pylibschc.libschc:test_fragmenter.py:113 w == window
2023-02-03T20:22:45.1344694Z DEBUG pylibschc.libschc:test_fragmenter.py:113 not all-x
2023-02-03T20:22:45.1479348Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:45.1672161Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:45.1828063Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x746f570 for device 1
2023-02-03T20:22:45.1959677Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x6006310
2023-02-03T20:22:45.2090744Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x746f660
2023-02-03T20:22:45.2312975Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:45.2446775Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5c63a70
2023-02-03T20:22:45.2590494Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:45.2725164Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:22:45.2857412Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:22:45.2996220Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:45.3242377Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:45.3372125Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:45.3499521Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:45.3626978Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:45.3815723Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:45.3947729Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:22:45.4070992Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x746f660
2023-02-03T20:22:45.4267899Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:45.4428623Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x5c63a70
2023-02-03T20:22:45.4605758Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:45.4748930Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:22:45.4884744Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:22:45.5017652Z DEBUG pylibschc.libschc:fragmenter.py:179 17 20
2023-02-03T20:22:45.5187939Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:22:45.5327062Z DEBUG pylibschc.libschc:fragmenter.py:86 w == w
2023-02-03T20:22:45.5458759Z DEBUG pylibschc.libschc:fragmenter.py:86 no more fragments, MIC ok
2023-02-03T20:22:45.5593109Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:22:45.5752426Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x6286ba0
2023-02-03T20:22:45.5904510Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 63, window is 0
2023-02-03T20:22:45.6041431Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 63 frag is 63, window count is 0
2023-02-03T20:22:45.6181037Z DEBUG pylibschc.libschc:test_fragmenter.py:113 END RX
2023-02-03T20:22:45.6341203Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): set head
2023-02-03T20:22:45.6494956Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x7535f00
2023-02-03T20:22:45.6628866Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:45.6759568Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x51bc430
2023-02-03T20:22:45.6891721Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): trying to free 0x746f570
2023-02-03T20:22:45.7023504Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): free'd 0x746f570
2023-02-03T20:22:45.7165367Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:45.7306665Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:46.7222521Z PASSED [ 32%]
2023-02-03T20:22:47.9309673Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.ACK_ON_ERROR-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:22:47.9311240Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:47.9312550Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x68b0710
2023-02-03T20:22:47.9439298Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:47.9568098Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:22:47.9871273Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x52d46e0
2023-02-03T20:22:48.0003259Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x52d46e0 for device 1
2023-02-03T20:22:48.0139380Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x60bacd0
2023-02-03T20:22:48.0273549Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:22:48.0410904Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:48.0540212Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x52d47d0
2023-02-03T20:22:48.0679899Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x52d46e0
2023-02-03T20:22:48.0807760Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x52d46e0
2023-02-03T20:22:49.2239747Z PASSED [ 33%]
2023-02-03T20:22:50.4298885Z tests/test_fragmenter.py::TestFragmenterReassemblerThreaded::test_fragmenter_reassembler_threaded[FragmentationMode.ACK_ON_ERROR-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:50.4300917Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:50.4301789Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x5cd3e20
2023-02-03T20:22:50.4436519Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:50.4573150Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:50.4703002Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:22:50.4850004Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:50.5041046Z DEBUG pylibschc.libschc:fragmenter.py:120 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:50.5180341Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:50.5372716Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:50.5502177Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:50.5868299Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x5ffea10
2023-02-03T20:22:50.5999574Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5ffea10 for device 1
2023-02-03T20:22:50.6128295Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x506ff80
2023-02-03T20:22:50.6258361Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5fd5090
2023-02-03T20:22:50.6453956Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:50.6591696Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:22:50.6748123Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:22:50.6887369Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:50.7117035Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:50.7256175Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:50.7390501Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:22:50.7515425Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:50.7708501Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:50.7864292Z DEBUG pylibschc.libschc:test_fragmenter.py:113 SEND
2023-02-03T20:22:50.8009365Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_fragment(): all-1 window
2023-02-03T20:22:50.8137942Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:22:50.8273799Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:22:50.8400700Z DEBUG pylibschc.libschc:test_fragmenter.py:113 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:22:50.8531970Z DEBUG pylibschc.libschc:test_fragmenter.py:113 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:22:50.8674781Z DEBUG pylibschc.libschc:test_fragmenter.py:113 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:50.8814869Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:50.9018202Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:50.9146092Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_retrans_timer(): for 400 ms
2023-02-03T20:22:51.1094048Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 62, window is 0
2023-02-03T20:22:51.1224410Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 0 frag is 62, window count is 0
2023-02-03T20:22:51.1359018Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:51.1595591Z DEBUG pylibschc.libschc:test_fragmenter.py:113 RECV WINDOW
2023-02-03T20:22:51.1737517Z DEBUG pylibschc.libschc:test_fragmenter.py:113 w == window
2023-02-03T20:22:51.1865032Z DEBUG pylibschc.libschc:test_fragmenter.py:113 not all-x
2023-02-03T20:22:51.1993005Z DEBUG pylibschc.libschc:test_fragmenter.py:113 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:22:51.2178936Z DEBUG pylibschc.libschc:test_fragmenter.py:113 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:22:51.2324268Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5ffea10 for device 1
2023-02-03T20:22:51.2465134Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x506ff80
2023-02-03T20:22:51.2598730Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5fd5090
2023-02-03T20:22:51.2794262Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:51.2928195Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5ce3900
2023-02-03T20:22:51.3073663Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:51.3207885Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:22:51.3339241Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:22:51.3479890Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:51.3684344Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:51.3818635Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:22:51.3954587Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:51.4095092Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:22:51.4282361Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:22:51.4417221Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:22:51.4547533Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x5fd5090
2023-02-03T20:22:51.4733856Z DEBUG pylibschc.libschc:fragmenter.py:179 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:22:51.4868041Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x5ce3900
2023-02-03T20:22:51.5006551Z DEBUG pylibschc.libschc:fragmenter.py:179 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:22:51.5140470Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:22:51.5269349Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:22:51.5398887Z DEBUG pylibschc.libschc:fragmenter.py:179 16 20
2023-02-03T20:22:51.5566430Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:22:51.5708661Z DEBUG pylibschc.libschc:fragmenter.py:86 received bitmap == local bitmap
2023-02-03T20:22:51.5839087Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:22:51.5981785Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x5cd3e20
2023-02-03T20:22:51.6127707Z DEBUG pylibschc.libschc:test_fragmenter.py:113 fcn is 63, window is 0
2023-02-03T20:22:51.6259185Z DEBUG pylibschc.libschc:test_fragmenter.py:113 value is 63 frag is 63, window count is 0
2023-02-03T20:22:51.6387793Z DEBUG pylibschc.libschc:test_fragmenter.py:113 END RX
2023-02-03T20:22:51.6541635Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): set head
2023-02-03T20:22:51.6704563Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x5026bf0
2023-02-03T20:22:51.6858245Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:51.6989918Z DEBUG pylibschc.libschc:test_fragmenter.py:113 mbuf_delete(): free 0x69b1750
2023-02-03T20:22:51.7117999Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): trying to free 0x5ffea10
2023-02-03T20:22:51.7246564Z DEBUG pylibschc.libschc:test_fragmenter.py:113 schc_free_connection(): free'd 0x5ffea10
2023-02-03T20:22:51.7389102Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:51.7535411Z INFO pylibschc.libschc:test_fragmenter.py:113 Timer fired with an unallocated fragmentation connection
2023-02-03T20:22:52.7629377Z PASSED [ 34%]
2023-02-03T20:22:52.8426497Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.NO_ACK-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:22:52.8427948Z -------------------------------- live log setup --------------------------------
2023-02-03T20:22:52.8428867Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:52.8942507Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:54.1828358Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:54.1829516Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x599b950
2023-02-03T20:22:54.1964386Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:54.2089086Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:22:54.2677984Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x5bae5a0
2023-02-03T20:22:54.2805234Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5bae5a0 for device 1
2023-02-03T20:22:54.2930786Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5b0aed0
2023-02-03T20:22:54.3063537Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:22:54.3198114Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:54.3326153Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x5b0af20
2023-02-03T20:22:54.3450243Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x5bae5a0
2023-02-03T20:22:54.3573712Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x5bae5a0
2023-02-03T20:22:55.0007040Z PASSED [ 35%]
2023-02-03T20:22:55.0008269Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:22:55.0009258Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:55.0608739Z
2023-02-03T20:22:55.0962764Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.NO_ACK-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:55.0964216Z -------------------------------- live log setup --------------------------------
2023-02-03T20:22:55.0965738Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:56.3018292Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:56.3019425Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x6fca540
2023-02-03T20:22:56.3149416Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:56.3276576Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:56.3403370Z DEBUG pylibschc.libschc:fragmenter.py:120 normal fragment
2023-02-03T20:22:56.3531528Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:56.3715960Z DEBUG pylibschc.libschc:fragmenter.py:120 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:56.3854064Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:56.4220939Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x732e870
2023-02-03T20:22:56.4365964Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x732e870 for device 1
2023-02-03T20:22:56.4499760Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5c09e00
2023-02-03T20:22:56.4629666Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x7028500
2023-02-03T20:22:56.4819645Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:56.4954312Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 0, window is 0
2023-02-03T20:22:56.5097264Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:56.5241825Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:56.5444224Z DEBUG pylibschc.libschc:test_fragmenter.py:224 SEND
2023-02-03T20:22:56.5572903Z DEBUG pylibschc.libschc:test_fragmenter.py:224 last fragment
2023-02-03T20:22:56.5700402Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 6
2023-02-03T20:22:56.5827445Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 6 bits, extra padding 2 bits
2023-02-03T20:22:56.5957618Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is C7481B99
2023-02-03T20:22:56.6089082Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_fragment(): sending fragment 2 with length 12 to device 1
2023-02-03T20:22:56.6227861Z DEBUG pylibschc.libschc:test_fragmenter.py:224 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:56.6368213Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_dc_timer(): for 100 ms
2023-02-03T20:22:56.6553681Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 0, window is 0
2023-02-03T20:22:56.6688381Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:56.6830759Z DEBUG pylibschc.libschc:test_fragmenter.py:224 RECV WINDOW
2023-02-03T20:22:56.7002852Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x732e870 for device 1
2023-02-03T20:22:56.7128516Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5c09e00
2023-02-03T20:22:56.7254107Z DEBUG pylibschc.libschc:fragmenter.py:168 2: 0x7028500
2023-02-03T20:22:56.7440786Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:56.7566685Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5bdd170
2023-02-03T20:22:56.7706725Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:56.7837848Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 1, window is 0
2023-02-03T20:22:56.7970300Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:56.8108406Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:56.8234481Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:56.8359078Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is C7481B99
2023-02-03T20:22:56.8484400Z DEBUG pylibschc.libschc:fragmenter.py:179 2: 0x7028500
2023-02-03T20:22:56.8670481Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:56.8799433Z DEBUG pylibschc.libschc:fragmenter.py:179 3: 0x5bdd170
2023-02-03T20:22:56.8940214Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:56.9068997Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is C7481B99
2023-02-03T20:22:56.9213294Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): set head
2023-02-03T20:22:56.9339889Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x7078cc0
2023-02-03T20:22:56.9463782Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:56.9597126Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x732e960
2023-02-03T20:22:56.9728554Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): trying to free 0x732e870
2023-02-03T20:22:56.9863056Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): free'd 0x732e870
2023-02-03T20:22:57.0076083Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_fragment(): end transmission cycle
2023-02-03T20:22:57.0225475Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): trying to free 0x6fca540
2023-02-03T20:22:57.6522976Z PASSED [ 36%]
2023-02-03T20:22:57.6524096Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:22:57.6524677Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:57.7110353Z
2023-02-03T20:22:57.7478742Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.NO_ACK-BitArray-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:22:57.7480182Z -------------------------------- live log setup --------------------------------
2023-02-03T20:22:57.7480742Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:22:58.9381166Z -------------------------------- live log call ---------------------------------
2023-02-03T20:22:58.9382261Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x71d2990
2023-02-03T20:22:58.9515219Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:22:58.9643002Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:22:58.9782037Z DEBUG pylibschc.libschc:fragmenter.py:120 normal fragment
2023-02-03T20:22:58.9912764Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:22:59.0102580Z DEBUG pylibschc.libschc:fragmenter.py:120 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:59.0236351Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:22:59.0603663Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x72ddaa0
2023-02-03T20:22:59.0735993Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x72ddaa0 for device 1
2023-02-03T20:22:59.0866065Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x6aac730
2023-02-03T20:22:59.0991217Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x72ddb90
2023-02-03T20:22:59.1179597Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:59.1308383Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 0, window is 0
2023-02-03T20:22:59.1432745Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:59.1570603Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:59.1756021Z DEBUG pylibschc.libschc:test_fragmenter.py:224 SEND
2023-02-03T20:22:59.1880978Z DEBUG pylibschc.libschc:test_fragmenter.py:224 last fragment
2023-02-03T20:22:59.2006791Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 6
2023-02-03T20:22:59.2129289Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 6 bits, extra padding 2 bits
2023-02-03T20:22:59.2250587Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is C7481B99
2023-02-03T20:22:59.2373988Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_fragment(): sending fragment 2 with length 12 to device 1
2023-02-03T20:22:59.2508046Z DEBUG pylibschc.libschc:test_fragmenter.py:224 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:59.2643625Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_dc_timer(): for 100 ms
2023-02-03T20:22:59.2812877Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 0, window is 0
2023-02-03T20:22:59.2945537Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:59.3132188Z DEBUG pylibschc.libschc:test_fragmenter.py:224 RECV WINDOW
2023-02-03T20:22:59.3299988Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x72ddaa0 for device 1
2023-02-03T20:22:59.3423562Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x6aac730
2023-02-03T20:22:59.3548270Z DEBUG pylibschc.libschc:fragmenter.py:168 2: 0x72ddb90
2023-02-03T20:22:59.3734172Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:59.3860395Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x778cbe0
2023-02-03T20:22:59.3996504Z DEBUG pylibschc.libschc:fragmenter.py:168 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:59.4122395Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 1, window is 0
2023-02-03T20:22:59.4257586Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:22:59.4397528Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:22:59.4521249Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:22:59.4647996Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is C7481B99
2023-02-03T20:22:59.4773437Z DEBUG pylibschc.libschc:fragmenter.py:179 2: 0x72ddb90
2023-02-03T20:22:59.4955900Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0x26 0x37 0xB9 0x32 0xB6 0x90 0x34 0xB8 0x39 0xBA 0xB6 0x90 0x32 0x37 0xB6 0x37 0xB9 0x10 0x39 0xB4 0xBA 0x10 0x30 0xB6 0xB2 0xBA 0x16 0x10 0x31 0xB7 0xB7 0x39 0xB2 0xBA 0x32 0xBA 0x3A 0xB9 0x10 0x39 0xB0 0xB2 0x34 0xB8 0x39 0xB1 0xB4 0xB7 0x33 0x90 0x32 0xB6 0x34 0xBA 0x39 0x16 0x10 0x39 0xB2
2023-02-03T20:22:59.5139567Z DEBUG pylibschc.libschc:fragmenter.py:179 3: 0x778cbe0
2023-02-03T20:22:59.5257952Z DEBUG pylibschc.libschc:fragmenter.py:179 0x15 0xE3 0xA4 0x0D 0xCC 0xD9 0x08 0x19 0x1A 0x58 0x5B 0x40
2023-02-03T20:22:59.5358699Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is C7481B99
2023-02-03T20:22:59.5509224Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): set head
2023-02-03T20:22:59.5650652Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x72c3d20
2023-02-03T20:22:59.5787144Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:22:59.5922088Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x778cc30
2023-02-03T20:22:59.6056915Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): trying to free 0x72ddaa0
2023-02-03T20:22:59.6190586Z DEBUG pylibschc.libschc:fragmenter.py:179 schc_free_connection(): free'd 0x72ddaa0
2023-02-03T20:22:59.6383247Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_fragment(): end transmission cycle
2023-02-03T20:22:59.6526513Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): trying to free 0x71d2990
2023-02-03T20:23:00.2799707Z PASSED [ 38%]
2023-02-03T20:23:00.2800922Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:00.2801952Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:00.3365504Z
2023-02-03T20:23:00.3721166Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.ACK_ALWAYS-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:23:00.3722592Z -------------------------------- live log setup --------------------------------
2023-02-03T20:23:00.3723324Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:01.5560128Z -------------------------------- live log call ---------------------------------
2023-02-03T20:23:01.5560841Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x6e79130
2023-02-03T20:23:01.5687418Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:23:01.5815364Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:23:01.6185867Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x6eba700
2023-02-03T20:23:01.6315559Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6eba700 for device 1
2023-02-03T20:23:01.6442430Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x6e79220
2023-02-03T20:23:01.6575341Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:23:01.6717395Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:01.6845810Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x6eba7f0
2023-02-03T20:23:01.6974560Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x6eba700
2023-02-03T20:23:01.7101143Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x6eba700
2023-02-03T20:23:02.3380874Z PASSED [ 39%]
2023-02-03T20:23:02.3382484Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:02.3383110Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:02.3955283Z
2023-02-03T20:23:02.4311906Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.ACK_ALWAYS-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:23:02.4313683Z -------------------------------- live log setup --------------------------------
2023-02-03T20:23:02.4314609Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:03.6409945Z -------------------------------- live log call ---------------------------------
2023-02-03T20:23:03.6410931Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x5b8d980
2023-02-03T20:23:03.6541998Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:23:03.6669533Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:23:03.6799085Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:23:03.6928483Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:23:03.7115745Z DEBUG pylibschc.libschc:fragmenter.py:120 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:03.7249981Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:03.7434592Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:03.7555707Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:23:03.7929338Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x5d41480
2023-02-03T20:23:03.8054220Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5d41480 for device 1
2023-02-03T20:23:03.8181478Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d079f0
2023-02-03T20:23:03.8320430Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x73820a0
2023-02-03T20:23:03.8506865Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:03.8634657Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:23:03.8764172Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:23:03.8896268Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:03.9042667Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:03.9172689Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:03.9300561Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:23:03.9431140Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:03.9622721Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:03.9809484Z DEBUG pylibschc.libschc:test_fragmenter.py:224 SEND
2023-02-03T20:23:03.9938607Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_fragment(): all-1 window
2023-02-03T20:23:04.0083424Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:23:04.0221962Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:23:04.0352925Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:23:04.0486105Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:23:04.0631257Z DEBUG pylibschc.libschc:test_fragmenter.py:224 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:04.0770799Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:04.0957607Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:04.1084880Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_retrans_timer(): for 400 ms
2023-02-03T20:23:04.1251727Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 62, window is 0
2023-02-03T20:23:04.1378910Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 0 frag is 62, window count is 0
2023-02-03T20:23:04.1508068Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:04.1649859Z DEBUG pylibschc.libschc:test_fragmenter.py:224 RECV WINDOW
2023-02-03T20:23:04.1776829Z DEBUG pylibschc.libschc:test_fragmenter.py:224 w == window
2023-02-03T20:23:04.1910851Z DEBUG pylibschc.libschc:test_fragmenter.py:224 not all-x
2023-02-03T20:23:04.2041520Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:04.2230080Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:04.2409794Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5d41480 for device 1
2023-02-03T20:23:04.2535249Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d079f0
2023-02-03T20:23:04.2659705Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x73820a0
2023-02-03T20:23:04.2847411Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:04.2980097Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5bc5660
2023-02-03T20:23:04.3120749Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:04.3263611Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:23:04.3392489Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:23:04.3524258Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:04.3661505Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:04.3784760Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:04.3912623Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:23:04.4034310Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:04.4217678Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:04.4456758Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:23:04.4588548Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x73820a0
2023-02-03T20:23:04.4772599Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:04.4899776Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x5bc5660
2023-02-03T20:23:04.5035946Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:04.5164573Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:23:04.5291327Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:23:04.5419297Z DEBUG pylibschc.libschc:fragmenter.py:179 17 20
2023-02-03T20:23:04.5621684Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 63, window is 0
2023-02-03T20:23:04.5752797Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 63 frag is 63, window count is 0
2023-02-03T20:23:04.5883005Z DEBUG pylibschc.libschc:test_fragmenter.py:224 END RX
2023-02-03T20:23:04.6027281Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): set head
2023-02-03T20:23:04.6151677Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x514b0c0
2023-02-03T20:23:04.6275639Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:04.6397099Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x5a841f0
2023-02-03T20:23:04.6522838Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): trying to free 0x5d41480
2023-02-03T20:23:04.6653187Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): free'd 0x5d41480
2023-02-03T20:23:04.6785466Z DEBUG pylibschc.libschc:test_fragmenter.py:224 WAIT_BITMAP
2023-02-03T20:23:04.6918237Z DEBUG pylibschc.libschc:test_fragmenter.py:224 w == w
2023-02-03T20:23:04.7056952Z DEBUG pylibschc.libschc:test_fragmenter.py:224 timer expired
2023-02-03T20:23:04.7190270Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:23:04.7316689Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:23:04.7441219Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:23:04.7568978Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_empty(): sending all-x empty to device 1 with length 6 (48 b)
2023-02-03T20:23:04.7708302Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_retrans_timer(): for 400 ms
2023-02-03T20:23:04.7905408Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:23:04.8035536Z DEBUG pylibschc.libschc:fragmenter.py:86 w == w
2023-02-03T20:23:04.8164575Z DEBUG pylibschc.libschc:fragmenter.py:86 no more fragments, MIC ok
2023-02-03T20:23:04.8297422Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:23:04.8434821Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x5b8d980
2023-02-03T20:23:04.8659540Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x6084080
2023-02-03T20:23:04.8784350Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6084080 for device 1
2023-02-03T20:23:04.8911581Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d079f0
2023-02-03T20:23:04.9037927Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5be9f70
2023-02-03T20:23:04.9170859Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D
2023-02-03T20:23:04.9299293Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:23:04.9431530Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:23:04.9564864Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:04.9711396Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:04.9842669Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:04.9978841Z DEBUG pylibschc.libschc:fragmenter.py:179 discard_fragment():
2023-02-03T20:23:05.0119115Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:05.0251697Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x5bafae0
2023-02-03T20:23:05.0390032Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending bitmap
2023-02-03T20:23:05.0592685Z DEBUG pylibschc.libschc:fragmenter.py:179 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:05.0735337Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 10 (74 b)
2023-02-03T20:23:05.0874076Z DEBUG pylibschc.libschc:fragmenter.py:179 17 00 00 00 00 00 00 00 00 00
2023-02-03T20:23:05.1066800Z DEBUG pylibschc.libschc:test_fragmenter.py:224 connection 0x6084080 contains no fragments
2023-02-03T20:23:05.7222911Z PASSED [ 40%]
2023-02-03T20:23:05.7224075Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:05.7224859Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:05.7798887Z
2023-02-03T20:23:05.8144544Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.ACK_ALWAYS-BitArray-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:23:05.8145848Z -------------------------------- live log setup --------------------------------
2023-02-03T20:23:05.8146562Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:07.0295076Z -------------------------------- live log call ---------------------------------
2023-02-03T20:23:07.0298269Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x7896e50
2023-02-03T20:23:07.0419985Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:23:07.0544693Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:23:07.0669490Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:23:07.0799131Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:23:07.0982866Z DEBUG pylibschc.libschc:fragmenter.py:120 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:07.1112570Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:07.1294156Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:07.1417426Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:23:07.1782038Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x6a0c700
2023-02-03T20:23:07.1910605Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6a0c700 for device 1
2023-02-03T20:23:07.2034754Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d1d660
2023-02-03T20:23:07.2160175Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5fbb5b0
2023-02-03T20:23:07.2344449Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:07.2471236Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:23:07.2596497Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:23:07.2723586Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:07.2864092Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:07.2988473Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:07.3120994Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:23:07.3246380Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:07.3432250Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:07.3613458Z DEBUG pylibschc.libschc:test_fragmenter.py:224 SEND
2023-02-03T20:23:07.3740888Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_fragment(): all-1 window
2023-02-03T20:23:07.3869833Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:23:07.3996622Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:23:07.4121944Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:23:07.4250404Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:23:07.4386451Z DEBUG pylibschc.libschc:test_fragmenter.py:224 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:07.4519901Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:07.4703836Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:07.4831556Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_retrans_timer(): for 400 ms
2023-02-03T20:23:07.5002809Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 62, window is 0
2023-02-03T20:23:07.5130147Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 0 frag is 62, window count is 0
2023-02-03T20:23:07.5261642Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:07.5401329Z DEBUG pylibschc.libschc:test_fragmenter.py:224 RECV WINDOW
2023-02-03T20:23:07.5524151Z DEBUG pylibschc.libschc:test_fragmenter.py:224 w == window
2023-02-03T20:23:07.5650882Z DEBUG pylibschc.libschc:test_fragmenter.py:224 not all-x
2023-02-03T20:23:07.5777580Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:07.5967587Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:07.6146516Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x6a0c700 for device 1
2023-02-03T20:23:07.6273191Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d1d660
2023-02-03T20:23:07.6397283Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5fbb5b0
2023-02-03T20:23:07.6583540Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:07.6711548Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5cf96a0
2023-02-03T20:23:07.6849103Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:07.6975822Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:23:07.7103284Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:23:07.7233876Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:07.7369488Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:07.7491857Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:07.7619156Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:23:07.7751673Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:07.7941890Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:07.8070670Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:23:07.8196390Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x5fbb5b0
2023-02-03T20:23:07.8392239Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:07.8523882Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x5cf96a0
2023-02-03T20:23:07.8663444Z DEBUG pylibschc.libschc:fragmenter.py:179 0x17 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:07.8797618Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:23:07.8930003Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:23:07.9064342Z DEBUG pylibschc.libschc:fragmenter.py:179 17 20
2023-02-03T20:23:07.9271022Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 63, window is 0
2023-02-03T20:23:07.9408124Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 63 frag is 63, window count is 0
2023-02-03T20:23:07.9538688Z DEBUG pylibschc.libschc:test_fragmenter.py:224 END RX
2023-02-03T20:23:07.9681174Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): set head
2023-02-03T20:23:07.9814586Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x633ac90
2023-02-03T20:23:07.9945121Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:08.0081435Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x6060c80
2023-02-03T20:23:08.0218459Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): trying to free 0x6a0c700
2023-02-03T20:23:08.0346835Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): free'd 0x6a0c700
2023-02-03T20:23:08.0480080Z DEBUG pylibschc.libschc:test_fragmenter.py:224 WAIT_BITMAP
2023-02-03T20:23:08.0608556Z DEBUG pylibschc.libschc:test_fragmenter.py:224 w == w
2023-02-03T20:23:08.0737688Z DEBUG pylibschc.libschc:test_fragmenter.py:224 timer expired
2023-02-03T20:23:08.0869607Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:23:08.0999595Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:23:08.1128208Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:23:08.1259092Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_empty(): sending all-x empty to device 1 with length 6 (48 b)
2023-02-03T20:23:08.1396691Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_retrans_timer(): for 400 ms
2023-02-03T20:23:08.1597471Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:23:08.1723477Z DEBUG pylibschc.libschc:fragmenter.py:86 w == w
2023-02-03T20:23:08.1847739Z DEBUG pylibschc.libschc:fragmenter.py:86 no more fragments, MIC ok
2023-02-03T20:23:08.1971090Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:23:08.2108108Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x7896e50
2023-02-03T20:23:08.2330506Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x51fabf0
2023-02-03T20:23:08.2448790Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x51fabf0 for device 1
2023-02-03T20:23:08.2574677Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x5d1d660
2023-02-03T20:23:08.2699003Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5d5bb30
2023-02-03T20:23:08.2830526Z DEBUG pylibschc.libschc:fragmenter.py:168 0x17 0x3F 0x90 0xD9 0x5D 0x5D
2023-02-03T20:23:08.3053578Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:23:08.3183951Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:23:08.3310761Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:08.3446489Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:08.3571681Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:08.3699685Z DEBUG pylibschc.libschc:fragmenter.py:179 discard_fragment():
2023-02-03T20:23:08.3828856Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:08.3954930Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_delete(): free 0x60cc860
2023-02-03T20:23:08.4080607Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending bitmap
2023-02-03T20:23:08.4270242Z DEBUG pylibschc.libschc:fragmenter.py:179 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:08.4395963Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 10 (74 b)
2023-02-03T20:23:08.4530210Z DEBUG pylibschc.libschc:fragmenter.py:179 17 00 00 00 00 00 00 00 00 00
2023-02-03T20:23:08.4722675Z DEBUG pylibschc.libschc:test_fragmenter.py:224 connection 0x51fabf0 contains no fragments
2023-02-03T20:23:09.0986093Z PASSED [ 41%]
2023-02-03T20:23:09.0987337Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:09.0988197Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:09.1607379Z
2023-02-03T20:23:09.1969229Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.ACK_ON_ERROR-bytes-foobar-FragmentationResult.NO_FRAGMENTATION]
2023-02-03T20:23:09.1970534Z -------------------------------- live log setup --------------------------------
2023-02-03T20:23:09.1971271Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:10.3921371Z -------------------------------- live log call ---------------------------------
2023-02-03T20:23:10.3922492Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x73e03f0
2023-02-03T20:23:10.4045471Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:23:10.4166956Z DEBUG pylibschc.libschc:fragmenter.py:120 init_connection(): no fragmentation needed
2023-02-03T20:23:10.4530544Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x5cab330
2023-02-03T20:23:10.4652631Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x5cab330 for device 1
2023-02-03T20:23:10.4774469Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x5cab420
2023-02-03T20:23:10.4904971Z DEBUG pylibschc.libschc:fragmenter.py:168 0x66 0x6F 0x6F 0x62 0x61 0x72
2023-02-03T20:23:10.5064954Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:10.5184834Z DEBUG pylibschc.libschc:fragmenter.py:177 mbuf_delete(): free 0x5cab470
2023-02-03T20:23:10.5307470Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): trying to free 0x5cab330
2023-02-03T20:23:10.5431144Z DEBUG pylibschc.libschc:fragmenter.py:177 schc_free_connection(): free'd 0x5cab330
2023-02-03T20:23:11.1686062Z PASSED [ 42%]
2023-02-03T20:23:11.1687392Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:11.1688212Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:11.2259159Z
2023-02-03T20:23:11.2616916Z tests/test_fragmenter.py::TestFragmenterReassemblerAsync::test_fragmenter_reassembler_async[FragmentationMode.ACK_ON_ERROR-bytes-Lorem ipsum dolor sit amet, consetetur sadipscing elitr, sed diam-FragmentationResult.SUCCESS]
2023-02-03T20:23:11.2618494Z -------------------------------- live log setup --------------------------------
2023-02-03T20:23:11.2619324Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:12.4658437Z -------------------------------- live log call ---------------------------------
2023-02-03T20:23:12.4658997Z DEBUG pylibschc.libschc:fragmenter.py:112 schc_free_connection(): trying to free 0x7793450
2023-02-03T20:23:12.4782109Z DEBUG pylibschc.libschc:fragmenter.py:120 INIT_TX
2023-02-03T20:23:12.4904840Z DEBUG pylibschc.libschc:fragmenter.py:120 SEND
2023-02-03T20:23:12.5034102Z DEBUG pylibschc.libschc:fragmenter.py:120 schc_fragment(): normal fragment
2023-02-03T20:23:12.5167107Z DEBUG pylibschc.libschc:fragmenter.py:120 send_fragment(): sending fragment 1 with length 60 to device 1
2023-02-03T20:23:12.5359732Z DEBUG pylibschc.libschc:fragmenter.py:120 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:12.5490070Z DEBUG pylibschc.libschc:fragmenter.py:120 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:12.5672190Z DEBUG pylibschc.libschc:fragmenter.py:120 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:12.5798789Z DEBUG pylibschc.libschc:fragmenter.py:120 set_dc_timer(): for 100 ms
2023-02-03T20:23:12.6164970Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): malloc'd 0x7a97230
2023-02-03T20:23:12.6287365Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x7a97230 for device 1
2023-02-03T20:23:12.6409315Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x73ecaa0
2023-02-03T20:23:12.6532319Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x73fe4e0
2023-02-03T20:23:12.6713672Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:12.6837631Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 62, window is 0
2023-02-03T20:23:12.6957694Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 0 frag is 62, window count is 0
2023-02-03T20:23:12.7089430Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:12.7225284Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:12.7348605Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:12.7472392Z DEBUG pylibschc.libschc:fragmenter.py:179 not all-x
2023-02-03T20:23:12.7588640Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:12.7765925Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:12.7947292Z DEBUG pylibschc.libschc:test_fragmenter.py:224 SEND
2023-02-03T20:23:12.8069139Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_fragment(): all-1 window
2023-02-03T20:23:12.8191910Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_fragmentation_header(): padding bits of last tile 0
2023-02-03T20:23:12.8319201Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): original packet length 520 bits, last tile padding 0 bits, extra padding 0 bits
2023-02-03T20:23:12.8444000Z DEBUG pylibschc.libschc:test_fragmenter.py:224 compute_mic(): MIC for device 1 is 90D95D5D
2023-02-03T20:23:12.8564732Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_fragment(): sending fragment 2 with length 13 to device 1
2023-02-03T20:23:12.8693535Z DEBUG pylibschc.libschc:test_fragmenter.py:224 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:12.8887354Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:12.9074374Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:12.9204674Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_retrans_timer(): for 400 ms
2023-02-03T20:23:12.9379179Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 62, window is 0
2023-02-03T20:23:12.9508474Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 0 frag is 62, window count is 0
2023-02-03T20:23:12.9643905Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:12.9784890Z DEBUG pylibschc.libschc:test_fragmenter.py:224 RECV WINDOW
2023-02-03T20:23:12.9909964Z DEBUG pylibschc.libschc:test_fragmenter.py:224 w == window
2023-02-03T20:23:13.0032261Z DEBUG pylibschc.libschc:test_fragmenter.py:224 not all-x
2023-02-03T20:23:13.0154654Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_local_bitmap(): for fcn 62 at index 0
2023-02-03T20:23:13.0340385Z DEBUG pylibschc.libschc:test_fragmenter.py:224 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2023-02-03T20:23:13.0516030Z DEBUG pylibschc.libschc:fragmenter.py:168 schc_get_connection(): selected connection 0x7a97230 for device 1
2023-02-03T20:23:13.0641946Z DEBUG pylibschc.libschc:fragmenter.py:168 get_fragmentation_rule(): curr rule 0x73ecaa0
2023-02-03T20:23:13.0766652Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x73fe4e0
2023-02-03T20:23:13.0952724Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:13.1079140Z DEBUG pylibschc.libschc:fragmenter.py:168 0: 0x74357a0
2023-02-03T20:23:13.1217734Z DEBUG pylibschc.libschc:fragmenter.py:168 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:13.1346281Z DEBUG pylibschc.libschc:fragmenter.py:179 fcn is 63, window is 0
2023-02-03T20:23:13.1471962Z DEBUG pylibschc.libschc:fragmenter.py:179 value is 63 frag is 63, window count is 0
2023-02-03T20:23:13.1604985Z DEBUG pylibschc.libschc:fragmenter.py:179 set_inactivity_timer(): for 100 ms
2023-02-03T20:23:13.1744909Z DEBUG pylibschc.libschc:fragmenter.py:179 RECV WINDOW
2023-02-03T20:23:13.1867657Z DEBUG pylibschc.libschc:fragmenter.py:179 w == window
2023-02-03T20:23:13.1991219Z DEBUG pylibschc.libschc:fragmenter.py:179 all-1
2023-02-03T20:23:13.2115775Z DEBUG pylibschc.libschc:fragmenter.py:179 set_local_bitmap(): for fcn 63 at index 62
2023-02-03T20:23:13.2295223Z DEBUG pylibschc.libschc:fragmenter.py:179 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
2023-02-03T20:23:13.2461305Z DEBUG pylibschc.libschc:fragmenter.py:179 mic_correct(): received MIC is 90D95D5D
2023-02-03T20:23:13.2586907Z DEBUG pylibschc.libschc:fragmenter.py:179 0: 0x73fe4e0
2023-02-03T20:23:13.2764140Z DEBUG pylibschc.libschc:fragmenter.py:179 0x16 0x3E 0x4C 0x6F 0x72 0x65 0x6D 0x20 0x69 0x70 0x73 0x75 0x6D 0x20 0x64 0x6F 0x6C 0x6F 0x72 0x20 0x73 0x69 0x74 0x20 0x61 0x6D 0x65 0x74 0x2C 0x20 0x63 0x6F 0x6E 0x73 0x65 0x74 0x65 0x74 0x75 0x72 0x20 0x73 0x61 0x64 0x69 0x70 0x73 0x63 0x69 0x6E 0x67 0x20 0x65 0x6C 0x69 0x74 0x72 0x2C 0x20 0x73
2023-02-03T20:23:13.2888174Z DEBUG pylibschc.libschc:fragmenter.py:179 63: 0x74357a0
2023-02-03T20:23:13.3020960Z DEBUG pylibschc.libschc:fragmenter.py:179 0x16 0x3F 0x90 0xD9 0x5D 0x5D 0x65 0x64 0x20 0x64 0x69 0x61 0x6D
2023-02-03T20:23:13.3143924Z DEBUG pylibschc.libschc:fragmenter.py:179 mbuf_compute_mic(): MIC is 90D95D5D
2023-02-03T20:23:13.3269686Z DEBUG pylibschc.libschc:fragmenter.py:179 send_ack(): sending ack to device 1 for fragment 64 with length 2 (11 b)
2023-02-03T20:23:13.3394944Z DEBUG pylibschc.libschc:fragmenter.py:179 16 20
2023-02-03T20:23:13.3603749Z DEBUG pylibschc.libschc:test_fragmenter.py:224 fcn is 63, window is 0
2023-02-03T20:23:13.3731060Z DEBUG pylibschc.libschc:test_fragmenter.py:224 value is 63 frag is 63, window count is 0
2023-02-03T20:23:13.3860409Z DEBUG pylibschc.libschc:test_fragmenter.py:224 END RX
2023-02-03T20:23:13.4000233Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): set head
2023-02-03T20:23:13.4125157Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x73fe560
2023-02-03T20:23:13.4252234Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): mbuf is head, delete head
2023-02-03T20:23:13.4377510Z DEBUG pylibschc.libschc:test_fragmenter.py:224 mbuf_delete(): free 0x52f6300
2023-02-03T20:23:13.4500040Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): trying to free 0x7a97230
2023-02-03T20:23:13.4625395Z DEBUG pylibschc.libschc:test_fragmenter.py:224 schc_free_connection(): free'd 0x7a97230
2023-02-03T20:23:13.4754297Z DEBUG pylibschc.libschc:test_fragmenter.py:224 WAIT_BITMAP
2023-02-03T20:23:13.4881580Z DEBUG pylibschc.libschc:test_fragmenter.py:224 timer expired
2023-02-03T20:23:13.5014843Z DEBUG pylibschc.libschc:test_fragmenter.py:224 send_tx_empty() for device 1
2023-02-03T20:23:13.5140992Z DEBUG pylibschc.libschc:test_fragmenter.py:224 set_dc_timer(): for 100 ms
2023-02-03T20:23:13.5323413Z DEBUG pylibschc.libschc:fragmenter.py:86 WAIT_BITMAP
2023-02-03T20:23:13.5449402Z DEBUG pylibschc.libschc:fragmenter.py:86 received bitmap == local bitmap
2023-02-03T20:23:13.5570221Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_fragment(): end transmission cycle
2023-02-03T20:23:13.5705984Z DEBUG pylibschc.libschc:fragmenter.py:86 schc_free_connection(): trying to free 0x7793450
2023-02-03T20:23:14.2038893Z PASSED [ 44%]
2023-02-03T20:23:14.2040091Z ------------------------------ live log teardown -------------------------------
2023-02-03T20:23:14.2040934Z DEBUG asyncio:selector_events.py:54 Using selector: EpollSelector
2023-02-03T20:23:14.2708922Z
2023-02-03T20:23:14.4502485Z tests/test_rules.py::test_compression_rule_field[Invalid Enum value] PASSED [ 45%]
2023-02-03T20:23:14.6263994Z tests/test_rules.py::test_compression_rule_field[target_value bytes longer than field_length bits] PASSED [ 46%]
2023-02-03T20:23:14.7924909Z tests/test_rules.py::test_compression_rule_field[target_value int overflows field_length bits] PASSED [ 47%]
2023-02-03T20:23:14.9560219Z tests/test_rules.py::test_compression_rule_field[target_value int in bytes longer than field_length bits] PASSED [ 48%]
2023-02-03T20:23:15.1266738Z tests/test_rules.py::test_compression_rule_field[MO_param_length < target_value list with MATCHMAP/MAPPINGSENT] PASSED [ 50%]
2023-02-03T20:23:15.3039263Z tests/test_rules.py::test_compression_rule_field[MO_param_length > target_value list with MATCHMAP/MAPPINGSENT] PASSED [ 51%]
2023-02-03T20:23:15.4732554Z tests/test_rules.py::test_compression_rule_field[MO_param_length > field_length with MSB/LSB] PASSED [ 52%]
2023-02-03T20:23:15.6553880Z tests/test_rules.py::test_compression_rule_field[IPv6 address target_value with prefix too long] PASSED [ 53%]
2023-02-03T20:23:15.8312096Z tests/test_rules.py::test_compression_rule_field[IPv6 address target_value with suffix bytes too long] PASSED [ 54%]
2023-02-03T20:23:16.0081659Z tests/test_rules.py::test_compression_rule_field[IPv6 address target_value with suffix bits too long] PASSED [ 55%]
2023-02-03T20:23:16.1808362Z tests/test_rules.py::test_compression_rule_field[IPv6 address target_value with no address field identifier] PASSED [ 57%]
2023-02-03T20:23:16.9849971Z tests/test_rules.py::test_compression_rule_field[Success: use defaults] PASSED [ 58%]
2023-02-03T20:23:17.2092988Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with bytes target_value] PASSED [ 59%]
2023-02-03T20:23:17.4170815Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with string target_value] PASSED [ 60%]
2023-02-03T20:23:17.6183539Z tests/test_rules.py::test_compression_rule_field[Success: sub-bits field_length with bytes target_value] PASSED [ 61%]
2023-02-03T20:23:17.8251106Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with IPv6 address target_value with prefix field] PASSED [ 63%]
2023-02-03T20:23:18.0372396Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with IPv6 prefix target_value with prefix field] PASSED [ 64%]
2023-02-03T20:23:18.2551478Z tests/test_rules.py::test_compression_rule_field[Success: sub-bits field_length with IPv6 address target_value with prefix field] PASSED [ 65%]
2023-02-03T20:23:18.4720704Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with IPv6 address target_value with IID field] PASSED [ 66%]
2023-02-03T20:23:18.6894191Z tests/test_rules.py::test_compression_rule_field[Success: full-byte field_length with IPv6 prefix target_value with IID field] PASSED [ 67%]
2023-02-03T20:23:18.9047288Z tests/test_rules.py::test_compression_rule_field[Success: sub-bits field_length with IPv6 address target_value with IID field] PASSED [ 69%]
2023-02-03T20:23:19.1130153Z tests/test_rules.py::test_compression_rule_field[Success: Mapping values as target_value list with MAPPINGSENT] PASSED [ 70%]
2023-02-03T20:23:19.3222219Z tests/test_rules.py::test_compression_rule_field[Success: Mapping values as bytes target_value with MAPPINGSENT] PASSED [ 71%]
2023-02-03T20:23:19.5237485Z tests/test_rules.py::test_compression_rule_field[Success: Mapping values as target_value list with NOTSENT] PASSED [ 72%]
2023-02-03T20:23:19.7909499Z tests/test_rules.py::test_compression_rule_field[Success: Mapping values as target_value IPv6 list with MAPPINGSENT] PASSED [ 73%]
2023-02-03T20:23:19.9790161Z tests/test_rules.py::test_compression_rule_field[Success: MSB/LSB MO_param_length] PASSED [ 75%]
2023-02-03T20:23:20.1445652Z tests/test_rules.py::test_compression_rule_field_c_schc_field_declaration[field0-{ IP6_V, 0, 4, 1, BI, {0x06}, &mo_ignore, NOTSENT }] PASSED [ 76%]
2023-02-03T20:23:20.3099370Z tests/test_rules.py::test_compression_rule_field_c_schc_field_declaration[field1-{ IP6_FL, 0, 20, 1, BI, {0x00, 0x00, 0x00}, &mo_ignore, NOTSENT }] PASSED [ 77%]
2023-02-03T20:23:20.4773593Z tests/test_rules.py::test_compression_rule_field_c_schc_field_declaration[field2-{ IP6_DEVPRE, 44, 104, 1, BI, {\n 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x01, 0x00, 0x00,\n 0x00, 0x00, 0x00, 0x00, 0x00\n }, &mo_MSB, LSB }] PASSED [ 78%]
2023-02-03T20:23:20.6536220Z tests/test_rules.py::test_compression_rule_field_c_schc_field_declaration[field3-{ IP6_DEVPRE, 4, 44, 1, BI, {\n 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x10,\n 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x20,\n 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x30,\n 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x40\n }, &mo_matchmap, MAPPINGSENT }] PASSED [ 79%]
2023-02-03T20:23:20.8189223Z tests/test_rules.py::test_compression_rule[No Rule-ID] PASSED [ 80%]
2023-02-03T20:23:20.9799003Z tests/test_rules.py::test_compression_rule[Rule-ID does not fit Rule-ID size bits] PASSED [ 82%]
2023-02-03T20:23:21.1730749Z tests/test_rules.py::test_compression_rule[CoAP field in IPv6 rule] PASSED [ 83%]
2023-02-03T20:23:21.3446343Z tests/test_rules.py::test_compression_rule[IPv6 field in UDP rule] PASSED [ 84%]
2023-02-03T20:23:21.5127602Z tests/test_rules.py::test_compression_rule[UDP field in CoAP rule] PASSED [ 85%]
2023-02-03T20:23:21.9871149Z tests/test_rules.py::test_compression_rule[Success] PASSED [ 86%]
2023-02-03T20:23:22.1282815Z tests/test_rules.py::test_compression_rule_c_schc_layer_rule_declaration_no_layer_rule PASSED [ 88%]
2023-02-03T20:23:22.3348347Z tests/test_rules.py::test_compression_rule_c_schc_ipv6_rule_declaration PASSED [ 89%]
2023-02-03T20:23:22.5168855Z tests/test_rules.py::test_compression_rule_c_schc_udp_rule_declaration PASSED [ 90%]
2023-02-03T20:23:22.6614384Z tests/test_rules.py::test_compression_rule_c_schc_coap_rule_declaration PASSED [ 91%]
2023-02-03T20:23:22.8109954Z tests/test_rules.py::test_compression_rule_c_schc_declaration PASSED [ 92%]
2023-02-03T20:23:22.9413686Z tests/test_rules.py::test_fragmentation_rule_c_schc_declaration PASSED [ 94%]
2023-02-03T20:23:23.0777149Z tests/test_rules.py::test_device_rule_id_duplicates PASSED [ 95%]
2023-02-03T20:23:23.2175643Z tests/test_rules.py::test_device_c_schc_declaration PASSED [ 96%]
2023-02-03T20:23:23.3583863Z tests/test_rules.py::test_config_duplicate_device PASSED [ 97%]
2023-02-03T20:23:25.5724128Z tests/test_rules.py::test_config_to_c_header PASSED [ 98%]
2023-02-03T20:23:27.4748249Z ==4671== Warning: invalid file descriptor 65524 in syscall close()
2023-02-03T20:23:27.4752384Z ==4671== Warning: invalid file descriptor 65525 in syscall close()
2023-02-03T20:23:27.4753222Z ==4671== Warning: invalid file descriptor 65526 in syscall close()
2023-02-03T20:23:27.4764190Z ==4671== Warning: invalid file descriptor 65527 in syscall close()
2023-02-03T20:23:27.4765233Z ==4671== Use --log-fd=<number> to select an alternative log fd.
2023-02-03T20:23:27.4766163Z ==4671== Warning: invalid file descriptor 65528 in syscall close()
2023-02-03T20:23:27.4766804Z ==4671== Warning: invalid file descriptor 65529 in syscall close()
2023-02-03T20:23:27.8968894Z ==4690== Warning: invalid file descriptor 65524 in syscall close()
2023-02-03T20:23:27.8977118Z ==4690== Warning: invalid file descriptor 65525 in syscall close()
2023-02-03T20:23:27.8977808Z ==4690== Warning: invalid file descriptor 65526 in syscall close()
2023-02-03T20:23:27.8981878Z ==4690== Warning: invalid file descriptor 65527 in syscall close()
2023-02-03T20:23:27.8982978Z ==4690== Use --log-fd=<number> to select an alternative log fd.
2023-02-03T20:23:27.8984119Z ==4690== Warning: invalid file descriptor 65528 in syscall close()
2023-02-03T20:23:27.8984751Z ==4690== Warning: invalid file descriptor 65529 in syscall close()
2023-02-03T20:23:28.5181670Z ==4714== Warning: invalid file descriptor 65524 in syscall close()
2023-02-03T20:23:28.5190544Z ==4714== Warning: invalid file descriptor 65525 in syscall close()
2023-02-03T20:23:28.5191911Z ==4714== Warning: invalid file descriptor 65526 in syscall close()
2023-02-03T20:23:28.5192524Z ==4714== Warning: invalid file descriptor 65527 in syscall close()
2023-02-03T20:23:28.5193412Z ==4714== Use --log-fd=<number> to select an alternative log fd.
2023-02-03T20:23:28.5193962Z ==4714== Warning: invalid file descriptor 65528 in syscall close()
2023-02-03T20:23:28.5194399Z ==4714== Warning: invalid file descriptor 65529 in syscall close()
2023-02-03T20:24:27.8053964Z tests/test_rules.py::test_config_to_c_header_compilable PASSED [100%]
2023-02-03T20:24:27.8054677Z
2023-02-03T20:24:27.8056670Z -- generated xml file: /home/runner/work/pylibschc/pylibschc/test-report.xml ---
2023-02-03T20:24:27.8058689Z
2023-02-03T20:24:27.8059322Z ---------- coverage: platform linux, python 3.10.9-final-0 -----------
2023-02-03T20:24:27.8059775Z Name Stmts Miss Branch BrPart Cover Missing
2023-02-03T20:24:27.8060362Z ----------------------------------------------------------------------------------------------------------------
2023-02-03T20:24:27.8061020Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/__init__.py 5 0 0 0 100%
2023-02-03T20:24:27.8061595Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/_pydantic.py 24 0 4 0 100%
2023-02-03T20:24:27.8062297Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/compressor.py 34 0 12 0 100%
2023-02-03T20:24:27.8062848Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/device.py 88 0 28 0 100%
2023-02-03T20:24:27.8063454Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/fragmenter.py 89 0 14 0 100%
2023-02-03T20:24:27.8063987Z .tox/valgrind/lib/python3.10/site-packages/pylibschc/rules.py 333 0 109 0 100%
2023-02-03T20:24:27.8072483Z tests/__init__.py 0 0 0 0 100%
2023-02-03T20:24:27.8073316Z tests/conftest.py 43 0 6 0 100%
2023-02-03T20:24:27.8073906Z tests/test_bitarray.py 36 0 6 0 100%
2023-02-03T20:24:27.8074456Z tests/test_compressor.py 51 0 8 0 100%
2023-02-03T20:24:27.8074887Z tests/test_debug.py 35 0 16 0 100%
2023-02-03T20:24:27.8075573Z tests/test_device.py 64 0 10 0 100%
2023-02-03T20:24:27.8076029Z tests/test_fragmenter.py 142 0 38 0 100%
2023-02-03T20:24:27.8076854Z tests/test_rules.py 98 0 20 0 100%
2023-02-03T20:24:27.8077607Z ----------------------------------------------------------------------------------------------------------------
2023-02-03T20:24:27.8078167Z TOTAL 1042 0 271 0 100%
2023-02-03T20:24:27.8086401Z Coverage XML written to file coverage.xml
2023-02-03T20:24:27.8086835Z
2023-02-03T20:24:27.8087316Z ================= 84 passed, 1 deselected in 209.42s (0:03:29) =================
2023-02-03T20:24:31.6185669Z ==3139==
2023-02-03T20:24:31.6191654Z ==3139== HEAP SUMMARY:
2023-02-03T20:24:31.6192231Z ==3139== in use at exit: 7,199,751 bytes in 5,953 blocks
2023-02-03T20:24:31.6192903Z ==3139== total heap usage: 197,533 allocs, 191,580 frees, 271,596,243 bytes allocated
2023-02-03T20:24:31.6240526Z ==3139==
2023-02-03T20:24:31.8872293Z ==3139== LEAK SUMMARY:
2023-02-03T20:24:31.8872695Z ==3139== definitely lost: 0 bytes in 0 blocks
2023-02-03T20:24:31.8873013Z ==3139== indirectly lost: 0 bytes in 0 blocks
2023-02-03T20:24:31.8873342Z ==3139== possibly lost: 610,676 bytes in 754 blocks
2023-02-03T20:24:31.8874090Z ==3139== still reachable: 6,589,075 bytes in 5,199 blocks
2023-02-03T20:24:31.8874411Z ==3139== suppressed: 0 bytes in 0 blocks
2023-02-03T20:24:31.8874778Z ==3139== Reachable blocks (those to which a pointer was found) are not shown.
2023-02-03T20:24:31.8875504Z ==3139== To see them, rerun with: --leak-check=full --show-leak-kinds=all
2023-02-03T20:24:31.8875802Z ==3139==
2023-02-03T20:24:31.8876113Z ==3139== ERROR SUMMARY: 196 errors from 192 contexts (suppressed: 0 from 0)
2023-02-03T20:24:31.8876414Z ==3139==
2023-02-03T20:24:31.8876641Z ==3139== 5 errors in context 1 of 192:
2023-02-03T20:24:31.8876921Z ==3139== Invalid read of size 8
2023-02-03T20:24:31.8877246Z ==3139== at 0x93CEC0D: __Pyx_PyBool_FromLong (libschc.c:27970)
2023-02-03T20:24:31.8877685Z ==3139== by 0x93CEC0D: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_12_allocated (libschc.c:13609)
2023-02-03T20:24:31.8878193Z ==3139== by 0x93CEC0D: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_13_allocated (libschc.c:13573)
2023-02-03T20:24:31.8878630Z ==3139== by 0x93C879B: __Pyx_PyObject_CallMethO (libschc.c:22503)
2023-02-03T20:24:31.8886120Z ==3139== by 0x93C879B: __Pyx_PyObject_CallNoArg (libschc.c:23781)
2023-02-03T20:24:31.8886621Z ==3139== by 0x93C879B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task__timer_task_wrapper (libschc.c:14733)
2023-02-03T20:24:31.8887204Z ==3139== by 0x93C879B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_18_c_post_timer_task_1_timer_task_wrapper (libschc.c:14685)
2023-02-03T20:24:31.8887660Z ==3139== by 0x49B0CFE: _PyObject_MakeTpCall (call.c:215)
2023-02-03T20:24:31.8888002Z ==3139== by 0x4A1799C: call_function (ceval.c:5888)
2023-02-03T20:24:31.8888337Z ==3139== by 0x4A1799C: _PyEval_EvalFrameDefault (ceval.c:4213)
2023-02-03T20:24:31.8888717Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8889063Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8889375Z ==3139== by 0x4A13A75: do_call_core (ceval.c:5943)
2023-02-03T20:24:31.8889716Z ==3139== by 0x4A13A75: _PyEval_EvalFrameDefault (ceval.c:4277)
2023-02-03T20:24:31.8890079Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8890406Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8890769Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8891127Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:24:31.8891475Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8895163Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8895823Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8898742Z ==3139== by 0x4A11550: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8899127Z ==3139== by 0x4A11550: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:24:31.8899475Z ==3139== by 0x4A11550: call_function (ceval.c:5891)
2023-02-03T20:24:31.8899815Z ==3139== by 0x4A11550: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8900183Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8900510Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8901139Z ==3139== Address 0x6acbac0 is 112 bytes inside a block of size 168 free'd
2023-02-03T20:24:31.8902262Z ==3139== at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
2023-02-03T20:24:31.8902734Z ==3139== by 0x93BE825: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_28reset (libschc.c:17588)
2023-02-03T20:24:31.8903225Z ==3139== by 0x93BE825: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_29reset (libschc.c:17558)
2023-02-03T20:24:31.8903657Z ==3139== by 0x93C7941: __Pyx_PyObject_CallMethO (libschc.c:22503)
2023-02-03T20:24:31.8904023Z ==3139== by 0x93C7941: __Pyx_PyObject_CallNoArg (libschc.c:23781)
2023-02-03T20:24:31.8965096Z ==3139== by 0x93C7941: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__reassemble (libschc.c:17372)
2023-02-03T20:24:31.8965656Z ==3139== by 0x93C2F6E: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_26reassemble (libschc.c:17519)
2023-02-03T20:24:31.8966153Z ==3139== by 0x93C2F6E: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_27reassemble (libschc.c:17495)
2023-02-03T20:24:31.8966590Z ==3139== by 0x49D6CE4: cfunction_vectorcall_NOARGS (methodobject.c:489)
2023-02-03T20:24:31.8966962Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8967329Z ==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:24:31.8967676Z ==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
2023-02-03T20:24:31.8968006Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:24:31.8968328Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8968687Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8969022Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8969355Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8969696Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:24:31.8970026Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8977324Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8977685Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8978120Z ==3139== Block was alloc'd at
2023-02-03T20:24:31.8978615Z ==3139== at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
2023-02-03T20:24:31.8979023Z ==3139== by 0x93E79E9: schc_get_connection (fragmenter.c:1319)
2023-02-03T20:24:31.8979382Z ==3139== by 0x93E9851: schc_fragment_input (fragmenter.c:2367)
2023-02-03T20:24:31.8980149Z ==3139== by 0x93DA17E: __pyx_f_9pylibschc_7libschc_23FragmentationConnection__input (libschc.c:16623)
2023-02-03T20:24:31.8980852Z ==3139== by 0x93C4F1B: __pyx_pf_9pylibschc_7libschc_23FragmentationConnection_24input (libschc.c:17085)
2023-02-03T20:24:31.8981350Z ==3139== by 0x93C4F1B: __pyx_pw_9pylibschc_7libschc_23FragmentationConnection_25input (libschc.c:16994)
2023-02-03T20:24:31.8981784Z ==3139== by 0x49D6DB6: cfunction_vectorcall_O (methodobject.c:516)
2023-02-03T20:24:31.8982177Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8982537Z ==3139== by 0x4A8BEC1: PyObject_Vectorcall (abstract.h:123)
2023-02-03T20:24:31.8982889Z ==3139== by 0x4A8BEC1: trace_call_function (ceval.c:5862)
2023-02-03T20:24:31.8983223Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:24:31.8991110Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8991656Z ==3139== by 0x4A0FFE5: _PyEval_EvalFrame (pycore_ceval.h:46)
2023-02-03T20:24:31.8992012Z ==3139== by 0x4A0FFE5: _PyEval_Vector (ceval.c:5065)
2023-02-03T20:24:31.8992375Z ==3139== by 0x4A8B4B3: _PyObject_VectorcallTstate (abstract.h:114)
2023-02-03T20:24:31.8992717Z ==3139== by 0x4A179EB: call_function (ceval.c:5888)
2023-02-03T20:24:31.8993067Z ==3139== by 0x4A179EB: _PyEval_EvalFrameDefault (ceval.c:4198)
2023-02-03T20:24:31.8993364Z ==3139==
2023-02-03T20:24:31.8994446Z ==3139== ERROR SUMMARY: 196 errors from 192 contexts (suppressed: 0 from 0)
2023-02-03T20:24:31.9064520Z .pkg: _exit> python /opt/hostedtoolcache/Python/3.10.9/x64/lib/python3.10/site-packages/pyproject_api/_backend.py True setuptools.build_meta
2023-02-03T20:24:32.0339839Z valgrind: OK (329.04=setup[58.43]+cmd[270.62] seconds)
2023-02-03T20:24:32.0340219Z congratulations :) (329.77 seconds)
I've tried to install this python module via pip but the compiling have some problems.
OS: Linux
Python version: 3.10.13 and also with 3.11.6
$ pip install pylibschc
Collecting pylibschc
Downloading pylibschc-0.2.0b2.tar.gz (244 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 244.1/244.1 kB 9.8 MB/s eta 0:00:00
Installing build dependencies ... done
Getting requirements to build wheel ... done
Preparing metadata (pyproject.toml) ... error
error: subprocess-exited-with-error
× Preparing metadata (pyproject.toml) did not run successfully.
│ exit code: 1
╰─> [156 lines of output]
running dist_info
creating /tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info
writing /tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info/PKG-INFO
writing dependency_links to /tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info/dependency_links.txt
writing requirements to /tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info/requires.txt
writing top-level names to /tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info/top_level.txt
writing manifest file '/tmp/pip-modern-metadata-_3swzh_5/pylibschc.egg-info/SOURCES.txt'
Error compiling Cython file:
------------------------------------------------------------
...
else:
self._frag_conn = NULL
cdef _init_ops(self):
self._frag_conn.timer_ctx = <void *>self
self._frag_conn.send = self._send
^
------------------------------------------------------------
pylibschc/libschc.pyx:1021:35: Cannot assign type 'uint8_t (uint8_t *, uint16_t, uint32_t) except *' to 'uint8_t (*)(uint8_t *, uint16_t, uint32_t) noexcept'. Exception values are incompatible. Suggest adding 'noexcept' to type 'uint8_t (uint8_t *, uint16_t, uint32_t) except *'.
Error compiling Cython file:
------------------------------------------------------------
...
self._frag_conn = NULL
cdef _init_ops(self):
self._frag_conn.timer_ctx = <void *>self
self._frag_conn.send = self._send
self._frag_conn.post_timer_task = self._c_post_timer_task
^
------------------------------------------------------------
pylibschc/libschc.pyx:1022:46: Cannot assign type 'void (schc_fragmentation_t *, void (*)(void *) except *, uint32_t, void *) except *' to 'void (*)(schc_fragmentation_t *, void (*)(void *) noexcept, uint32_t, void *) noexcept'
Error compiling Cython file:
------------------------------------------------------------
...
cdef _init_ops(self):
self._frag_conn.timer_ctx = <void *>self
self._frag_conn.send = self._send
self._frag_conn.post_timer_task = self._c_post_timer_task
self._frag_conn.end_rx = self._c_end_rx
^
------------------------------------------------------------
pylibschc/libschc.pyx:1023:37: Cannot assign type 'void (schc_fragmentation_t *) except *' to 'void (*)(schc_fragmentation_t *) noexcept'. Exception values are incompatible. Suggest adding 'noexcept' to type 'void (schc_fragmentation_t *) except *'.
Error compiling Cython file:
------------------------------------------------------------
...
cdef _init_ops(self):
self._frag_conn.timer_ctx = <void *>self
self._frag_conn.send = self._send
self._frag_conn.post_timer_task = self._c_post_timer_task
self._frag_conn.end_rx = self._c_end_rx
self._frag_conn.end_tx = self._c_end_tx
^
------------------------------------------------------------
pylibschc/libschc.pyx:1024:37: Cannot assign type 'void (schc_fragmentation_t *) except *' to 'void (*)(schc_fragmentation_t *) noexcept'. Exception values are incompatible. Suggest adding 'noexcept' to type 'void (schc_fragmentation_t *) except *'.
Error compiling Cython file:
------------------------------------------------------------
...
self._frag_conn.timer_ctx = <void *>self
self._frag_conn.send = self._send
self._frag_conn.post_timer_task = self._c_post_timer_task
self._frag_conn.end_rx = self._c_end_rx
self._frag_conn.end_tx = self._c_end_tx
self._frag_conn.remove_timer_entry = self._c_remove_timer_entry
^
------------------------------------------------------------
pylibschc/libschc.pyx:1025:49: Cannot assign type 'void (schc_fragmentation_t *) except *' to 'void (*)(schc_fragmentation_t *) noexcept'. Exception values are incompatible. Suggest adding 'noexcept' to type 'void (schc_fragmentation_t *) except *'.
Error compiling Cython file:
------------------------------------------------------------
...
self._frag_conn.send = self._send
self._frag_conn.post_timer_task = self._c_post_timer_task
self._frag_conn.end_rx = self._c_end_rx
self._frag_conn.end_tx = self._c_end_tx
self._frag_conn.remove_timer_entry = self._c_remove_timer_entry
self._frag_conn.free_conn_cb = self._c_free_conn_cb
^
------------------------------------------------------------
pylibschc/libschc.pyx:1026:43: Cannot assign type 'void (schc_fragmentation_t *) except *' to 'void (*)(schc_fragmentation_t *) noexcept'. Exception values are incompatible. Suggest adding 'noexcept' to type 'void (schc_fragmentation_t *) except *'.
Compiling pylibschc/libschc.pyx because it changed.
[1/1] Cythonizing pylibschc/libschc.pyx
Traceback (most recent call last):
File "/home/dldyat/documents/develop/youandtech/clienti/unidata/converter-deveui-ip/venv/lib64/python3.11/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 353, in <module>
main()
File "/home/dldyat/documents/develop/youandtech/clienti/unidata/converter-deveui-ip/venv/lib64/python3.11/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 335, in main
json_out['return_val'] = hook(**hook_input['kwargs'])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/dldyat/documents/develop/youandtech/clienti/unidata/converter-deveui-ip/venv/lib64/python3.11/site-packages/pip/_vendor/pyproject_hooks/_in_process/_in_process.py", line 149, in prepare_metadata_for_build_wheel
return hook(metadata_directory, config_settings)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/build_meta.py", line 366, in prepare_metadata_for_build_wheel
self.run_setup()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/build_meta.py", line 311, in run_setup
exec(code, locals())
File "<string>", line 54, in <module>
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/__init__.py", line 103, in setup
return distutils.core.setup(**attrs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/core.py", line 185, in setup
return run_commands(dist)
^^^^^^^^^^^^^^^^^^
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/core.py", line 201, in run_commands
dist.run_commands()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/dist.py", line 969, in run_commands
self.run_command(cmd)
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/dist.py", line 963, in run_command
super().run_command(command)
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/dist.py", line 988, in run_command
cmd_obj.run()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/dist_info.py", line 91, in run
self.egg_info.run()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/egg_info.py", line 321, in run
self.find_sources()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/egg_info.py", line 329, in find_sources
mm.run()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/egg_info.py", line 551, in run
self.add_defaults()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/egg_info.py", line 589, in add_defaults
sdist.add_defaults(self)
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/sdist.py", line 112, in add_defaults
super().add_defaults()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/command/sdist.py", line 249, in add_defaults
self._add_defaults_python()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/sdist.py", line 123, in _add_defaults_python
build_py = self.get_finalized_command('build_py')
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/cmd.py", line 305, in get_finalized_command
cmd_obj.ensure_finalized()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/cmd.py", line 111, in ensure_finalized
self.finalize_options()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/command/build_py.py", line 39, in finalize_options
orig.build_py.finalize_options(self)
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/command/build_py.py", line 46, in finalize_options
self.set_undefined_options(
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/cmd.py", line 293, in set_undefined_options
src_cmd_obj.ensure_finalized()
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib/python3.11/site-packages/setuptools/_distutils/cmd.py", line 111, in ensure_finalized
self.finalize_options()
File "<string>", line 43, in finalize_options
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib64/python3.11/site-packages/Cython/Build/Dependencies.py", line 1154, in cythonize
cythonize_one(*args)
File "/tmp/pip-build-env-tkdhdnp3/overlay/lib64/python3.11/site-packages/Cython/Build/Dependencies.py", line 1321, in cythonize_one
raise CompileError(None, pyx_file)
Cython.Compiler.Errors.CompileError: pylibschc/libschc.pyx
[end of output]
note: This error originates from a subprocess, and is likely not a problem with pip.
error: metadata-generation-failed
× Encountered error while generating package metadata.
╰─> See above for output.
note: This is an issue with the package mentioned above, not pip.
hint: See above for details.
A declarative, efficient, and flexible JavaScript library for building user interfaces.
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
An Open Source Machine Learning Framework for Everyone
The Web framework for perfectionists with deadlines.
A PHP framework for web artisans
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
Some thing interesting about web. New door for the world.
A server is a program made to process requests and deliver data to clients.
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
Some thing interesting about visualization, use data art
Some thing interesting about game, make everyone happy.
We are working to build community through open source technology. NB: members must have two-factor auth.
Open source projects and samples from Microsoft.
Google ❤️ Open Source for everyone.
Alibaba Open Source for everyone
Data-Driven Documents codes.
China tencent open source team.