detect dead tunnel

[brianjmurrell]

Hi.

I've been having problems with tunnels going dead. To be clear, the problem is not sshuttle outright dying -- it keeps running but nothing moves over the tunnel.

I suspect that this is not in fact sshuttle but the underlying transport stack (ssh, network, etc.) that is hanging up or timing out.

In looking at the debug output for sshuttle I see PING/PONG messages as such:

Oct 30 12:28:25 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PING len=6 (fullness=36022)
Oct 30 12:28:26 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PING len=6
Oct 30 12:28:26 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PONG len=6 (fullness=224)
Oct 30 12:28:26 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PONG len=6
Oct 30 12:28:26 host.example.com sshuttle[12487]: c : received PING response
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PING len=6 (fullness=34080)
Oct 30 12:28:27 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PING len=6
Oct 30 12:28:27 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PONG len=6 (fullness=29451)
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PONG len=6
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s: received PING response
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PING len=6 (fullness=32952)
Oct 30 12:28:27 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PING len=6
Oct 30 12:28:27 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PONG len=6 (fullness=29457)
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PONG len=6
Oct 30 12:28:27 host.example.com sshuttle[12487]:  s: received PING response
Oct 30 12:29:29 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PING len=6 (fullness=33464)
Oct 30 12:29:29 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PING len=6
Oct 30 12:29:29 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PONG len=6 (fullness=23910)
Oct 30 12:29:29 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PONG len=6
Oct 30 12:29:29 host.example.com sshuttle[12487]: c : received PING response
Oct 30 12:29:36 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PING len=6 (fullness=33915)
Oct 30 12:29:36 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PING len=6
Oct 30 12:29:36 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PONG len=6 (fullness=24264)
Oct 30 12:29:36 host.example.com sshuttle[12487]: c :  > channel=0 cmd=PING len=6 (fullness=50477)
Oct 30 12:29:36 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PONG len=6
Oct 30 12:29:36 host.example.com sshuttle[12487]:  s: received PING response
Oct 30 12:29:36 host.example.com sshuttle[12487]:  s: <  channel=0 cmd=PING len=6
Oct 30 12:29:36 host.example.com sshuttle[12487]:  s:  > channel=0 cmd=PONG len=6 (fullness=13054)
Oct 30 12:29:36 host.example.com sshuttle[12487]: c : <  channel=0 cmd=PONG len=6
Oct 30 12:29:36 host.example.com sshuttle[12487]: c : received PING response

Those were the last PING/PONG messages from that tunnel, yet that tunnel stayed alive until the connection timeout finally kicked in:

Oct 30 13:53:54 host.example.com sshuttle[12487]: c : Remaining DNS requests: 2
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : Remaining UDP channels: 0
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : read: err was: [Errno 11] Resource temporarily unavailable
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : Waiting: 6 r=[5, 7, 9, 23] w=[9] x=[] (fullness=20255/0)
Oct 30 13:53:54 host.example.com sshuttle[12487]: c :   Ready: 6 r=[] w=[9] x=[]
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : mux wrote: 55/55
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : read: err was: [Errno 11] Resource temporarily unavailable
Oct 30 13:53:54 host.example.com sshuttle[12487]: c : Waiting: 6 r=[5, 7, 9, 23] w=[] x=[] (fullness=20255/0)
Oct 30 13:54:20 host.example.com sshuttle[12487]: packet_write_wait: Connection to UNKNOWN port 65535: Broken pipe
Oct 30 13:54:20 host.example.com sshuttle[12487]: c :   Ready: 6 r=[9] w=[] x=[]
Oct 30 13:54:20 host.example.com sshuttle[12487]: c : read: err was: [Errno 11] Resource temporarily unavailable
Oct 30 13:54:20 host.example.com sshuttle[12487]: c : read: err was: [Errno 11] Resource temporarily unavailable
Oct 30 13:54:20 host.example.com sshuttle[12487]: firewall manager: undoing changes.
Oct 30 13:54:20 host.example.com sshuttle[12487]: firewall manager: undoing IPv4 changes.
Oct 30 13:54:21 host.example.com sshuttle[12487]: >> iptables -t nat -D OUTPUT -j sshuttle-12304
Oct 30 13:54:21 host.example.com sshuttle[12487]: >> iptables -t nat -D PREROUTING -j sshuttle-12304
Oct 30 13:54:21 host.example.com sshuttle[12487]: >> iptables -t nat -F sshuttle-12304
Oct 30 13:54:21 host.example.com sshuttle[12487]: >> iptables -t nat -X sshuttle-12304
Oct 30 13:54:21 host.example.com sshuttle[12487]: firewall manager: undoing /etc/hosts changes.
Oct 30 13:54:21 host.example.com sshuttle[12487]: c : fatal: server died with error code 255

As you can see above though, the last PING/PONG messages on my tunnel were almost a half hour before the tunnel finally died.

What are the PING/PONG messages for if not to at minimum detect dead tunnels (and hopefully restart them)?

[brianmay]

I am guessing the purpose of PING/PONG might be to keep the connection alive in case there is something present that disconnects idle connections.

Yes, would be good if it would disconnect dead connections too. PR welcome!

[carbolymer]

As a workaround one can use following script:

ssh user@router.home "ps ux | grep ssh | grep notty | cut -d' ' -f3 | xargs kill"

sshuttle -D --pidfile /tmp/sshuttle-home.pid -r router.home 10.10.10.0/24
journalctl -f -q -n 0 -t sshuttle | grep --line-buffered -E 'Timeout|died|Broken|closed' | while read line
do 
  kill -9 `cat /tmp/sshuttle-home.pid`
  sleep 1
  shuttle -D --pidfile /tmp/sshuttle-home.pid -r router.home 10.10.10.0/24
done

[skuhl]

The fix for #494 makes sshuttle exit when the ssh process exits/finishes. If that is happening for the original poster, then it should fix the problem.

[skuhl]

Is it possible that the iptables rules that sshuttle set up got reset/overwritten somehow? Since the client-server connection doesn't rely on iptables, that would explain why that continues to run. Everything else that goes through sshuttle depends on the iptable rules being correctly set up.

[rderooy]

Perhaps this could also help with detecting network changes. For instance, I run sshuttle on a notebook and the network can change due to various reasons like change from ethernet <> wifi or move from the office to home. Right now sshuttle keeps running and causes network problems until I kill and restart it.

I would prefer if sshuttle would either stop by itself if the underlying network connection vanishes, or to try to re-connect.

[skuhl]

I would prefer if sshuttle would either stop by itself if the underlying network connection vanishes, or to try to re-connect.

Which version of sshuttle are you using? I had similar troubles, prior to the fix for #494. I think version 1.0.5 and newer should have the fix. With the fix, sshuttle should exit when the ssh process exits.

[rderooy]

I have been using sshuttle-1.0.5-2.fc34.noarch for some time, but recently I have switched to a build I did myself to get some of the systemd-resolve fixes.

In any case, I have never seen sshuttle disconnect by itself. Also, it can take a very long time for ssh sessions to time out on a sudden disconnect, so that does not sound like a great solution.

[skuhl]

I have the following in my ssh config file so that ssh sends a null packet every 5 seconds (and expects a response). If 3 in a row receive no response, ssh exits. I forgot I had it configured that way and that explains why we are seeing different behaviors. The downside of setting these numbers too small is that ssh might exit prematurely for a network outage that is actually temporary.

ServerAliveInterval 5
ServerAliveCountMax 3

[brianjmurrell]

I have the following in my ssh config file so that ssh sends a null packet every 5 seconds (and expects a response). If 3 in a row receive no response, ssh exits. I forgot I had it configured that way and that explains why we are seeing different behaviors. The downside of setting these numbers too small is that ssh might exit prematurely for a network outage that is actually temporary.

ServerAliveInterval 5
ServerAliveCountMax 3

And if your Internet connection (or any other link between you and the remote server) goes down for just 60 seconds, you lose your tunnel. Without the above your tunnel would survive such a short outage.

[skuhl]

That is the trouble with trying to detect a dead tunnel: How long do you wait? Waiting a short period of time may be sensible when using sshuttle on a laptop that changes networks regularly. For other use cases, you may want sshuttle to be a lot more patient.

ssh has a built-in, well-tested way of detecting dead connections and does/can exit if the connection is dead. Recent versions of sshuttle automatically exit when ssh exits. We could pass the different ServerAlive options to ssh from sshuttle, but that would require agreement on sensible values and/or another configuration option to allow them to be overridden. Therefore, it makes sense to me to rely on the user's ssh configuration to detect dead tunnels instead of handling it in sshuttle. It can be configured to wait a long time or a short time.

To answer the question in the original report, the ping/pong messages are not used to detect dead connections, they are used as a part of a way to reduce latency and deal with large ssh buffers that can lead to increased latency.