Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

LDS-ME Intermittent Connection Issue on Windows Only #6459

Open
5 of 7 tasks
abehonest opened this issue May 6, 2024 · 0 comments
Open
5 of 7 tasks

LDS-ME Intermittent Connection Issue on Windows Only #6459

abehonest opened this issue May 6, 2024 · 0 comments

Comments

@abehonest
Copy link

Description

I have been experiencing an intermittent issue with the Open62541 LDS-ME server on Windows 10 Pro and don't know what is causing it. After a fresh bootup on Windows the LDS-ME server generally works fine, but after a certain point it will stop discovering servers. I do not know what is triggering it to stop discovering servers as it seems to happen randomly each time I test it. Restarting does not seem to fix this issue, however shutting my PC down, waiting for a minute, then booting my PC back to Windows does seem to temporarily fix it. This problem is only on Windows - my Ubuntu build works perfectly every time.

Background Information / Reproduction Steps

I do not know how to reproduce this issue reliably. The way I get it to trigger is by booting up Windows and running the discovery_server_lds.exe and checking if it sees the servers I know it should be able to see. If it is able to see them, then I will just repeatedly run discovery_server_lds.exe until it can no longer see them. If this does not work, I will do some other work for a while and check again after an hour or so and it will often no longer work then. Running as an administrator makes no difference.

I have also validated that discovery still is possible from my PC using the UA Foundation's official lds-me implementation (https://opcfoundation.github.io/UA-LDS/). Note that I am not running this LDS server as a service. I have disabled it as a service and only run it in debug mode to get debug messages on what servers it has found. I have provided a log of its debug messages below. The OPC Foundation's lds-me server seems to show the same logs regardless of if the intermittent issue with Open62541 is occuring.

All logs shown below are output from the example LDS-ME server (https://github.com/open62541/open62541/blob/master/examples/discovery/server_lds.c) built with Open62541 1.4. The last few entries in each log dump indicate what servers were found. Wireshark logs are packets filtered using the term 'mdns contains "opcua-tcp" and ip.src==MY_IP' which were captured starting right before starting discovery_server_lds and ending ~1minute after starting it up.

Logs from before the intermittent issue hits on Windows 10:

Console Log:

PS C:\Users\LOCALUSER\projects\open62541\build\bin\examples> .\discovery_server_lds.exe
[2024-05-03 12:23:12.401 (UTC-0700)] info/eventloop     Starting the EventLoop
[2024-05-03 12:23:12.401 (UTC-0700)] warn/server        AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-03 12:23:12.401 (UTC-0700)] info/server        AccessControl: Anonymous login is enabled
[2024-05-03 12:23:12.401 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 12:23:12.423 (UTC-0700)] warn/userland      ServerUrls already set. Overriding.
[2024-05-03 12:23:12.423 (UTC-0700)] warn/server        AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-03 12:23:12.424 (UTC-0700)] info/server        AccessControl: Anonymous login is enabled
[2024-05-03 12:23:12.424 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 12:23:12.424 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 12:23:12.425 (UTC-0700)] warn/server        Maximum SecureChannels count not enough for the maximum Sessions count
[2024-05-03 12:23:12.425 (UTC-0700)] info/network       TCP     | Listening on all interfaces
[2024-05-03 12:23:12.431 (UTC-0700)] info/network       TCP 280 | Creating listen socket for "LOCALUSER-ENG-25.BusinessName.local" (with local hostname "LOCALUSER-ENG-25") on port 4840
[2024-05-03 12:23:12.431 (UTC-0700)] info/server        New DiscoveryUrl added: opc.tcp:https://LOCALUSER-ENG-25:4840
[2024-05-03 12:23:12.431 (UTC-0700)] info/network       TCP 468 | Creating listen socket for "LOCALUSER-ENG-25.BusinessName.local" (with local hostname "LOCALUSER-ENG-25") on port 4840
[2024-05-03 12:23:12.441 (UTC-0700)] info/network       UDP 464 | New listen socket for "224.0.0.251" on port 5353
[2024-05-03 12:23:12.441 (UTC-0700)] warn/network       UDP 464 | No network interface defined for multicast. That means the first suitable network interface is used.
[2024-05-03 12:23:12.442 (UTC-0700)] warn/network       UDP 460 | No network interface defined for multicast. That means the first suitable network interface is used.
[2024-05-03 12:23:12.443 (UTC-0700)] info/network       UDP 460 | New connection to "224.0.0.251" on port 5353
[2024-05-03 12:23:12.443 (UTC-0700)] warn/discovery     Cannot add mDNS Record: BadOutOfRange
[2024-05-03 12:23:14.504 (UTC-0700)] info/server        Multicast DNS: found server: opc.tcp:https://User_1-OptiPlex-3080:4840
[2024-05-03 12:23:14.505 (UTC-0700)] info/server        Multicast DNS: found server: opc.tcp:https://10.0.0.150:4845

