Skip to content

[XU4] [4.9.51-1-ARCH] systemd-networkd watchdog timeout - network stack seemingly FUBARs #317

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
aphirst opened this issue Oct 8, 2017 · 9 comments

Comments

@aphirst
Copy link

aphirst commented Oct 8, 2017

Please feel free to rename/retag this as and when the underlying issue becomes clear

I originally posted this on the rpi tracker but it occurs to me that this issue might not be the same, as I had superficially thought.

My XU4 "server" went down suddenly today, and I was unable to SSH back in. (EDIT: I also couldn't reach the device via ping.) Foolishly I neglected to try UART, and instead just did a power cycle. Afterwards I took some journalctl -xe logs. https://pastebin.com/ZVAgLFJH

It looks as if I was under ssh login bombardment. (I've since reconfigured my firewall, and disabled password login - keys are better anyway.) But as of about line 805, you see this:

Oct 08 18:35:24 alarm kernel: fb_ili9340 spi1.0: I/O Error: rx-0 tx-1 res:rx-p tx-f len-4096
Oct 08 18:35:24 alarm kernel: fb_ili9340 spi1.0: SPI transfer failed: -5
Oct 08 18:35:24 alarm kernel: spi_master spi1: failed to transfer one message from queue
Oct 08 18:35:24 alarm kernel: fb_ili9340 spi1.0: fbtft_update_display: write_vmem failed to update display buffer
Oct 08 18:35:46 alarm kernel: INFO: rcu_preempt detected stalls on CPUs/tasks:
Oct 08 18:35:46 alarm kernel:         4-...: (1 GPs behind) idle=75b/140000000000000/0 softirq=4893732/4893733 fqs=1986
Oct 08 18:35:46 alarm kernel:         (detected by 1, t=4202 jiffies, g=2562895, c=2562894, q=602)
Oct 08 18:35:46 alarm kernel: Task dump for CPU 4:
Oct 08 18:35:46 alarm kernel: kworker/4:0     R  running task        0 30198      2 0x00000002
Oct 08 18:35:46 alarm kernel: Workqueue: events fb_deferred_io_work
Oct 08 18:35:46 alarm kernel: [<c0968994>] (__schedule) from [<00000001>] (0x1)
Oct 08 18:36:38 alarm systemd[1]: systemd-timesyncd.service: Watchdog timeout (limit 3min)!
Oct 08 18:36:38 alarm systemd[1]: systemd-timesyncd.service: Killing process 343 (systemd-timesyn) with signal SIGABRT.
Oct 08 18:36:49 alarm kernel: INFO: rcu_preempt detected stalls on CPUs/tasks:
Oct 08 18:36:49 alarm kernel:         4-...: (1 GPs behind) idle=75b/140000000000000/0 softirq=4893732/4893733 fqs=8125
Oct 08 18:36:49 alarm kernel:         (detected by 0, t=16809 jiffies, g=2562895, c=2562894, q=974)
Oct 08 18:36:49 alarm kernel: Task dump for CPU 4:
Oct 08 18:36:49 alarm kernel: kworker/4:0     R  running task        0 30198      2 0x00000002
Oct 08 18:36:49 alarm kernel: Workqueue: events fb_deferred_io_work
Oct 08 18:36:49 alarm kernel: [<c0968994>] (__schedule) from [<00000001>] (0x1)
Oct 08 18:37:38 alarm systemd[1]: systemd-networkd.service: Watchdog timeout (limit 3min)!
Oct 08 18:37:38 alarm systemd[1]: systemd-networkd.service: Killing process 283 (systemd-network) with signal SIGABRT.
Oct 08 18:37:52 alarm kernel: INFO: rcu_preempt detected stalls on CPUs/tasks:
Oct 08 18:37:52 alarm kernel:         4-...: (1 GPs behind) idle=75b/140000000000000/0 softirq=4893732/4893733 fqs=14073
Oct 08 18:37:52 alarm kernel:         (detected by 1, t=29412 jiffies, g=2562895, c=2562894, q=1116)
Oct 08 18:37:52 alarm kernel: Task dump for CPU 4:
Oct 08 18:37:52 alarm kernel: kworker/4:0     R  running task        0 30198      2 0x00000002
Oct 08 18:37:52 alarm kernel: Workqueue: events fb_deferred_io_work
Oct 08 18:37:52 alarm kernel: [<c0968994>] (__schedule) from [<00000001>] (0x1)
-- Reboot --

At the end, you can see where I pulled the plug, and after that is just the log from a normal boot.

The module mentioned at the top is that for the CloudShell2 LCD panel (which I am indeed using, or at least, I use the CS2 and enabled the LCD via modprobe.conf, though I haven't really set a use for it yet with a custom script).

How should I best proceed from here?

@polyzen
Copy link

polyzen commented Oct 8, 2017

Had you upgraded openssh and were making use of hmac-ripemd160?

stribika/stribika.github.io@6cb1ee5
stribika/stribika.github.io#46

@aphirst
Copy link
Author

aphirst commented Oct 8, 2017

Just after I did the hard reboot and just before I decided to start looking into the issue I did a pacman -Syu and got an update to openssh-7.6p1-1.

I don't know what hpac-ripemd is so I don't think I'm using it. But since the upgrade SSH works, so I guess I wasn't?

@aphirst
Copy link
Author

aphirst commented Oct 8, 2017

It's probably worth mentioning that I also couldn't ping the device, Destination Unreachable was I think the message. I guess @polyzen was thinking that I updated OpenSSH and due to the removal of that algorithm, couldn't log in for that reason.

@ardje
Copy link

ardje commented Oct 9, 2017 via email

@aphirst
Copy link
Author

aphirst commented Oct 9, 2017

@ardje Yeah, the SSH stuff is probably just a red herring (and like I say, shouldn't happen again since I've locked everything down).

In the meantime I've unloaded (and blacklisted) the display driver, but that's clearly not really a solution. Is there any further info I could provide which might help?

@ardje
Copy link

ardje commented Oct 10, 2017 via email

@aphirst
Copy link
Author

aphirst commented Oct 10, 2017

For now the only thing that seems to fail is the SPI, which -I assume- probably triggered systemd to kill the network.

No, the SPI should not fail, but I also think it did not cause the network outage

@ardje This reads a bit strangely, as if it actually contradicts itself, so as a result I'm not sure I understood what you really meant. Could you clarify?

@radfish
Copy link

radfish commented Oct 17, 2017

Btw, does 'ip set link down dev eth0' and 'ip set link up dev eth0' bring the network back up? (Assuming you have a serial console where you can type this.) It did in my issue with network stack dying on Odroid U3 in 4.9 and 4.13.

@ardje
Copy link

ardje commented Oct 23, 2017

@aphirst : what I meant was that the SPI breakage broke another daemon, at which systemd decided to do a watchdog reboot. So the network was just a symptom of systemd failing to do a watchdog reboot.
As an admin I'm always confused of why they kill the network first. It always takes some work to make sure that sshd starts first and stops last and that networking also stops much later.

ardje pushed a commit to ardje/linux that referenced this issue Apr 5, 2020
commit feee6b2 upstream.

We currently try to shrink a single zone when removing memory.  We use
the zone of the first page of the memory we are removing.  If that
memmap was never initialized (e.g., memory was never onlined), we will
read garbage and can trigger kernel BUGs (due to a stale pointer):

    BUG: unable to handle page fault for address: 000000000000353d
    #PF: supervisor write access in kernel mode
    #PF: error_code(0x0002) - not-present page
    PGD 0 P4D 0
    Oops: 0002 [hardkernel#1] SMP PTI
    CPU: 1 PID: 7 Comm: kworker/u8:0 Not tainted 5.3.0-rc5-next-20190820+ hardkernel#317
    Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.12.1-0-ga5cab58e9a3f-prebuilt.qemu.4
    Workqueue: kacpi_hotplug acpi_hotplug_work_fn
    RIP: 0010:clear_zone_contiguous+0x5/0x10
    Code: 48 89 c6 48 89 c3 e8 2a fe ff ff 48 85 c0 75 cf 5b 5d c3 c6 85 fd 05 00 00 01 5b 5d c3 0f 1f 840
    RSP: 0018:ffffad2400043c98 EFLAGS: 00010246
    RAX: 0000000000000000 RBX: 0000000200000000 RCX: 0000000000000000
    RDX: 0000000000200000 RSI: 0000000000140000 RDI: 0000000000002f40
    RBP: 0000000140000000 R08: 0000000000000000 R09: 0000000000000001
    R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000140000
    R13: 0000000000140000 R14: 0000000000002f40 R15: ffff9e3e7aff3680
    FS:  0000000000000000(0000) GS:ffff9e3e7bb00000(0000) knlGS:0000000000000000
    CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    CR2: 000000000000353d CR3: 0000000058610000 CR4: 00000000000006e0
    DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
    DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
    Call Trace:
     __remove_pages+0x4b/0x640
     arch_remove_memory+0x63/0x8d
     try_remove_memory+0xdb/0x130
     __remove_memory+0xa/0x11
     acpi_memory_device_remove+0x70/0x100
     acpi_bus_trim+0x55/0x90
     acpi_device_hotplug+0x227/0x3a0
     acpi_hotplug_work_fn+0x1a/0x30
     process_one_work+0x221/0x550
     worker_thread+0x50/0x3b0
     kthread+0x105/0x140
     ret_from_fork+0x3a/0x50
    Modules linked in:
    CR2: 000000000000353d

Instead, shrink the zones when offlining memory or when onlining failed.
Introduce and use remove_pfn_range_from_zone(() for that.  We now
properly shrink the zones, even if we have DIMMs whereby

 - Some memory blocks fall into no zone (never onlined)

 - Some memory blocks fall into multiple zones (offlined+re-onlined)

 - Multiple memory blocks that fall into different zones

Drop the zone parameter (with a potential dubious value) from
__remove_pages() and __remove_section().

Link: http://lkml.kernel.org/r/[email protected]
Fixes: f1dd2cd ("mm, memory_hotplug: do not associate hotadded memory to zones until online")	[visible after d0dc12e]
Signed-off-by: David Hildenbrand <[email protected]>
Reviewed-by: Oscar Salvador <[email protected]>
Cc: Michal Hocko <[email protected]>
Cc: "Matthew Wilcox (Oracle)" <[email protected]>
Cc: "Aneesh Kumar K.V" <[email protected]>
Cc: Pavel Tatashin <[email protected]>
Cc: Greg Kroah-Hartman <[email protected]>
Cc: Dan Williams <[email protected]>
Cc: Logan Gunthorpe <[email protected]>
Cc: <[email protected]>	[5.0+]
Signed-off-by: Andrew Morton <[email protected]>
Signed-off-by: Linus Torvalds <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants