Page 1 of 1

Visual Bug: "Connecting..."

Posted: Tue Jan 26, 2021 8:59 pm
by map
Hello,

I have a visual bug in Viscosity.
The connection has some kind of error and after that the status remains on "Connecting".
It is happening approximately every six hours.
As far as I can tell this is only a visual bug, as all remote access is still working.

The last few lines at 2:41:43 are the ones where the connection is resetting in some way.
If someone can tell me how to change the language in Viscosity I can upload a log file in english, as I can't find an option to switch the language.
Code: Select all
Jan 21 8:41:41 : Status auf Verbinde geändert
Jan 21 8:41:41 : Viscosity Windows 1.9 (1695)
Jan 21 8:41:41 : Betriebsystem ist Windows 10 2004 (19041) 64 bit
Jan 21 8:41:41 : Betriebsystem ist .NET Framework Version 4.8.04084.528372
Jan 21 8:41:41 : Checking reachability status of connection...
Jan 21 8:41:41 : Connection is reachable. Starting connection attempt.
Jan 21 8:41:41 : Aktivieren des Netzwerkadapters...
Jan 21 8:41:41 : OpenVPN 2.4.9 Windows-MSVC [SSL (OpenSSL)] [LZO] [LZ4] [AEAD] built on Oct  6 2020
Jan 21 8:41:41 : library versions: OpenSSL 1.1.1h  22 Sep 2020, LZO 2.10
Jan 21 8:41:42 : Resolving address: "GATE.xxx.COM"
Jan 21 8:41:44 : Valid endpoint found: GATE.xxxx.COM:443:udp
Jan 21 8:41:44 : WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Jan 21 8:41:44 : TCP/UDP: Preserving recently used remote address: [AF_INET]xxx.xxx.xxx.xxx:443
Jan 21 8:41:44 : Socket Buffers: R=[65536->65536] S=[65536->65536]
Jan 21 8:41:44 : UDP link local: (not bound)
Jan 21 8:41:44 : UDP link remote: [AF_INET]xxx.xxx.xxx.xxx:443
Jan 21 8:41:44 : Status auf Authenticating geändert
Jan 21 8:41:44 : TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:443, sid=eaa5463f 75dd017f
Jan 21 8:41:44 : WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Jan 21 8:41:44 : VERIFY OK: nsCertType=SERVER
Jan 21 8:41:44 : VERIFY OK: depth=0, CN=OpenVPN Server
Jan 21 8:41:44 : Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Jan 21 8:41:44 : [OpenVPN Server] Peer Connection Initiated with [AF_INET]xxx.xxx.xxx.xxx:443
Jan 21 8:41:44 : Status auf Verbinde geändert
Jan 21 8:41:44 : SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
Jan 21 8:41:44 : PUSH: Received control message: 'PUSH_REPLY,explicit-exit-notify,topology subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 12,ping-restart 50,compress stub-v2,redirect-gateway def1,redirect-gateway bypass-dhcp,redirect-gateway autolocal,route-gateway xxx.xxx.xxx.xxx,dhcp-option DNS xxx.xxx.xxx.xxx,dhcp-option DNS xxx.xxx.xxx.xxx,dhcp-option ADAPTER_DOMAIN_SUFFIX xxxx.com,register-dns,block-ipv6,ifconfig xxx.xxx.xxx.xxx 255.255.255.224,peer-id 3,auth-tokenSESS_ID,cipher AES-256-GCM'
Jan 21 8:41:44 : Pushed option removed by filter: 'route-delay 5 30'
Jan 21 8:41:44 : Obsolete option --dhcp-release detected. This is now on by default
Jan 21 8:41:44 : Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:19: block-ipv6 (2.4.9)
Jan 21 8:41:44 : OPTIONS IMPORT: timers and/or timeouts modified
Jan 21 8:41:44 : OPTIONS IMPORT: explicit notify parm(s) modified
Jan 21 8:41:44 : OPTIONS IMPORT: compression parms modified
Jan 21 8:41:44 : OPTIONS IMPORT: --ifconfig/up options modified
Jan 21 8:41:44 : OPTIONS IMPORT: route options modified
Jan 21 8:41:44 : OPTIONS IMPORT: route-related options modified
Jan 21 8:41:44 : OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Jan 21 8:41:44 : OPTIONS IMPORT: peer-id set
Jan 21 8:41:44 : OPTIONS IMPORT: adjusting link_mtu to 1625
Jan 21 8:41:44 : OPTIONS IMPORT: data channel crypto options modified
Jan 21 8:41:44 : Data Channel: using negotiated cipher 'AES-256-GCM'
Jan 21 8:41:44 : Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan 21 8:41:44 : Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan 21 8:41:44 : interactive service msg_channel=0
Jan 21 8:41:44 : ROUTE_GATEWAY xxx.xxx.xxx.xxx/255.255.255.0 I=12 HWADDR=ee:ee:ee:e7:27:ee
Jan 21 8:41:44 : Awaiting adapter to come up...
Jan 21 8:41:44 : TAP-WIN32 device [[email protected]] opened: \\.\Global\{xxxxx}.tap, index: 10
Jan 21 8:41:45 : Set TAP-Windows TUN subnet mode network/local/netmask = xxx.xxx.xxx.xxx/xxx.xxx.xxx.xxx/255.255.255.224 [SUCCEEDED]
Jan 21 8:41:45 : Waiting for DNS Setup to complete...
Jan 21 8:41:49 : Successful ARP Flush on interface [10] {xxxx}
Jan 21 8:41:49 : TAP: DHCP address released
Jan 21 8:41:53 : TAP: DHCP address renewal succeeded
Jan 21 8:41:53 : TEST ROUTES: 2/2 succeeded len=1 ret=1 a=0 u/d=up
Jan 21 8:41:53 : ROUTE remote_host is NOT LOCAL
Jan 21 8:41:53 : C:\Windows\system32\route.exe ADD xxx.xxx.xxx.xxx MASK 255.255.255.255 xxx.xxx.xxx.xxx
Jan 21 8:41:53 : IPv4 Route addition via management succeeded
Jan 21 8:41:53 : C:\Windows\system32\route.exe ADD 0.0.0.0 MASK 128.0.0.0 xxx.xxx.xxx.xxx
Jan 21 8:41:53 : IPv4 Route addition via management succeeded
Jan 21 8:41:53 : C:\Windows\system32\route.exe ADD 128.0.0.0 MASK 128.0.0.0 xxx.xxx.xxx.xxx
Jan 21 8:41:53 : IPv4 Route addition via management succeeded
Jan 21 8:41:53 : C:\Windows\system32\route.exe ADD xxx.xxx.xxx.xxx MASK 255.255.255.0 xxx.xxx.xxx.xxx METRIC 10
Jan 21 8:41:53 : Warning: address xxx.xxx.xxx.xxx is not a network address in relation to netmask 255.255.255.0
Jan 21 8:41:53 : Route addition via IPAPI failed. Fallback to route.exe
Jan 21 8:41:53 : IPv4 Route addition via management succeeded
Jan 21 8:41:53 : Initialization Sequence Completed
Jan 21 8:41:53 : DNS ist auf 'Vollständig' eingestellt:
Server - xxx.xxx.xxx.xxx; Lookup Type - Any; Domains - xxxx.com.
Server - xxx.xxx.xxx.xxx; Lookup Type - Any; Domains - xxxx.com.

