Device at v2.85.2 still online and accessible even if glider disconnected #2352

acostach · 2021-10-21T08:48:13Z

Steps to reproduce: provision a device at v2.85.2
Run the testlodge http-connect or socks5 test.

Note that when glider is closed on the host PC, the device under test stays online and the webterminal is still accessible.
When glider is closed, the device should go offline.

Leviathan tests for current open meta-balena PRs are marked as passed.

acostach · 2021-10-21T09:26:17Z

Tested on an older release, on Pi4 2.73.1+rev1 which was known to be working correctly.
Same as with the v2.85.2 release, device comes back up online and the webterminal is also accessible although glider was closed on the host PC.

klutchell · 2021-11-11T12:45:37Z

Does glider show logs of the connections?

klutchell · 2021-11-11T13:17:46Z

I tried to reproduce with the steps from TC141 - socks5 proxy and I cleaned them up a bit in the process.

Everything works as expected for me. Can you try the test again @acostach and share any differences in your results?

If the steps below work we can update Testlodge accordingly, but at the core the test is the same.

TC141 - socks5 proxy

Start glider mixed proxy on your workstation via docker. Keep this terminal open and do not kill the container yet. Make sure to allow port 8123 through your workstation firewall!

docker run --rm --network host --user 995 nadoo/glider:v0.15.0 -verbose -listen :8123

Set these 2 variables in a new workstation terminal to make the next steps easier.

SERVER_IP=<your_workstation_ip_running_glider>
DEVICE_UUID=<your_device_uuid>

Paste this command on your workstation to put a redsocks config on the device.

cat << EOTTY | balena ssh "${DEVICE_UUID}" --tty
mkdir -p /mnt/boot/system-proxy/
cat <<'EOF'> /mnt/boot/system-proxy/redsocks.conf
base {
log_debug = off;
log_info = on;
log = stderr;
daemon = off;
redirector = iptables;
}
redsocks {
type = socks5;
ip = ${SERVER_IP};
port = 8123;
local_ip = 127.0.0.1;
local_port = 12345;
}
EOF
reboot
EOTTY

Verify the device connects to the cloud after it reboots.

balena device $DEVICE_UUID

Verify the glider logs in your other terminal show connections from the device.

2021/11/11 12:51:46 group.go:186: [group] only 1 forwarder found, disable health checking
2021/11/11 12:51:46 server.go:107: [socks5] listening UDP on :8123
2021/11/11 12:51:46 mixed.go:68: [mixed] listening TCP on :8123
2021/11/11 13:01:15 server.go:87: [socks5] 192.168.1.209:57918 <-> 34.192.70.219:443 via DIRECT
2021/11/11 13:01:18 server.go:87: [socks5] 192.168.1.209:57926 <-> 35.169.76.143:443 via DIRECT
2021/11/11 13:01:28 server.go:87: [socks5] 192.168.1.209:57932 <-> 54.164.146.95:443 via DIRECT
2021/11/11 13:01:28 server.go:87: [socks5] 192.168.1.209:57936 <-> 54.160.66.231:443 via DIRECT
2021/11/11 13:01:29 server.go:87: [socks5] 192.168.1.209:57940 <-> 52.203.153.157:443 via DIRECT
2021/11/11 13:01:29 server.go:87: [socks5] 192.168.1.209:57944 <-> 34.192.70.219:443 via DIRECT
2021/11/11 13:01:29 server.go:87: [socks5] 192.168.1.209:57948 <-> 54.147.227.172:443 via DIRECT

Kill the glider container with CTRL-C.
Verify the device is no longer connected to the cloud.

balena device $DEVICE_UUID

Restart the glider proxy with the same command from step one.

docker run --rm --network host --user 995 nadoo/glider:v0.15.0 -verbose -listen :8123

Verify the device is connected to the cloud again.

balena device $DEVICE_UUID

Remove the redsocks config from the device.

cat << EOTTY | balena ssh "${DEVICE_UUID}" --tty
rm -rf /mnt/boot/system-proxy/redsocks.conf && reboot
EOTTY

While the device is rebooting you can kill the glider proxy.
Verify the device reconnects to the cloud without the proxy.

balena device $DEVICE_UUID

acostach · 2021-11-11T13:41:19Z

@klutchell Sure I'll test these steps. By any chance, did you try leave glider in container closed for ~10 minutes and check if the board shows back up even if glider is stopped?

klutchell · 2021-11-11T13:43:41Z

By any chance, did you try leave glider in container closed for ~10 minutes and check if the board shows back up even if glider is stopped?

No, I only waited long enough to see it disconnect when I closed glider. But I can try that now.

