Initial dial timeout waits forever

[neben]

Every now and then clients are offline due to intermittent Internet issues and won't reconnect automatically. If I connect to these devices over a local ssh connection and strace the exe process, I can see that the last message complains about a timed out DNS resolution. It seems as this might be the reason the client gets stuck?

# strace -fs 255 -p `pidof exe`
strace: Process 3906 attached with 7 threads
[pid  9442] futex(0x4000181d48, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] futex(0x4000180148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3910] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3909] futex(0x400005cf48, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3908] futex(0x400005c848, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3907] restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
[pid  3906] write(2, "2025/11/18 22:51:22 Unable to connect directly TCP: failed to connect: dial tcp: lookup <redacted> on 8.8.8.8:53: read udp 192.168.0.101:33880->8.8.8.8:53: i/o timeout\n", 172

[NHAS]

Hi there,

Thanks for the bug report, were these clients using any sort of proxy?

[NHAS]

			conn, err = Connect(realAddr, settings.ProxyAddr, config.Timeout, settings.ProxyUseHostKerberos, settings.ntlm)
			if err != nil {

				if errMsg := err.Error(); strings.Contains(errMsg, "missing port in address") {
					log.Fatalf("Unable to connect to TCP invalid address: %q, %s", settings.Addr, errMsg)
				}

				log.Printf("Unable to connect directly TCP: %v\n", err)

				if len(potentialProxies) > 0 {
					if len(potentialProxies) <= triedProxyIndex {
						log.Printf("Unable to connect via proxies (from env), retrying with proxy as %q: %v", potentialProxies, initialProxyAddr)
						triedProxyIndex = 0
						settings.ProxyAddr = initialProxyAddr
						continue
					}
					proxy := potentialProxies[triedProxyIndex]
					triedProxyIndex++

					log.Println("Trying to proxy via env variable (", proxy, ")")

					settings.ProxyAddr, err = GetProxyDetails(proxy)
					if err != nil {
						log.Println("Could not parse the env proxy value: ", proxy)
					}
					// dont wait 10 seconds, just immediately try each proxy
					continue
				}

				<-time.After(10 * time.Second)
				continue
			}

This is the retry logic, so effectively if you're getting that error message there can only be a 10 second wait before attempting to reconnect.

[NHAS]

Also Im assuming your clients are using a regular tcp connection?

Just as there is this as well in the connection logic:

	if tcpC, ok := conn.(*net.TCPConn); ok {
		tcpC.SetKeepAlivePeriod(2 * time.Hour)
	}

Have you found their connection works properly after 2 hours?

[NHAS]

Unfortunately I cannot replicate this.

This is with perfect network connections after reconnection. So that may play a part.

# disconnection in docker container
2025/11/21 22:55:04 Server disconnected unexpectedly: connection terminated
2025/11/21 22:55:14 Connecting to testing.example.com:3232
2025/11/21 22:55:14 [client] WARNING client.go:372 func1() : No server key specified, allowing connection to testing.example.com:3232
# reconnection
2025/11/21 22:55:14 Successfully connnected testing.example.com:3232

2025/11/21 22:55:29 Server disconnected unexpectedly: connection terminated
2025/11/21 22:55:39 Connecting to testing.example.com:3232

# failure due to no network
2025/11/21 22:55:39 Unable to connect directly TCP: failed to connect: dial tcp: lookup testing.example.com on 8.8.8.8:53: dial udp 8.8.8.8:53: connect: network is unreachable
2025/11/21 22:55:49 Connecting to testing.example.com:3232
2025/11/21 22:55:49 [client] WARNING client.go:372 func1() : No server key specified, allowing connection to testing.example.com:3232
2025/11/21 22:55:49 Successfully connnected testing.example.com:3232

# disconnection that took roughly 5 mins to timeout
2025/11/21 22:59:49 Server disconnected unexpectedly: connection terminated

# network reconnected 
2025/11/21 23:01:19 [client] WARNING client.go:372 func1() : No server key specified, allowing connection to testing.example.com:3232
2025/11/21 23:01:19 Successfully connnected testing.example.com:3232
2025/11/21 23:01:34 Server disconnected unexpectedly: connection terminated

[neben]

Here's another instance from today, with a longer strace output. It can't establish an rssh tunnel despite Internet being available again, but I have local access so I could debug this. It's an arm64 machine, it has strace but not gdb. @NHAS Any ideas what I could look for?

# strace -fs 255 -p `pidof exe`
strace: Process 3910 attached with 7 threads
[pid 14722] futex(0x400005d948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  9834] futex(0x400040a148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3913] write(2, "2025/11/22 11:11:03 Connecting to <redacted>:3232\n", 54 <unfinished ...>
[pid  3912] futex(0x400005c948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield( <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield( <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0} <unfinished ...>
[pid  3914] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3914] futex(0x97efc0, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  3911] <... futex resumed> )       = 0
[pid  3914] futex(0x400005c948, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... futex resumed> )       = 1
[pid  3912] <... futex resumed> )       = 0
[pid  3912] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3912] <... futex resumed> )       = 1
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3912] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  3910] <... futex resumed> )       = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3912] <... nanosleep resumed> NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3910] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  3912] futex(0x400005c948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3910] <... nanosleep resumed> NULL) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  3910] <... futex resumed> )       = 0
[pid  3914] futex(0x97efd8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=100000} <unfinished ...>
[pid  3910] futex(0x97efd8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3910] <... futex resumed> )       = 0
[pid  3914] sched_yield( <unfinished ...>
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3914] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3914] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  3910] <... futex resumed> )       = 0
[pid  3914] futex(0x97efd8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=100000} <unfinished ...>
[pid  3910] futex(0x97efd8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3910] <... futex resumed> )       = 0
[pid  3914] sched_yield( <unfinished ...>
[pid  3910] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3910] <... nanosleep resumed> NULL) = 0
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield( <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield()               = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... futex resumed> )       = 1
[pid  3910] <... futex resumed> )       = 0
[pid  3910] futex(0x400005c948, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3912] <... futex resumed> )       = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3912] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  3910] <... futex resumed> )       = 1
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3910] nanosleep({tv_sec=0, tv_nsec=3000},  <unfinished ...>
[pid  3912] <... nanosleep resumed> NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3912] futex(0x400005c948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3910] <... nanosleep resumed> NULL) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] epoll_pwait(4,  <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] <... epoll_pwait resumed> [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0} <unfinished ...>
[pid  3914] futex(0x97efc0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3914] <... futex resumed> )       = 0
[pid  3911] sched_yield( <unfinished ...>
[pid  3914] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] <... sched_yield resumed> ) = 0
[pid  3914] <... futex resumed> )       = 1
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3910] <... futex resumed> )       = 0
[pid  3914] futex(0x97efd8, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=100000} <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] sched_yield( <unfinished ...>
[pid  3910] futex(0x97efd8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... sched_yield resumed> ) = 0
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] futex(0x4000080528, FUTEX_WAIT_PRIVATE, 4294967295, NULL <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3910] <... futex resumed> )       = 0
[pid  3910] futex(0x4000080528, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3914] <... futex resumed> )       = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3910] <... futex resumed> )       = 1
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3910] futex(0x97ccc0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield()               = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] futex(0x4000080148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3911] futex(0x97efc0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}) = -1 ETIMEDOUT (Connection timed out)
[pid  3911] epoll_pwait(4, [], 128, 0, NULL, 0) = 0
[pid  3911] futex(0x4000080148, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] sched_yield()               = 0
[pid  3914] futex(0x4000080528, FUTEX_WAIT_PRIVATE, 4294967295, NULL <unfinished ...>
[pid  3911] futex(0x4000080528, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid  3914] <... futex resumed> )       = 0
[pid  3911] <... futex resumed> )       = 1
[pid  3914] epoll_pwait(4,  <unfinished ...>
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000},  <unfinished ...>
[pid  3914] <... epoll_pwait resumed> [], 128, 0, NULL, 0) = 0
[pid  3914] futex(0x97ccc0, FUTEX_WAKE_PRIVATE, 1) = 1
[pid  3911] <... nanosleep resumed> NULL) = 0
[pid  3910] <... futex resumed> )       = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid  3911] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0

