Hello,
we’re using eCatcher on a VM (VM-ware Horizon). eCatcher is installed and it connects to a cosy 131 without problems. But after some minutes or seconds, the connection breaks down and eCatcher tries to reconnect. I’m logged in into Windows as a normal Windows user.
The issue occurs on several cosys at different places in the world. When I use a different PC for eCatcher, everything works fine. We need a clue what to look for.
Here’s some log info:
Horizon VM:
8/12/22 10:52:20 AM INFO: USR115726:DEV1072559:User [breitenc_admin] connected to eWON [Teststand]
8/12/22 10:52:54 AM INFO: USR115726:DEV1072559:User [breitenc_admin] disconnected from eWON [Teststand]
8/12/22 10:54:16 AM INFO: USR115726:DEV1072559:User [breitenc_admin] connected to eWON [Teststand]
8/12/22 10:54:18 AM INFO: USR115726:DEV1072559:User [breitenc_admin] disconnected from eWON [Teststand]
8/12/22 10:56:15 AM INFO: USR115726:DEV1072559:User [breitenc_admin] connected to eWON [Teststand]
8/12/22 11:00:54 AM INFO: USR115726:DEV1072559:User [breitenc_admin] disconnected from eWON [Teststand]
8/12/22 11:02:19 AM INFO: USR115726:DEV1072559:User [breitenc_admin] connected to eWON [Teststand]
8/12/22 11:02:23 AM INFO: USR115726:DEV1072559:User [breitenc_admin] disconnected from eWON [Teststand]
A PC that works:
8/12/22 11:08:59 AM INFO: USR115726:DEV1072559:User [breitenc_admin] connected to eWON [Teststand]
And here’s the eCatcher logfile from the VM:
2022-08-12T11:02:02,756 INFO - route del 150.150.98.0
2022-08-12T11:02:02,756 WARN - route del 150.150.98.0
2022-08-12T11:02:02,756 WARN - OK
2022-08-12T11:02:02,806 INFO - reconnecting device [1072559]
2022-08-12T11:02:02,806 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:02:04,356 WARN - shutdown
2022-08-12T11:02:04,361 WARN - > LOG: 1660294924,I,SIGTERM received, sending exit notification to peer
2022-08-12T11:02:04,361 WARN - > STATE: 1660294924,EXITING,exit-with-notification,
2022-08-12T11:02:04,361 INFO - ConnectionWorkerProgressStatus : null - 1268 %
2022-08-12T11:02:04,361 INFO - ConnectionWorkerProgressStatus : null - 1184 %
2022-08-12T11:02:04,361 INFO - ConnectionWorkerProgressStatus : null - 596 %
2022-08-12T11:02:05,612 WARN - > LOG: 1660294925,Closing TUN/TAP interface
2022-08-12T11:02:05,627 WARN - > LOG: 1660294925,I,SIGTERM[soft,exit-with-notification] received, process exiting
2022-08-12T11:02:05,627 WARN - > LOG: 1660294925,MANAGEMENT: >STATE:1660294925,EXITING,exit-with-notification,
2022-08-12T11:02:05,627 WARN - > STATE: 1660294925,EXITING,exit-with-notification,
2022-08-12T11:02:05,677 WARN - OK
2022-08-12T11:02:05,722 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Requesting Talk2M server informations… - 5 %
2022-08-12T11:02:05,742 INFO - Best endPoint choosen: UDP on client.vpn41.talk2m.com(51.75.89.5):1194
2022-08-12T11:02:05,747 WARN - start client.vpn41.talk2m.com 1194 “C:\Users\srv-breitenc\AppData\Roaming.talk2M\temp\e629274c-8cfe-4697-b13b-411ccfc8244a” tap UDP netsh
2022-08-12T11:02:05,782 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Opening VPN tunnel… - 20 %
2022-08-12T11:02:06,852 WARN - OK
2022-08-12T11:02:07,360 WARN - > INFO: OpenVPN Management Interface Version 1 – type ‘help’ for more info
2022-08-12T11:02:07,360 WARN - > HOLD: Waiting for hold release:0
2022-08-12T11:02:07,360 WARN - > LOG: 1660294927,D,MANAGEMENT: CMD ‘hold release’
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,MANAGEMENT: >STATE:1660294927,RESOLVE,
2022-08-12T11:02:07,435 WARN - > STATE: 1660294927,RESOLVE,
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 1280 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 1196 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 608 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 32 %
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,I,TCP/UDP: Preserving recently used remote address: [AF_INET]51.75.89.5:1194
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,Socket Buffers: R=[65536->65536] S=[65536->65536]
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,I,UDP link local: (not bound)
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,I,UDP link remote: [AF_INET]51.75.89.5:1194
2022-08-12T11:02:07,435 WARN - > LOG: 1660294927,MANAGEMENT: >STATE:1660294927,WAIT,
2022-08-12T11:02:07,435 WARN - > STATE: 1660294927,WAIT,
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 1292 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 1208 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 620 %
2022-08-12T11:02:07,435 INFO - ConnectionWorkerProgressStatus : null - 44 %
2022-08-12T11:02:07,445 WARN - > LOG: 1660294927,MANAGEMENT: >STATE:1660294927,AUTH,
2022-08-12T11:02:07,445 WARN - > STATE: 1660294927,AUTH,
2022-08-12T11:02:07,445 INFO - ConnectionWorkerProgressStatus : null - 1304 %
2022-08-12T11:02:07,445 INFO - ConnectionWorkerProgressStatus : null - 1220 %
2022-08-12T11:02:07,445 INFO - ConnectionWorkerProgressStatus : null - 632 %
2022-08-12T11:02:07,445 INFO - ConnectionWorkerProgressStatus : null - 56 %
2022-08-12T11:02:07,445 WARN - > LOG: 1660294927,TLS: Initial packet from [AF_INET]51.75.89.5:1194, sid=dcdb359f 84026767
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,VERIFY OK: depth=1, C=BE, ST=Brabant Wallon, L=Nivelles, O=eWON sa, OU=Talk2M, CN=Talk2M Certification Authority, emailAddress=itmanager@talk2m.com
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,VERIFY KU OK
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,Validating certificate extended key usage
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,VERIFY EKU OK
2022-08-12T11:02:07,470 WARN - > LOG: 1660294927,VERIFY OK: depth=0, C=BE, ST=Brabant Wallon, L=Nivelles, O=HMS Industrial Networks SA, OU=Talk2M, CN=server-client, emailAddress=info@ewon.biz
2022-08-12T11:02:07,490 WARN - > LOG: 1660294927,Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
2022-08-12T11:02:07,490 WARN - > LOG: 1660294927,I,[server-client] Peer Connection Initiated with [AF_INET]51.75.89.5:1194
2022-08-12T11:02:08,692 WARN - > LOG: 1660294928,MANAGEMENT: >STATE:1660294928,GET_CONFIG,
2022-08-12T11:02:08,692 WARN - > STATE: 1660294928,GET_CONFIG,
2022-08-12T11:02:08,692 INFO - ConnectionWorkerProgressStatus : null - 1316 %
2022-08-12T11:02:08,692 INFO - ConnectionWorkerProgressStatus : null - 1232 %
2022-08-12T11:02:08,692 INFO - ConnectionWorkerProgressStatus : null - 644 %
2022-08-12T11:02:08,692 INFO - ConnectionWorkerProgressStatus : null - 68 %
2022-08-12T11:02:08,692 WARN - > LOG: 1660294928,SENT CONTROL [server-client]: ‘PUSH_REQUEST’ (status=1)
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,PUSH: Received control message: ‘PUSH_REPLY,topology subnet,ping 10,ping-exit 300,ifconfig 10.41.2.60 255.255.0.0,peer-id 20,cipher AES-256-GCM’
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,OPTIONS IMPORT: timers and/or timeouts modified
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,OPTIONS IMPORT: --ifconfig/up options modified
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,OPTIONS IMPORT: peer-id set
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,OPTIONS IMPORT: adjusting link_mtu to 1657
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,OPTIONS IMPORT: data channel crypto options modified
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,Data Channel: using negotiated cipher ‘AES-256-GCM’
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,Outgoing Data Channel: Cipher ‘AES-256-GCM’ initialized with 256 bit key
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,Incoming Data Channel: Cipher ‘AES-256-GCM’ initialized with 256 bit key
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,interactive service msg_channel=0
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,I,open_tun
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,I,TAP-WIN32 device [Talk2m-eCatcher] opened: \.\Global{796CC8AC-193A-4F6B-B291-57C08F736035}.tap
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,TAP-Windows Driver Version 9.21
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,I,Successful ARP Flush on interface [9] {796CC8AC-193A-4F6B-B291-57C08F736035}
2022-08-12T11:02:08,716 WARN - > LOG: 1660294928,MANAGEMENT: >STATE:1660294928,ASSIGN_IP,10.41.2.60,
2022-08-12T11:02:08,716 WARN - > STATE: 1660294928,ASSIGN_IP,10.41.2.60,
2022-08-12T11:02:08,716 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Configuring local interface… - 1328 %
2022-08-12T11:02:08,716 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Configuring local interface… - 1244 %
2022-08-12T11:02:08,716 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Configuring local interface… - 656 %
2022-08-12T11:02:08,716 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Configuring local interface… - 80 %
2022-08-12T11:02:09,717 WARN - > LOG: 1660294929,I,NETSH: C:\Windows\system32\netsh.exe interface ip set address Talk2m-eCatcher static 10.41.2.60 255.255.0.0
2022-08-12T11:02:11,473 WARN - > LOG: 1660294931,I,NETSH: C:\Windows\system32\netsh.exe interface ip delete dns Talk2m-eCatcher all
2022-08-12T11:02:12,562 WARN - > LOG: 1660294932,I,NETSH: C:\Windows\system32\netsh.exe interface ip delete wins Talk2m-eCatcher all
2022-08-12T11:02:17,080 WARN - > LOG: 1660294937,TEST ROUTES: 0/0 succeeded len=0 ret=1 a=0 u/d=up
2022-08-12T11:02:17,080 WARN - > LOG: 1660294937,W,WARNING: this configuration may cache passwords in memory – use the auth-nocache option to prevent this
2022-08-12T11:02:17,080 WARN - > LOG: 1660294937,I,Initialization Sequence Completed
2022-08-12T11:02:17,080 WARN - > LOG: 1660294937,MANAGEMENT: >STATE:1660294937,CONNECTED,SUCCESS,10.41.2.60,51.75.89.5,1194,
2022-08-12T11:02:17,080 WARN - > STATE: 1660294937,CONNECTED,SUCCESS,10.41.2.60,51.75.89.5,1194,
2022-08-12T11:02:17,080 INFO - ConnectionWorkerProgressStatus : null - 1340 %
2022-08-12T11:02:17,080 INFO - ConnectionWorkerProgressStatus : null - 1256 %
2022-08-12T11:02:17,080 INFO - ConnectionWorkerProgressStatus : null - 668 %
2022-08-12T11:02:17,080 INFO - ConnectionWorkerProgressStatus : null - 92 %
2022-08-12T11:02:17,080 INFO - VPN connection established on server :client.vpn41.talk2m.com
2022-08-12T11:02:17,120 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Opening VPN tunnel… - 80 %
2022-08-12T11:02:17,595 INFO - ConnectionWorkerProgressStatus : Connecting Talk2M: Connecting Ewon… - 90 %
2022-08-12T11:02:21,296 INFO - connected to eWON [Teststand] vpnIp [10.41.134.157]
2022-08-12T11:02:21,351 INFO - route add 150.150.98.0 255.255.255.0 10.41.134.157 30
2022-08-12T11:02:21,351 WARN - route add 150.150.98.0 255.255.255.0 10.41.134.157 30
2022-08-12T11:02:21,376 WARN - SUCCESS | RT1 | 20220812T09:02:21 | Ewon LAN devices network added. (code 1)
2022-08-12T11:02:21,376 INFO - route broadcast on 10.41.134.157
2022-08-12T11:02:21,376 WARN - route broadcast on 10.41.134.157
2022-08-12T11:02:21,386 WARN - OK
2022-08-12T11:02:21,386 INFO - route postconnect
2022-08-12T11:02:21,386 WARN - route postconnect
2022-08-12T11:02:21,386 WARN - SUCCESS | RT1 | 20220812T09:02:21 | post connect arp cleanup done (code 1)
2022-08-12T11:02:21,386 ERROR - The system cannot find the file specified.
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice
2022-08-12T11:03:11,410 INFO - Impossible to delete registry key : Software\eWON\eCatcher\connectedDevice