UPDATE: I waited an hour and my device remained offline when glider was not running.

acostach · 2021-11-12T11:35:49Z

Hi @klutchell , I've tried now with 2.85.2 and can still reproduce the issue:

docker run --rm --network host --user 995 nadoo/glider:v0.15.0 -verbose -listen :8123
Unable to find image 'nadoo/glider:v0.15.0' locally
v0.15.0: Pulling from nadoo/glider
29291e31a76a: Pull complete 
7ae280a0a2e7: Pull complete 
8a71bc7c5d51: Pull complete 
Digest: sha256:5f4da128a7064dd49af7b2c033c850a4d13636aa954fdd00421a08adc7d6dd95
Status: Downloaded newer image for nadoo/glider:v0.15.0
2021/11/12 11:20:15 group.go:186: [group] only 1 forwarder found, disable health checking
2021/11/12 11:20:15 server.go:107: [socks5] listening UDP on :8123
2021/11/12 11:20:15 mixed.go:68: [mixed] listening TCP on :8123
2021/11/12 11:21:53 server.go:87: [socks5] 192.168.0.198:49676 <-> 34.195.99.244:443 via DIRECT
^C

cat /mnt/boot/system-proxy/redsocks.conf 
base {
log_debug = off;
log_info = on;
log = stderr;
daemon = off;
redirector = iptables;
}
redsocks {
type = socks5;
ip = 192.168.0.110;
port = 8123;
local_ip = 127.0.0.1;
local_port = 12345;
}

I also booted the board with this config and the glider container stopped, and it showed up online.

Tested with meta-balena v2.85.2.

floion · 2021-11-12T12:43:56Z

I just tested with OS 2021.10.2 on a raspberrypi3 device type and the bug is reproducible.
As Alex also observed, when closing the glider container the device didn't even go offline.

klutchell · 2021-11-12T13:44:52Z

I just tested balenaOS 2.86.0+rev1 on raspberrypi3 and could not reproduce. The device would not come online unless glider was running. Stopping glider disconnected the device immediately.

I will try some other things to reproduce...

klutchell · 2021-11-12T13:48:09Z

@floion @acostach is the redsocks service still running when glider is disconnected? Can you collect redsocks journal logs? My logs are full of Connection refused during the windows where glider was not running.

acostach · 2021-11-16T12:10:33Z

@klutchell I took these debug logs with the last production image of Pi4, in production environment, they most likely match what @floion saw since it's the same behavior:

root@6962f75:~# journalctl | grep -i redsocks
Nov 16 11:58:35 6962f75 sh[1373]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:35 6962f75 sh[1374]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:35 6962f75 sh[1376]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: Joining mDNS multicast group on interface resin-redsocks.IPv4 with address 10.114.103.1.
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: New relevant interface resin-redsocks.IPv4 for mDNS.
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: Registering new address record for 10.114.103.1 on resin-redsocks.IPv4.
Nov 16 11:58:36 6962f75 NetworkManager[1324]: <info>  [1637063916.2960] manager: (resin-redsocks): new Bridge device (/org/freedesktop/NetworkManager/Devices/5)
Nov 16 11:58:36 6962f75 redsocks[1424]: 1637063916.469490 warning redsocks.c:177 redsocks_onexit(...) Overwriting `redsocks:local_ip` entry: it needs to match OS' iptables configuration.
Nov 16 11:58:36 6962f75 redsocks[1424]: 1637063916.469789 notice main.c:167 main(...) redsocks started, conn_max=128
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.540162 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:61446->35.169.89.252:443]: accepted
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.554331 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:56570->18.210.69.101:443]: accepted
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.629375 debug redsocks.c:352 redsocks_start_relay(...) [192.168.0.130:61446->35.169.89.252:443]: data relaying started
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.629733 debug redsocks.c:352 redsocks_start_relay(...) [192.168.0.130:56570->18.210.69.101:443]: data relaying started
Nov 16 11:59:09 6962f75 redsocks[1424]: 1637063949.496040 info redsocks.c:682 redsocks_drop_client(...) [192.168.0.130:56570->18.210.69.101:443]: connection closed
root@6962f75:~# cat /etc/os-release 
ID="balena-os"
NAME="balenaOS"
VERSION="2.85.2+rev3"
VERSION_ID="2.85.2+rev3"
PRETTY_NAME="balenaOS 2.85.2+rev3"
MACHINE="raspberrypi4-64"
META_BALENA_VERSION="2.85.2"
BALENA_BOARD_REV="ab7bc92"
META_BALENA_REV="34a41e07"
SLUG="raspberrypi4-64"

Kill glider container, leaving it closed:

docker run --rm --network host --user 995 nadoo/glider:v0.15.0 -verbose -listen :8123
2021/11/16 11:56:51 group.go:186: [group] only 1 forwarder found, disable health checking
2021/11/16 11:56:51 mixed.go:68: [mixed] listening TCP on :8123
2021/11/16 11:56:51 server.go:107: [socks5] listening UDP on :8123
2021/11/16 11:59:03 server.go:87: [socks5] 192.168.0.130:57110 <-> 18.210.69.101:443 via DIRECT
2021/11/16 11:59:03 server.go:87: [socks5] 192.168.0.130:57106 <-> 35.169.89.252:443 via DIRECT
^C

Device goes offline briefly, then comes back online:

root@6962f75:~# journalctl | grep -i redsocks
Nov 16 11:58:35 6962f75 sh[1373]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:35 6962f75 sh[1374]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:35 6962f75 sh[1376]: iptables v1.8.4 (legacy): Couldn't load target `REDSOCKS':No such file or directory
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: Joining mDNS multicast group on interface resin-redsocks.IPv4 with address 10.114.103.1.
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: New relevant interface resin-redsocks.IPv4 for mDNS.
Nov 16 11:58:36 6962f75 avahi-daemon[1352]: Registering new address record for 10.114.103.1 on resin-redsocks.IPv4.
Nov 16 11:58:36 6962f75 NetworkManager[1324]: <info>  [1637063916.2960] manager: (resin-redsocks): new Bridge device (/org/freedesktop/NetworkManager/Devices/5)
Nov 16 11:58:36 6962f75 redsocks[1424]: 1637063916.469490 warning redsocks.c:177 redsocks_onexit(...) Overwriting `redsocks:local_ip` entry: it needs to match OS' iptables configuration.
Nov 16 11:58:36 6962f75 redsocks[1424]: 1637063916.469789 notice main.c:167 main(...) redsocks started, conn_max=128
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.540162 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:61446->35.169.89.252:443]: accepted
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.554331 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:56570->18.210.69.101:443]: accepted
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.629375 debug redsocks.c:352 redsocks_start_relay(...) [192.168.0.130:61446->35.169.89.252:443]: data relaying started
Nov 16 11:58:45 6962f75 redsocks[1424]: 1637063925.629733 debug redsocks.c:352 redsocks_start_relay(...) [192.168.0.130:56570->18.210.69.101:443]: data relaying started
Nov 16 11:59:09 6962f75 redsocks[1424]: 1637063949.496040 info redsocks.c:682 redsocks_drop_client(...) [192.168.0.130:56570->18.210.69.101:443]: connection closed
Nov 16 11:59:56 6962f75 redsocks[1424]: 1637063996.111891 info redsocks.c:682 redsocks_drop_client(...) [192.168.0.130:61446->35.169.89.252:443]: connection closed
Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.131752 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:61492->35.169.89.252:443]: accepted
Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.211803 notice utils.c:269 red_is_socket_connected_ok(...) connect: Connection refused
Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.211905 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:61492->35.169.89.252:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.211962 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:61492->35.169.89.252:443]: dropping client (R/W), relay (R/W), idle 0.000182s
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.232164 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:54812->35.169.76.143:443]: accepted
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237038 notice utils.c:269 red_is_socket_connected_ok(...) connect: Connection refused
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237117 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:54812->35.169.76.143:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237168 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:54812->35.169.76.143:443]: dropping client (R/W), relay (R/W), idle 0.000144s
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.257491 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:59492->3.227.28.93:443]: accepted
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.261982 notice utils.c:269 red_is_socket_connected_ok(...) connect: Connection refused
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.262061 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:59492->3.227.28.93:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.262112 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:59492->3.227.28.93:443]: dropping client (R/W), relay (R/W), idle 0.000146s

