ApolloX extension periodically restarts imx8 board

dfliegel · August 10, 2023, 7:53pm

Hello Toradex community!

We are very happy with your boards and the quality of them but now we are trying to implement an application with your Torizon IDE Extension - ApolloX 2.1.0.
We user the Verdin Development Board V1.1D with an imx8m-plus daughterboard.
After ApolloX tries to discover the Board, the board reboots because of watchdog failure. This starts an infinite reboot loop because of watchdog failure.
Now the steps:

My Desktop Operating System is ArchLinux
I’m using proprietary Visual Studio Code
Imx8m gets fresh installed with a recent TorizonCore Image via EasyInstaller
I login via ssh and change the password of the torizon user
press “+” in the extension to add a Board
I enter IP, user and password and after a few seconds the imx8m reboots

It is working for a colleague who is using Ubuntu Linux. I can’t figure out, what is wrong?

Here you see a journalctl log of the imx8m- board before it starts reboot loop:

Jul 31 13:44:52 verdin-imx8mp-14753725 systemd[1]: Started OpenSSH Per-Connection Daemon (10.42.0.1:48686).
Jul 31 13:44:52 verdin-imx8mp-14753725 sshd[1110]: Accepted password for torizon from 10.42.0.1 port 48686 ssh2
Jul 31 13:44:52 verdin-imx8mp-14753725 sshd[1110]: pam_unix(sshd:session): session opened for user torizon(uid=1000) by (uid=0)
Jul 31 13:44:52 verdin-imx8mp-14753725 systemd-logind[804]: New session c2 of user torizon.
Jul 31 13:44:52 verdin-imx8mp-14753725 systemd[1]: Started Session c2 of User torizon.
Jul 31 13:44:52 verdin-imx8mp-14753725 audit[1110]: SYSCALL arch=c00000b7 syscall=64 success=yes exit=4 a0=7 a1=ffffc6ebe4e0 a2=4 a3=ffffbb395920 items=0 ppid=1 pid=1110 auid=100
0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=2 comm="sshd" exe="/usr/sbin/sshd" key=(null)
Jul 31 13:44:52 verdin-imx8mp-14753725 audit: PROCTITLE proctitle=737368643A20746F72697A6F6E205B707269765D
Jul 31 13:44:52 verdin-imx8mp-14753725 kernel: audit: type=1006 audit(1690811092.612:56): pid=1110 uid=0 old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=2 res=1
Jul 31 13:44:52 verdin-imx8mp-14753725 kernel: audit: type=1300 audit(1690811092.612:56): arch=c00000b7 syscall=64 success=yes exit=4 a0=7 a1=ffffc6ebe4e0 a2=4 a3=ffffbb395920 it
ems=0 ppid=1 pid=1110 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=2 comm="sshd" exe="/usr/sbin/sshd" key=(null)
Jul 31 13:44:52 verdin-imx8mp-14753725 kernel: audit: type=1327 audit(1690811092.612:56): proctitle=737368643A20746F72697A6F6E205B707269765D
Jul 31 13:44:52 verdin-imx8mp-14753725 systemd[1]: Started OpenSSH Per-Connection Daemon (10.42.0.1:48688).
Jul 31 13:44:52 verdin-imx8mp-14753725 sshd[1120]: Accepted password for torizon from 10.42.0.1 port 48688 ssh2
Jul 31 13:44:52 verdin-imx8mp-14753725 sshd[1120]: pam_unix(sshd:session): session opened for user torizon(uid=1000) by (uid=0)
Jul 31 13:44:52 verdin-imx8mp-14753725 systemd-logind[804]: New session c3 of user torizon.
Jul 31 13:44:52 verdin-imx8mp-14753725 systemd[1]: Started Session c3 of User torizon.
Jul 31 13:44:52 verdin-imx8mp-14753725 audit[1120]: SYSCALL arch=c00000b7 syscall=64 success=yes exit=4 a0=7 a1=ffffc8727ba0 a2=4 a3=ffff8a10c920 items=0 ppid=1 pid=1120 auid=100
0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=3 comm="sshd" exe="/usr/sbin/sshd" key=(null)
Jul 31 13:44:52 verdin-imx8mp-14753725 audit: PROCTITLE proctitle=737368643A20746F72697A6F6E205B707269765D
Jul 31 13:44:53 verdin-imx8mp-14753725 kernel: audit: type=1006 audit(1690811092.982:57): pid=1120 uid=0 old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=3 res=1
Jul 31 13:44:53 verdin-imx8mp-14753725 kernel: audit: type=1300 audit(1690811092.982:57): arch=c00000b7 syscall=64 success=yes exit=4 a0=7 a1=ffffc8727ba0 a2=4 a3=ffff8a10c920 it
ems=0 ppid=1 pid=1120 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=3 comm="sshd" exe="/usr/sbin/sshd" key=(null)
Jul 31 13:44:53 verdin-imx8mp-14753725 kernel: audit: type=1327 audit(1690811092.982:57): proctitle=737368643A20746F72697A6F6E205B707269765D
Jul 31 13:44:53 verdin-imx8mp-14753725 sudo[1126]:  torizon : PWD=/var/rootdirs/home/torizon ; USER=root ; COMMAND=/usr/bin/mkdir -p /etc/systemd/system/docker.service.d
Jul 31 13:44:53 verdin-imx8mp-14753725 sudo[1132]:  torizon : PWD=/var/rootdirs/home/torizon ; USER=root ; COMMAND=/usr/bin/sh -c 'echo \'{#012   "insecure-registries" : [":5002"
]#012}#012\' > /etc/docker/daemon.json'
Jul 31 13:44:53 verdin-imx8mp-14753725 sudo[1136]:  torizon : PWD=/var/rootdirs/home/torizon ; USER=root ; COMMAND=/usr/bin/sh -c 'echo \'[Service]#012ExecStart=#012ExecStart=/us
r/bin/dockerd -H fd:// -H tcp://0.0.0.0:2375#012\' > /etc/systemd/system/docker.service.d/override.conf'
Jul 31 13:44:53 verdin-imx8mp-14753725 sudo[1140]:  torizon : PWD=/var/rootdirs/home/torizon ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload
Jul 31 13:44:53 verdin-imx8mp-14753725 systemd[1]: Reloading.
Jul 31 13:44:53 verdin-imx8mp-14753725 systemd-sysv-generator[1154]: SysV service '/etc/init.d/fuse3' lacks a native systemd unit file. Automatically generating a unit file for c
ompatibility. Please update package to include a native systemd unit file, in order to make it more safe and robust.
Jul 31 13:44:53 verdin-imx8mp-14753725 systemd[1]: docker.service: Current command vanished from the unit file, execution of the command list won't be resumed.
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=14 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=15 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 kernel: audit: type=1334 audit(1690811094.022:58): prog-id=14 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 kernel: audit: type=1334 audit(1690811094.022:59): prog-id=15 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 kernel: audit: type=1334 audit(1690811094.022:60): prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 kernel: audit: type=1334 audit(1690811094.022:61): prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=16 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=17 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=18 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=19 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=20 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=21 op=LOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 audit: BPF prog-id=0 op=UNLOAD
Jul 31 13:44:54 verdin-imx8mp-14753725 sudo[1157]:  torizon : PWD=/var/rootdirs/home/torizon ; USER=root ; COMMAND=/usr/bin/systemctl restart docker
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[897]: time="2023-07-31T13:44:54.147215760Z" level=info msg="Processing signal 'terminated'"
Jul 31 13:44:54 verdin-imx8mp-14753725 systemd[1]: Stopping Docker Application Container Engine...
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[897]: time="2023-07-31T13:44:54.150146536Z" level=info msg="stopping event stream following graceful shutdown" error="<nil>" module
=libcontainerd namespace=moby
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[897]: time="2023-07-31T13:44:54.152268895Z" level=info msg="Daemon shutdown complete"
Jul 31 13:44:54 verdin-imx8mp-14753725 systemd[1]: docker.service: Deactivated successfully.
Jul 31 13:44:54 verdin-imx8mp-14753725 systemd[1]: Stopped Docker Application Container Engine.
Jul 31 13:44:54 verdin-imx8mp-14753725 systemd[1]: Starting Docker Application Container Engine...
Jul 31 13:44:54 verdin-imx8mp-14753725 systemd-timesyncd[642]: Initial synchronization to time server 216.239.35.4:123 (time2.google.com).
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:54.304796820Z" level=info msg="Starting up"
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:54.306067624Z" level=warning msg="Binding to IP address without --tlsverify is insecure and gives roo
t access on this machine to everyone who has access to your network." host="tcp://0.0.0.0:2375"
Jul 31 13:44:54 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:54.306157753Z" level=warning msg="Binding to an IP address, even on localhost, can also give access t
o scripts run in a browser. Be safe out there!" host="tcp://0.0.0.0:2375"
Jul 31 13:44:55 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:55.306669315Z" level=warning msg="Binding to an IP address without --tlsverify is deprecated. Startup
 is intentionally being slowed down to show this message" host="tcp://0.0.0.0:2375"