[neben]

Also Im assuming your clients are using a regular tcp connection?

Just as there is this as well in the connection logic:

if tcpC, ok := conn.(*net.TCPConn); ok {
tcpC.SetKeepAlivePeriod(2 * time.Hour)
}
Have you found their connection works properly after 2 hours?

Yes, regular tcp connection. No, unfortunately won't connect after 2 hours.

[neben]

Hi there,

Thanks for the bug report, were these clients using any sort of proxy?

There is no proxy set up on the device. I'm also not aware of any transparent proxy on an inbetween gateway. On my server side, there is the docker swarm routing mesh in front of the rssh container.

[NHAS]

Can you also supply the rssh client log?

From that strace it just appears your network is still bad as you're just timing out.

Which isn't something we can solve with rssh...

[neben]

Can you also supply the rssh client log?

From that strace it just appears your network is still bad as you're just timing out.

Which isn't something we can solve with rssh...

That's the thing, the Internet is fine now. If I would restart rssh, it would work. It's just that this instance of rssh is timing out.

# ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8): 56 data bytes
64 bytes from 8.8.8.8: seq=0 ttl=119 time=10.086 ms
64 bytes from 8.8.8.8: seq=1 ttl=119 time=9.849 ms
64 bytes from 8.8.8.8: seq=2 ttl=119 time=9.196 ms
64 bytes from 8.8.8.8: seq=3 ttl=119 time=7.832 ms

Where do I find the rssh client log?

[NHAS]

Hm.

I feel that if the connection is in the middle attempting to connect it'll be using the dead network rather than your re-established network.

Are these on cellular?

RSSH logs to stdout if you've for grounded it, and if it's connected to the server you can instruct it to write it's log to a file.

Do you have a connection timeout set?

[NHAS]

Okay I think I might have found the problem

[NHAS]

conn, err = Connect(realAddr, settings.ProxyAddr, config.Timeout, settings.ProxyUseHostKerberos, settings.ntlm)

Here we're effectively passing a tcp connection a timeout with config.Timeout however that config.Timeout is the SSH client config, which is set to the zero value of a time.Duration, which means it'll have no timeout.

Thus meaning it can get stuck in the middle of connecting to something

[NHAS]

I've added a default timeout now of 180 seconds, I've also added --connect-timeout to be able to configure how long clients will wait on initial connection before bailing out.

This is all on unstable if you're able to give that a try.