Wireshark Log:
wireshark_windows_working_short

Logs from after the intermittent issue hits on Windows:

Console Log:

PS C:\Users\LOCALUSER\projects\open62541\build\bin\examples> ./discovery_server_lds.exe
[2024-05-02 12:02:44.466 (UTC-0700)] info/eventloop     Starting the EventLoop
[2024-05-02 12:02:44.466 (UTC-0700)] warn/server        AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-02 12:02:44.466 (UTC-0700)] info/server        AccessControl: Anonymous login is enabled
[2024-05-02 12:02:44.466 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-02 12:02:44.482 (UTC-0700)] warn/userland      ServerUrls already set. Overriding.
[2024-05-02 12:02:44.482 (UTC-0700)] warn/server        AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-02 12:02:44.482 (UTC-0700)] info/server        AccessControl: Anonymous login is enabled
[2024-05-02 12:02:44.498 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-02 12:02:44.498 (UTC-0700)] warn/server        x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-02 12:02:44.498 (UTC-0700)] warn/server        Maximum SecureChannels count not enough for the maximum Sessions count
[2024-05-02 12:02:44.498 (UTC-0700)] info/network       TCP     | Listening on all interfaces
[2024-05-02 12:02:44.513 (UTC-0700)] info/network       TCP 280 | Creating listen socket for "LOCALUSER-ENG-25.BusinessName.local" (with local hostname "LOCALUSER-ENG-25") on port 4840
[2024-05-02 12:02:44.513 (UTC-0700)] info/server        New DiscoveryUrl added: opc.tcp:https://LOCALUSER-ENG-25:4840
[2024-05-02 12:02:44.513 (UTC-0700)] info/network       TCP 468 | Creating listen socket for "LOCALUSER-ENG-25.BusinessName.local" (with local hostname "LOCALUSER-ENG-25") on port 4840
[2024-05-02 12:02:44.513 (UTC-0700)] info/network       UDP 460 | New listen socket for "224.0.0.251" on port 5353
[2024-05-02 12:02:44.513 (UTC-0700)] warn/network       UDP 460 | No network interface defined for multicast. That means the first suitable network interface is used.
[2024-05-02 12:02:44.513 (UTC-0700)] warn/network       UDP 456 | No network interface defined for multicast. That means the first suitable network interface is used.
[2024-05-02 12:02:44.513 (UTC-0700)] info/network       UDP 456 | New connection to "224.0.0.251" on port 5353
[2024-05-02 12:02:44.513 (UTC-0700)] warn/discovery     Cannot add mDNS Record: BadOutOfRange

Wireshark Log:
(There were no packets found using the filter I described above)
wireshark_windows_not_working

Logs from Linux build (works perfectly every time):