Jul 31 13:44:55 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:55.306847543Z" level=warning msg="Please consider generating tls certificates with client validation 
to prevent exposing unauthenticated root access to your network" host="tcp://0.0.0.0:2375"
Jul 31 13:44:55 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:55.306911285Z" level=warning msg="You can override this by explicitly specifying '--tls=false' or '--
tlsverify=false'" host="tcp://0.0.0.0:2375"
Jul 31 13:44:55 verdin-imx8mp-14753725 dockerd[1159]: time="2023-07-31T13:44:55.306963404Z" level=warning msg="Support for listening on TCP without authentication or explicit int
ent to run without authentication will be removed in the next release" host="tcp://0.0.0.0:2375"
[  149.172481] watchdog: watchdog0: watchdog did not stop!
[  149.598038] imx2-wdt 30280000.watchdog: Device shutdown: Expect reboot!
[  149.599001] reboot: Restarting system

Here you see the same log of my ubuntu colleague:
The row with the stars (**********) is the row where the imx8m reboots while connected with my ArchLinux box.

Apr 28 18:15:12 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:12.843949375Z" level=warning msg="Binding to an IP address without --tlsverify is deprecated. Startup
 is intentionally being slowed down to show this message" host="tcp://0.0.0.0:2375"
Apr 28 18:15:12 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:12.844085000Z" level=warning msg="Please consider generating tls certificates with client validation 
to prevent exposing unauthenticated root access to your network" host="tcp://0.0.0.0:2375"
Apr 28 18:15:12 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:12.844148625Z" level=warning msg="You can override this by explicitly specifying '--tls=false' or '--
tlsverify=false'" host="tcp://0.0.0.0:2375"
Apr 28 18:15:12 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:12.844202375Z" level=warning msg="Support for listening on TCP without authentication or explicit int
ent to run without authentication will be removed in the next release" host="tcp://0.0.0.0:2375"
**********
Apr 28 18:15:15 verdin-imx8mp-14753725 systemd-timesyncd[693]: Timed out waiting for reply from [2606:4700:f1::123]:123 (time.cloudflare.com).
Apr 28 18:15:25 verdin-imx8mp-14753725 systemd-timesyncd[693]: Timed out waiting for reply from 216.239.35.0:123 (time1.google.com).
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.848294250Z" level=info msg="parsed scheme: \"unix\"" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.848398000Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grp
c
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.848490000Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/con
tainerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.848548750Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.853276500Z" level=info msg="parsed scheme: \"unix\"" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.853369375Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grp
c
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.853466875Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/con
tainerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.853524000Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.970076500Z" level=info msg="[graphdriver] using prior storage driver: overlay2"
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.979360500Z" level=warning msg="Your kernel does not support CPU realtime scheduler"
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.979452750Z" level=warning msg="Your kernel does not support cgroup blkio weight"
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.979503000Z" level=warning msg="Your kernel does not support cgroup blkio weight_device"
Apr 28 18:15:27 verdin-imx8mp-14753725 dockerd[1181]: time="2022-04-28T18:15:27.980143500Z" level=info msg="Loading containers: start."
Apr 28 18:15:28 verdin-imx8mp-14753725 audit[1196]: NETFILTER_CFG table=nat family=2 entries=11 op=xt_replace pid=1196 comm="iptables"
Apr 28 18:15:28 verdin-imx8mp-14753725 audit[1196]: SYSCALL arch=c00000b7 syscall=208 success=yes exit=0 a0=4 a1=0 a2=40 a3=aaaae90279c0 items=0 ppid=1181 pid=1196 auid=429496729
5 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-legacy-multi" key=(null)
Apr 28 18:15:28 verdin-imx8mp-14753725 audit: PROCTITLE proctitle=2F7573722F7362696E2F69707461626C6573002D2D77616974002D74006E6174002D4400505245524F5554494E47002D6D00616464727479
7065002D2D6473742D74797065004C4F43414C002D6A00444F434B4552