root@6962f75:~# systemctl status redsocks 
● redsocks.service - redsocks transparent proxy redirector
     Loaded: loaded (/lib/systemd/system/redsocks.service; enabled; vendor preset: enabled)
     Active: active (running) since Tue 2021-11-16 11:58:36 UTC; 4min 18s ago
   Main PID: 1424 (redsocks)
      Tasks: 1 (limit: 822)
     Memory: 552.0K
     CGroup: /system.slice/redsocks.service
             └─1424 /usr/bin/redsocks -c /mnt/boot/system-proxy/redsocks.conf

Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.211905 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:61492->35.169.89.252:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:01 6962f75 redsocks[1424]: 1637064001.211962 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:61492->35.169.89.252:443]: dropping client (R/W), relay (R/W), idle 0.000182s
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.232164 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:54812->35.169.76.143:443]: accepted
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237038 notice utils.c:269 red_is_socket_connected_ok(...) connect: Connection refused
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237117 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:54812->35.169.76.143:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:06 6962f75 redsocks[1424]: 1637064006.237168 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:54812->35.169.76.143:443]: dropping client (R/W), relay (R/W), idle 0.000144s
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.257491 info redsocks.c:1254 redsocks_accept_client(...) [192.168.0.130:59492->3.227.28.93:443]: accepted
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.261982 notice utils.c:269 red_is_socket_connected_ok(...) connect: Connection refused
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.262061 notice redsocks.c:969 redsocks_relay_connected(...) [192.168.0.130:59492->3.227.28.93:443]: red_is_socket_connected_ok: Connection refused
Nov 16 12:00:11 6962f75 redsocks[1424]: 1637064011.262112 info redsocks.c:697 redsocks_drop_client(...) [192.168.0.130:59492->3.227.28.93:443]: dropping client (R/W), relay (R/W), idle 0.000146s

klutchell · 2021-11-22T20:36:40Z

@acostach @floion I tried again today, and while glider was closed my device was offline. My logs look the same as yours, redsocks is still running but the connection is refused over and over.

How are you determining that the device is "back online" after a few minutes? I'm using the balena CLI and the balena dashboard to verify that it is no longer able to reach the API when glider is offline. However, existing SSH sessions seem to stay alive. Note that ping tests always ignore the proxy as well.

acostach · 2021-11-23T08:15:38Z

@klutchell we're using the dashboard and are accessing the device trough the webterminal. Commands can be run trough the web termina, status is set to online..

klutchell · 2021-11-23T18:02:59Z

@acostach, @floion your device is accessing the internet over IPv6 and I'm pretty sure redsocks is not configured to proxy IPv6 traffic. I tested IPv4 traffic and it seems to be failing. I'll open a separate issue for supporting the proxy of IPv6 traffic.

For now we need to adjust the manual proxy tests to curl an IPv4 only endpoint from a shell on the device.

See https://github.com/balena-io-modules/device-diagnostics/pull/294/files

curl -qs "https://ipv4.google.com" >/dev/null || echo "failed"

alexgg added this to To do in balenaOS Oct 21, 2021

klutchell mentioned this issue Nov 11, 2021

connectivity: proxy: move nadoo/glider to container #2364

Merged

6 tasks

klutchell mentioned this issue Nov 18, 2021

Test for non-connectivity when socks5/http proxy is disconnected #2400

Open

klutchell mentioned this issue Nov 23, 2021

Support proxying IPv6 traffic via redsocks #2408

Open

alexgg removed this from To do in balenaOS Oct 13, 2022

shaunco mentioned this issue Jul 17, 2023

Moving to redsocks2 (w/shadowsocks)? #3193

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Device at v2.85.2 still online and accessible even if glider disconnected #2352

Device at v2.85.2 still online and accessible even if glider disconnected #2352

acostach commented Oct 21, 2021 •

edited

acostach commented Oct 21, 2021

klutchell commented Nov 11, 2021

klutchell commented Nov 11, 2021

acostach commented Nov 11, 2021

klutchell commented Nov 11, 2021 •

edited

acostach commented Nov 12, 2021 •

edited

floion commented Nov 12, 2021

klutchell commented Nov 12, 2021

klutchell commented Nov 12, 2021 •

edited

acostach commented Nov 16, 2021

klutchell commented Nov 22, 2021 •

edited

acostach commented Nov 23, 2021

klutchell commented Nov 23, 2021

Device at v2.85.2 still online and accessible even if glider disconnected #2352

Device at v2.85.2 still online and accessible even if glider disconnected #2352

Comments

acostach commented Oct 21, 2021 • edited

acostach commented Oct 21, 2021

klutchell commented Nov 11, 2021

klutchell commented Nov 11, 2021

TC141 - socks5 proxy

acostach commented Nov 11, 2021

klutchell commented Nov 11, 2021 • edited

acostach commented Nov 12, 2021 • edited

floion commented Nov 12, 2021

klutchell commented Nov 12, 2021

klutchell commented Nov 12, 2021 • edited

acostach commented Nov 16, 2021

klutchell commented Nov 22, 2021 • edited

acostach commented Nov 23, 2021

klutchell commented Nov 23, 2021

acostach commented Oct 21, 2021 •

edited

klutchell commented Nov 11, 2021 •

edited

acostach commented Nov 12, 2021 •

edited

klutchell commented Nov 12, 2021 •

edited

klutchell commented Nov 22, 2021 •

edited