Jan 21 8:41:53 : Status auf Verbunden geändert
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23056 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23057 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23058 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23063 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23064 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23065 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 8:42:15 : AEAD Decrypt error: bad packet ID (may be a replay): [ #23066 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354692 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354693 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354694 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354695 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354696 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354697 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354699 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354700 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354703 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354704 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354705 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354706 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : AEAD Decrypt error: bad packet ID (may be a replay): [ #1354707 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Jan 21 11:52:06 : NOTE: --mute triggered...
Jan 21 2:41:43 : 68 variation(s) on previous 20 message(s) suppressed by --mute
Jan 21 2:41:43 : VERIFY OK: nsCertType=SERVER
Jan 21 2:41:43 : VERIFY OK: depth=0, CN=OpenVPN Server
Jan 21 2:41:43 : Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan 21 2:41:43 : Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan 21 2:41:43 : Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Jan 21 2:41:43 : PUSH: Received control message: 'PUSH_REPLY, auth-tokenSESS_ID'
Jan 21 2:41:43 : Status auf Verbinde geändert

Re: Visual Bug: "Connecting..."

Posted: Wed Jan 27, 2021 10:47 am
by Eric
Hi map,

No need to change language if you don't want to, we can translate your log. To do so if you want to though, exit Viscosity then run the following from a command prompt:

"C:\Program Files\Viscosity\Viscosity.exe" SetPref DisplayLanguage en

Could you please edit your connection and go to Advanced, there on a new line add:

verb 6

Save the connection and reconnect. Next time this issue then occurs, could you please send us another copy of your log, hopefully it will have some more information. It does appear a state change was issued by OpenVPN, so this is more than a visual bug, hopefully the verbose log will let us know what is going on.

Regards,
Eric

Re: Visual Bug: "Connecting..."

Posted: Thu Jan 28, 2021 8:18 pm
by map
Hi Eric,

here is the log with verb 6.
clean28012020dnsLog.txt
(114.28 KiB) Downloaded 503 times
I had to append it as an attachment, because it was to big for the forum.

At Jan 27 11:02 there was a complete disconnect but that could as well be a hiccup on the server side.
At Jan 27 5:29:20 the error happens the first time I think.
And after that every 6 hours on the dot.

A little bit off topic: why is there no AM/PM or 24 hour time in the log?

Re: Visual Bug: "Connecting..."

Posted: Mon Feb 01, 2021 9:34 am
by Eric
Hi map,

Ignore the below if you haven't already seen this, I believe we've found the issue and will post a reply when we have a beta up for you to try.

-----

Thanks for posting that, I'm afraid it didn't give us the extra information we were looking for. Could we please get one more log from you after doing the following:

- Exit Viscosity
- Run the following from Command Prompt:
"C:\Program Files\Viscosity\Viscosity.exe" SetPref DEBUG true
- Start Viscosity and use it normally again.

Then post another copy of the log after the issue occurs again.
A little bit off topic: why is there no AM/PM or 24 hour time in the log?
We'll look into this.

Regards,
Eric

Re: Visual Bug: "Connecting..."

Posted: Mon Feb 01, 2021 6:19 pm
by Eric
Hi map,

Version 1.9.1 Beta 9 is now available and should fix this bug, please let us know how you get on - https://sparklabs.com/support/kb/articl ... -versions/

Regards,
Eric

Re: Visual Bug: "Connecting..."

Posted: Thu Feb 04, 2021 9:17 pm
by map
It's working all fine now.
Thanks for the swift solution.