Why is this happening? Do you have a hint for me?
I already tried to disable the watchdog with no luck …

Thanks,
Daniel

jeremias.tx · August 10, 2023, 9:45pm

Greetings @dfliegel,

That sounds very odd. Just to make sure I understand, once you connect to the module with our VSCode extension, the module just goes into a reboot loop? It just reboots endlessly? Is there some kind of interval or pattern to the reboots?

Also what specific version of TorizonCore did you flash on this device?

It probably goes without saying but I’m not able to reproduce this, though I use Ubuntu on my laptop as well.

Best Regards,
Jeremias

matheus.tx · August 10, 2023, 11:28pm

Hey @dfliegel

could you please, if there is time before the machine reboot, get the content of the /etc/docker/daemon.json?

BR,

dfliegel · August 11, 2023, 8:13am

Hi Jeremias!

Thanks for you message.
The first reboot happens after ApolloX connects to the board and “does” some things. Roughly after 10s of work of ApolloX. The second and all furthermore reboots happen after 6s the board has bootet. I don’t think that ApolloX already has a SSH connection at this time.

I tried all recent versions of TorizonCore of the last 6 monaths.

Thanks,
Daniel

matheus.tx · August 11, 2023, 8:29am

The issue is not on TorizonCore side, we run tests only for Debian and Ubuntu development hosts. We do not guarantee QA on other Linux distros for now.

BR,

jeremias.tx · August 11, 2023, 9:13pm

@dfliegel,

Could you get us the contents of your /etc/docker/daemon.json file as my colleague Matheus has requested. We have a theory of what might be wrong here but we’d need to see the contents of this file to be certain. That is assuming you have enough time to get the contents of this file in between system reboots.

Best Regards,
Jeremias