[bug]: embassyd sometimes fails to complete graceful shutdown

[islandbitcoin]

trafficstars

Prerequisites

• [X] I have searched for existing issues that already report this problem, without success.

EmbassyOS Version

0.3.0.1

Device

Laptop/Desktop

Device OS

Linux

Device OS Version

Pop!_OS 21.10

Browser

Firefox

Browser Version

99.0 (64-bit)

Current Behavior

when trying to OTA update, embassyd does not shutdown properly, and hangs the update.

Expected Behavior

Shutdown completely. and restart with new update

Steps to Reproduce

Flashed 0.3.0.1 EOS. Initiate OTA update to 0.3.0.2 Click "Restart" when prompted

Anything else?

Logs:

root@embassy-f5fb24ed:~# uname -a Linux embassy-f5fb24ed 5.10.92-v8+ #1514 SMP PREEMPT Mon Jan 17 17:39:38 GMT 2022 aarch64 GNU/Linux root@embassy-f5fb24ed:~#

root@embassy-f5fb24ed:~# journalctl -u embassy-init -efa -- Journal begins at Tue 2022-03-29 08:19:55 BST. -- Apr 14 10:57:24 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 10:57:24 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 10:58:56 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 7 Apr 14 10:59:03 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 14 Apr 14 10:59:12 embassy-f5fb24ed dhclient[1324]: receive_packet failed on wlan0: Network is down Apr 14 10:59:17 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 15 Apr 14 10:59:32 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 12 Apr 14 10:59:44 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 12 Apr 14 10:59:56 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 1 Apr 14 10:59:57 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 10:59:57 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 11:00:10 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 7 Apr 14 11:00:17 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 12 Apr 14 11:00:29 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 9 Apr 14 11:00:38 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 9 Apr 14 11:00:47 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8 Apr 14 11:00:55 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 16 Apr 14 11:01:11 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 11:01:11 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 11:03:44 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 5 Apr 14 11:03:49 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 14 Apr 14 11:04:03 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 8 Apr 14 11:04:11 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 11 Apr 14 11:04:22 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 8 Apr 14 11:04:30 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on br-c204c447bf83 to 255.255.255.255 port 67 interval 15 Apr 14 11:04:35 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 5 Apr 14 11:04:40 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 10 Apr 14 11:04:45 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 11:04:45 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 11:04:50 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 11 Apr 14 11:05:01 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 12 Apr 14 11:05:13 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 8 Apr 14 11:05:21 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 13 Apr 14 11:05:34 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on docker0 to 255.255.255.255 port 67 interval 2 Apr 14 11:05:36 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 6 Apr 14 11:05:36 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 11:05:36 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 11:05:42 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 6 Apr 14 11:05:48 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 10 Apr 14 11:05:58 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 11 Apr 14 11:06:03 embassy-f5fb24ed dhclient[1324]: receive_packet failed on wlan0: Network is down Apr 14 11:06:09 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 18 Apr 14 11:06:27 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 10 Apr 14 11:06:37 embassy-f5fb24ed dhclient[1324]: No DHCPOFFERS received. Apr 14 11:06:37 embassy-f5fb24ed dhclient[1324]: No working leases in persistent database - sleeping. Apr 14 11:09:32 embassy-f5fb24ed dhclient[1324]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 7

