bug: OSError during test execution after migration to sdc11073 v2 version

[jannast]

Is there an existing issue for this?

• I have searched the existing issues

Current Behavior

During running test implementations with the new sdc11073 v2 version we observed that an error was multiple times logged (almost in every test case). It seems to be related to unsubscribe: end of subscription.

Log messages at start of a test:

2024-02-02 09:59:05,075 - sdc.client - INFO - Using SSL is enabled. TLS 1.3 Support = True
2024-02-02 09:59:05,075 - sdc.client - INFO - created SdcConsumer for https://127.0.0.1:55160/0d11ac9c95f74fecb9b1dc05bca50470
2024-02-02 09:59:05,107 - sdc.client.soap - INFO - created soap client No. 1 for 127.0.0.1:55160
2024-02-02 09:59:05,153 - sdc.client.soap - INFO - soap client No. 1 uses connection=127.0.0.1:55166
2024-02-02 09:59:05,153 - sdc.client - INFO - Peer Certificate: {'subject': ((('countryName', 'DE'),), (('organizationName', 'Draeger'),), (('commonName', 'PySDC_TEST-RTF_305'),)), 'issuer': ((('countryName', 'DE'),), (('organizationName', 'Draeger'),), (('commonName', 'Draeger Device Root CA - Test'),)), 'version': 3, 'serialNumber': '15BB5831BE3CCADBDF96654C9B2D4233F07DB7A1', 'notBefore': 'Jan 19 15:04:54 2022 GMT', 'notAfter': 'May 23 15:04:54 2084 GMT'}
2024-02-02 09:59:05,155 - sdc.device - INFO - _on_get_metadata from ('127.0.0.1', 55166)
2024-02-02 09:59:05,195 - sdc.client - INFO - SdcConsumer for https://127.0.0.1:55160/0d11ac9c95f74fecb9b1dc05bca50470 uses network adapter Loopback Pseudo-Interface 1: 127.0.0.1/8
2024-02-02 09:59:05,196 - sdc.client.notif_dispatch - INFO - starting http server on 127.0.0.1:55167
2024-02-02 09:59:05,196 - sdc.client - INFO - serving EventSink on https://127.0.0.1:55167/
2024-02-02 09:59:05,197 - sdc.client.subscr - INFO - start subscription "WaveformStream, EpisodicOperationalStateReport, EpisodicComponentReport, PeriodicOperationalStateReport, SystemErrorReport, EpisodicContextReport, PeriodicContextReport, DescriptionModificationReport, EpisodicAlertReport, PeriodicComponentReport, EpisodicMetricReport, PeriodicAlertReport, PeriodicMetricReport"
2024-02-02 09:59:05,199 - sdc.device.subscrMgr - INFO - new BicepsSubscriptionAsync(notify_to=https://127.0.0.1:55167/5b83183331cd4b28a2d5ff512ba4bb1f/subscr1 ident=[], my identifier=4cd19c68ea7c4d67a13575330fb445ac, expires=15, filter=['WaveformStream', 'EpisodicOperationalStateReport', 'EpisodicComponentReport', 'PeriodicOperationalStateReport', 'SystemErrorReport', 'EpisodicContextReport', 'PeriodicContextReport', 'DescriptionModificationReport', 'EpisodicAlertReport', 'PeriodicComponentReport', 'EpisodicMetricReport', 'PeriodicAlertReport', 'PeriodicMetricReport'])
2024-02-02 09:59:05,200 - sdc.client.subscr - INFO - Subscribe was successful: expires at 1706864360.2002678, address="https://127.0.0.1:55160/0d11ac9c95f74fecb9b1dc05bca50470/StateEvent/4cd19c68ea7c4d67a13575330fb445ac"
2024-02-02 09:59:05,201 - sdc.client.subscr - INFO - start subscription "OperationInvokedReport"
2024-02-02 09:59:05,202 - sdc.device.subscrMgr - INFO - new BicepsSubscriptionAsync(notify_to=https://127.0.0.1:55167/5b83183331cd4b28a2d5ff512ba4bb1f/subscr2 ident=[], my identifier=36198b435b40404291c8a5a073d3ac23, expires=15, filter=['OperationInvokedReport'])
2024-02-02 09:59:05,203 - sdc.client.subscr - INFO - Subscribe was successful: expires at 1706864360.2032702, address="https://127.0.0.1:55160/0d11ac9c95f74fecb9b1dc05bca50470/Set/36198b435b40404291c8a5a073d3ac23"
2024-02-02 09:59:05,204 - sdc.client.mdib - INFO - initializing mdib...
2024-02-02 09:59:05,256 - sdc.client.mdib - INFO - creating description containers...
2024-02-02 09:59:05,257 - sdc.client.mdib - INFO - creating state containers...
2024-02-02 09:59:05,258 - sdc.client.mdib - INFO - setting initial mdib version to 4
2024-02-02 09:59:05,258 - sdc.client.mdib - INFO - setting initial sequence id to urn:uuid:7ac97c61-cc7e-496a-bd27-7e2964efc753
2024-02-02 09:59:05,258 - sdc.client.mdib - INFO - setting initial instance id to None
2024-02-02 09:59:05,258 - sdc.client.mdib - INFO - found context states in GetMdib Result, will not call getContextStates
2024-02-02 09:59:05,258 - sdc.client.mdib - INFO - initializing mdib done
2024-02-02 09:59:05,508 - sdc.client.subscr - INFO - unsubscribe: end of subscription https://127.0.0.1:55167/5b83183331cd4b28a2d5ff512ba4bb1f/subscr1 was confirmed.
2024-02-02 09:59:05,510 - sdc.client.subscr - INFO - unsubscribe: end of subscription https://127.0.0.1:55167/5b83183331cd4b28a2d5ff512ba4bb1f/subscr2 was confirmed.
Exception in thread wsd.sendThread:
Traceback (most recent call last):
File "C:\tools\Python\python-3.9.6-win64\lib\threading.py", line 973, in _bootstrap_inner
self.run()
File "C:\tools\Python\python-3.9.6-win64\lib\threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "C:\develop\mgit_repos\T2I\venv39\lib\site-packages\sdc11073\wsdiscovery\networkingthread.py", line 186, in _run_send
self._send_msg(enqueued_msg)
File "C:\develop\mgit_repos\T2I\venv39\lib\site-packages\sdc11073\wsdiscovery\networkingthread.py", line 278, in _send_msg
self.sockets_collection.multi_out_uni_in.sendto(data, (msg.addr, msg.port))
OSError: [WinError 10038] Ein Vorgang bezog sich auf ein Objekt, das kein Socket ist
2024-02-02 09:59:06,198 - sdc.client.subscrMgr - INFO - terminating subscriptions check loop! self._run=False
2024-02-02 09:59:06,198 - sdc.client.soap - INFO - closing soapClientNo 1 for 127.0.0.1:55160
2024-02-02 09:59:06,213 - sdc.client.notif_dispatch - INFO - http server stopped.

at the end of a test case there is this message:

2024-02-02 09:59:08,823 - sdc.client.subscr - INFO - unsubscribe: end of subscription https://127.0.0.1:55173/652065c620f8484bb06f5035ffaa9f07/subscr1 was confirmed.
2024-02-02 09:59:08,825 - sdc.client.subscr - INFO - unsubscribe: end of subscription https://127.0.0.1:55173/652065c620f8484bb06f5035ffaa9f07/subscr2 was confirmed.
2024-02-02 09:59:09,410 - sdc.client.subscrMgr - INFO - terminating subscriptions check loop! self._run=False
2024-02-02 09:59:09,410 - sdc.client.soap - INFO - closing soapClientNo 2 for 127.0.0.1:55160
Exception in thread wsd.sendThread:
Traceback (most recent call last):
File "C:\tools\Python\python-3.9.6-win64\lib\threading.py", line 973, in _bootstrap_inner
self.run()
File "C:\tools\Python\python-3.9.6-win64\lib\threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "C:\develop\mgit_repos\T2I\venv39\lib\site-packages\sdc11073\wsdiscovery\networkingthread.py", line 186, in _run_send
self._send_msg(enqueued_msg)
File "C:\develop\mgit_repos\T2I\venv39\lib\site-packages\sdc11073\wsdiscovery\networkingthread.py", line 278, in _send_msg
self.sockets_collection.multi_out_uni_in.sendto(data, (msg.addr, msg.port))
OSError: [WinError 10038] Ein Vorgang bezog sich auf ein Objekt, das kein Socket ist
2024-02-02 09:59:09,613 - sdc.client.notif_dispatch - INFO - http server stopped.
2024-02-02 09:59:09,614 - sdc.client.notif_dispatch - INFO - closed socket for notifications from ('127.0.0.1', 55174)

Expected Behavior

No sdc11073 erros while using the library.

Minimal Reproducible Example

No response

Solution proposal

No response

Python Version

3.9

Operating system

win32

Sdc11073 Version

2.0.0a7

Link to sdc11073 Logs

No response

Further Information

No response

Participation

• I am willing to submit a pull request to fix this bug.

[maximilianpilz]

Might be fixed by replacing

self._recv_thread.join(1)
self._send_thread.join(1)
self._qread_thread.join(1)

in "sdc11073.wsdiscovery.networkingthread._NetworkingThreadBase.join" with

self._recv_thread.join()
self._send_thread.join()
self._qread_thread.join()