eCatcher gets interrupted after a short time

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

Meanwhile, we were able to sove the issue: We had a master image where eCatcher was installed and cloned this image to some virtual machines. We found out that the cloned VPN interface was the issue. We removed the TAP interface from the master image and created a new TAP interface via script (install.bat) for each clone. Everything looks fine now.

Hi @breitenc,

Thanks for the update! And yes, we’ve seen this issue before with VMs.
I’m glad everything is working fine now.

Best,
Juliana