[LOCALUSER-eng-25][LOCALUSER][~/tmp/open62541/build/bin/examples][1.4]
: ./discovery_server_lds 
[2024-05-03 08:32:03.184 (UTC-0700)] info/eventloop	Starting the EventLoop
[2024-05-03 08:32:03.185 (UTC-0700)] warn/server	AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-03 08:32:03.185 (UTC-0700)] info/server	AccessControl: Anonymous login is enabled
[2024-05-03 08:32:03.185 (UTC-0700)] warn/server	x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 08:32:03.186 (UTC-0700)] info/session	TCP 0	| SC 0	| Session "Administrator"	| AddNode (i=15303): No TypeDefinition. Use the default TypeDefinition for the Variable/Object
[2024-05-03 08:32:03.189 (UTC-0700)] info/session	TCP 0	| SC 0	| Session "Administrator"	| AddNode (i=25451): No TypeDefinition. Use the default TypeDefinition for the Variable/Object
[2024-05-03 08:32:03.193 (UTC-0700)] warn/userland	ServerUrls already set. Overriding.
[2024-05-03 08:32:03.193 (UTC-0700)] warn/server	AccessControl: Unconfigured AccessControl. Users have all permissions.
[2024-05-03 08:32:03.193 (UTC-0700)] info/server	AccessControl: Anonymous login is enabled
[2024-05-03 08:32:03.193 (UTC-0700)] warn/server	x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 08:32:03.193 (UTC-0700)] warn/server	x509 Certificate Authentication configured, but no encrypting SecurityPolicy. This can leak credentials on the network.
[2024-05-03 08:32:03.193 (UTC-0700)] warn/server	Maximum SecureChannels count not enough for the maximum Sessions count
[2024-05-03 08:32:03.193 (UTC-0700)] info/network	TCP	| Listening on all interfaces
[2024-05-03 08:32:03.193 (UTC-0700)] info/network	TCP 4	| Creating listen socket for "0.0.0.0" (with local hostname "LOCALUSER-eng-25") on port 4840
[2024-05-03 08:32:03.193 (UTC-0700)] info/server	New DiscoveryUrl added: opc.tcp:https://LOCALUSER-eng-25:4840
[2024-05-03 08:32:03.193 (UTC-0700)] info/network	TCP 5	| Creating listen socket for "::" (with local hostname "LOCALUSER-eng-25") on port 4840
[2024-05-03 08:32:03.193 (UTC-0700)] info/network	UDP 6	| New listen socket for "224.0.0.251" on port 5353
[2024-05-03 08:32:03.194 (UTC-0700)] warn/network	UDP 6	| No network interface defined for multicast. The first suitable network interface is used.
[2024-05-03 08:32:03.194 (UTC-0700)] warn/network	UDP 7	| No network interface defined for multicast. The first suitable network interface is used.
[2024-05-03 08:32:03.194 (UTC-0700)] info/network	UDP 7	| New connection to "224.0.0.251" on port 5353
[2024-05-03 08:32:03.194 (UTC-0700)] warn/discovery	Cannot add mDNS Record: BadOutOfRange
[2024-05-03 08:32:05.196 (UTC-0700)] info/server	Multicast DNS: found server: opc.tcp:https://User_1-OptiPlex-3080:4840
[2024-05-03 08:32:05.196 (UTC-0700)] info/server	Multicast DNS: found server: opc.tcp:https://10.0.0.150:4845

Wireshark Logs:
wireshark_linux_shortdump

Logs from the UA Foundation's LDS-ME implementation for Windows after Open62541 intermittent issue hits:

Mon May 06 09:56:19 [14068]: Server startup complete. Host name is LOCALUSER-ENG-25.BusinessName.local.
Mon May 06 09:56:19 [14068]: Using certificate store at C:\ProgramData\OPC Foundation\UA\pki\...
Mon May 06 09:56:19 [14068]: Win32StoreCheck is enabled.
Mon May 06 09:56:19 [14068]: Zeroconf is enabled.
Mon May 06 09:56:19 [14068]: Create Zeroconf registration timer with interval 5
Mon May 06 09:56:19 [14068]: ualds_findserversonnetwork_start_internal: Call DNSServiceBrowse for service type _opcua-tcp._tcp
Mon May 06 09:56:19 [14068]: ualds_findserversonnetwork_start_internal: Call DNSServiceBrowse for service type _opcua-wss._tcp
Mon May 06 09:56:19 [14068]: ualds_findserversonnetwork_start_internal: Call DNSServiceBrowse for service type _opcua-https._tcp
Mon May 06 09:56:19 [14068]: Create Zeroconf browse timer with interval 5
Mon May 06 09:56:19 [14068]: Opening endpoint 'opc.tcp://LOCALUSER-ENG-25.BusinessName.local:4840'...
Mon May 06 09:56:19 [14068]: Endpoint is open.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    UA Local Discovery Server on DESKTOP-PKIOQS8
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    LDS-WOPR
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    LDS-User_2-RaspiCM4-peripheral
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    product-infomodel-server-10-0-0-105
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    LDS-User_1-OptiPlex-3080
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:19 [14068]:                              interfaceIndex 11
Mon May 06 09:56:19 [14068]:                              serviceName    product-infomodel-server-10-0-0-150
Mon May 06 09:56:19 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:19 [14068]:                              replyDomain    local.
Mon May 06 09:56:19 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       UA\032Local\032Discovery\032Server\032on\032DESKTOP-PKIOQS8._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     DESKTOP-PKIOQS8.local.
Mon May 06 09:56:20 [14068]:                               port           4840
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       LDS-WOPR._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     WOPR.
Mon May 06 09:56:20 [14068]:                               port           4840
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       LDS-User_2-RaspiCM4-peripheral._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     User_2-RaspiCM4-peripheral.
Mon May 06 09:56:20 [14068]:                               port           4840
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       product-infomodel-server-10-0-0-105._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     10.0.0.105.
Mon May 06 09:56:20 [14068]:                               port           4845
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       LDS-User_1-OptiPlex-3080._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     User_1-OptiPlex-3080.
Mon May 06 09:56:20 [14068]:                               port           4840
Mon May 06 09:56:20 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:20 [14068]:                               interfaceIndex 11
Mon May 06 09:56:20 [14068]:                               fullname       product-infomodel-server-10-0-0-150._opcua-tcp._tcp.local.
Mon May 06 09:56:20 [14068]:                               hosttarget     10.0.0.150.
Mon May 06 09:56:20 [14068]:                               port           4845
Mon May 06 09:56:21 [14068]: ualds_DNSServiceRegisterReply: server registered:
Mon May 06 09:56:21 [14068]:                                flags 2
Mon May 06 09:56:21 [14068]:                                error 0
Mon May 06 09:56:21 [14068]:                                name UA Local Discovery Server on LOCALUSER-ENG-25.BusinessName.local
Mon May 06 09:56:21 [14068]:                                regtype _opcua-tcp._tcp.
Mon May 06 09:56:21 [14068]:                                domain local.
Mon May 06 09:56:21 [14068]: Announcing server urn:[gethostname]:UALocalDiscoveryServer via Zeroconf succeeded
Mon May 06 09:56:21 [14068]: ualds_DNSServiceBrowseReply: received service:
Mon May 06 09:56:21 [14068]:                              interfaceIndex 11
Mon May 06 09:56:21 [14068]:                              serviceName    UA Local Discovery Server on LOCALUSER-ENG-25.BusinessName.local
Mon May 06 09:56:21 [14068]:                              regtype        _opcua-tcp._tcp.
Mon May 06 09:56:21 [14068]:                              replyDomain    local.
Mon May 06 09:56:21 [14068]: ualds_DNSServiceBrowseReply: Call DNSServiceResolve
Mon May 06 09:56:21 [14068]: ualds_DNSServiceBrowseReply: ignoring known service UA Local Discovery Server on LOCALUSER-ENG-25.BusinessName.local / _opcua-tcp._tcp.
Mon May 06 09:56:21 [14068]: ualds_DNSServiceBrowseReply: ignoring known service UA Local Discovery Server on LOCALUSER-ENG-25.BusinessName.local / _opcua-tcp._tcp.
Mon May 06 09:56:21 [14068]: ualds_DNSServiceBrowseReply: ignoring known service UA Local Discovery Server on LOCALUSER-ENG-25.BusinessName.local / _opcua-tcp._tcp.
Mon May 06 09:56:21 [14068]: ualds_DNSServiceResolveReply: resolved service:
Mon May 06 09:56:21 [14068]:                               interfaceIndex 11
Mon May 06 09:56:21 [14068]:                               fullname       UA\032Local\032Discovery\032Server\032on\032LOCALUSER-ENG-25\.BusinessName\.local._opcua-tcp._tcp.local.
Mon May 06 09:56:21 [14068]:                               hosttarget     LOCALUSER-ENG-25.local.
Mon May 06 09:56:21 [14068]:                               port           4840

Used CMake options:

cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DUA_MULTITHREADING=101 -DUA_ENABLE_SUBSCRIPTIONS=ON -DUA_ENABLE_SUBSCRIPTIONS_EVENTS=ON -DUA_ENABLE_PUBSUB=ON -DUA_ENABLE_PUBSUB_MONITORING=ON -DUA_ENABLE_HISTORIZING=ON -DUA_ENABLE_JSON_ENCODING=ON -DUA_ENABLE_METHODCALLS=ON -DUA_ENABLE_DISCOVERY=ON -DUA_ENABLE_DISCOVERY_MULTICAST=ON -DUA_BUILD_EXAMPLES=ON ..

Checklist

Please provide the following information:

  • open62541 Version (release number or git tag): 1.4
  • Other OPC UA SDKs used (client or server): https://opcfoundation.github.io/UA-LDS/
  • Operating system: Windows 10 Pro
  • Logs (with UA_LOGLEVEL set as low as necessary) attached
  • Wireshark network dump attached
  • Self-contained code example attached
  • Critical issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@abehonest