root@embassy-f5fb24ed:~# systemctl status embassyd ● embassyd.service - Embassy Daemon Loaded: loaded (/etc/systemd/system/embassyd.service; enabled; vendor preset: enabled) Active: active (running) since Sun 2022-04-10 17:56:45 BST; 3 days ago Main PID: 1442 (embassyd) Tasks: 2 (limit: 9277) CPU: 2d 12h 42min 57.537s CGroup: /system.slice/embassyd.service └─1442 /usr/local/bin/embassyd

Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.637 DEBUG run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Adding mdns CNAME entry for 2vund6kjdciur2jet6ihfogfzq2ufygeabfhnhjw23ytm7zggvvkeqad.local Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.638 INFO run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Published "2vund6kjdciur2jet6ihfogfzq2ufygeabfhnhjw23ytm7zggvvkeqad.local" Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.638 DEBUG run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Adding mdns CNAME entry for egdhxnhvqrsh5aaeywenmvgq2uxsqxgglhbg6j6ajhy6txgdilb3eiid.local Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.639 INFO run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Published "egdhxnhvqrsh5aaeywenmvgq2uxsqxgglhbg6j6ajhy6txgdilb3eiid.local" Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.640 DEBUG run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Adding mdns CNAME entry for bbp43eh3h5gacpuwussexeplf47b7qfgmufmkoui3dt2itaojv2bipyd.local Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.641 INFO run_main:remove{pkg_id=PackageId(Id("bitcoind"))}: embassy::net::mdns: Published "bbp43eh3h5gacpuwussexeplf47b7qfgmufmkoui3dt2itaojv2bipyd.local" Apr 14 14:28:31 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:31.738 DEBUG inner_main{cfg_path=None}:shutdown:empty: embassy::manager: Manager for [email protected] is shutdown Apr 14 14:28:41 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:41.638 DEBUG run_main:remove{pkg_id=PackageId(Id("lnd"))}: embassy::net::mdns: Loading services for mDNS Apr 14 14:28:41 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:41.640 INFO run_main:remove{pkg_id=PackageId(Id("lnd"))}: embassy::net::mdns: Published "embassy-f5fb24ed.local" Apr 14 14:28:41 embassy-f5fb24ed embassyd[1442]: Apr 14 14:28:41.738 DEBUG inner_main{cfg_path=None}:shutdown:empty: embassy::manager: Manager for [email protected] is shutdown root@embassy-f5fb24ed:~#

root@embassy-f5fb24ed:~# dmesg [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083] [ 0.000000] Linux version 5.10.92-v8+ (dom@buildbot) (aarch64-linux-gnu-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1514 SMP PREEMPT Mon Jan 17 17:39:38 GMT 2022 [ 0.000000] random: fast init done [ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.4 [ 0.000000] efi: UEFI not found. [ 0.000000] Reserved memory: created CMA memory pool at 0x000000002a000000, size 64 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff] [ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000ffffffff] [ 0.000000] Normal [mem 0x0000000100000000-0x00000001ffffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff] [ 0.000000] On node 0 totalpages: 2061312 [ 0.000000] DMA zone: 3792 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 242688 pages, LIFO batch:63 [ 0.000000] DMA32 zone: 12288 pages used for memmap [ 0.000000] DMA32 zone: 770048 pages, LIFO batch:63 [ 0.000000] Normal zone: 16384 pages used for memmap [ 0.000000] Normal zone: 1048576 pages, LIFO batch:63 [ 0.000000] percpu: Embedded 32 pages/cpu s91416 r8192 d31464 u131072 [ 0.000000] pcpu-alloc: s91416 r8192 d31464 u131072 alloc=32*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: Spectre-v2 [ 0.000000] CPU features: detected: Spectre-v4 [ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2028848 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=0 bcm2708_fb.fbheight=0 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:DE:05:BB vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 usb-storage.quirks=152d:0562:u,14cd:121c:u,0781:cfcb:u boot=overlay console=ttyS0,115200 console=tty1 root=PARTUUID=cb15ae4d-03 rootfstype=ext4 fsck.repair=yes rootwait quiet [ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) [ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x0000000037400000-0x000000003b400000] (64MB) [ 0.000000] Memory: 7916788K/8245248K available (11136K kernel code, 1950K rwdata, 3988K rodata, 3712K init, 1253K bss, 262924K reserved, 65536K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 36801 entries in 144 pages [ 0.000000] ftrace: allocated 144 pages with 2 groups [ 0.000000] rcu: Preemptible hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] random: get_random_bytes called from start_kernel+0x3b0/0x570 with crng_init=1 [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000006] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000264] Console: colour dummy device 80x25 [ 0.000321] printk: console [tty1] enabled [ 0.000375] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000) [ 0.000401] pid_max: default: 32768 minimum: 301 [ 0.000542] LSM: Security Framework initializing [ 0.000812] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.000915] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.002179] cgroup: Disabling memory control group subsystem [ 0.004528] rcu: Hierarchical SRCU implementation. [ 0.005591] EFI services will not be available. [ 0.006100] smp: Bringing up secondary CPUs ...

[dr-bonez]

will escalate if reproduced

[kn0wmad]

This is occasionally experienced in support, where a user thinks they have restarted, and a 'hard reboot' is required to bring them back online. Please lmk what needs to be provided to help diagnose

[chrisguida]

Why was this closed?

[islandbitcoin]

my bad, closed the wrong issue