Issues booting 1.4 nightly on Sophos XG 85

hb.vyos.usr · September 18, 2022, 2:36pm

I’m trying to install vyos-1.4-rolling-202209160217-amd64.iso onto Sophos XG 85 appliance and running into a problem during live boot.

Hardware

CPU: Intel(R) Atom™ Processor E3930 @ 1.30GHz
RAM: 2048MB (DDR3 1600)
Storage: mmcblk0: mmc0:0001 8GTF4R 7.28 GiB

The live boot starts up fine but appears to hang when reaching this point:

[  210.886447] systemd[1]: Detected architecture x86-64.
[  212.101488] systemd[1]: Set hostname to <localhost.localdomain>.
[  214.271464] systemd[1]: Initializing machine ID from random generator.
[  274.977518] systemd[1]: Queued start job for default target Graphical Interface.
[  275.211734] systemd[1]: Created slice system-getty.slice.
[  275.332187] systemd[1]: Created slice system-modprobe.slice.
[  275.439239] systemd[1]: Created slice system-serial\x2dgetty.slice.
[  275.527642] systemd[1]: Created slice User and Session Slice.
[  275.571209] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  275.609623] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[  275.675261] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[  275.711063] systemd[1]: Reached target Local Encrypted Volumes.
[  275.744361] systemd[1]: Reached target Remote File Systems.
[  275.764433] systemd[1]: Reached target Slices.
[  275.785399] systemd[1]: Reached target Swap.
[  275.840406] systemd[1]: Listening on Syslog Socket.
[  275.876569] systemd[1]: Listening on initctl Compatibility Named Pipe.
[  276.019086] systemd[1]: Listening on Journal Audit Socket.
[  276.077640] systemd[1]: Listening on Journal Socket (/dev/log).
[  276.141494] systemd[1]: Listening on Journal Socket.
[  276.205375] systemd[1]: Listening on udev Control Socket.
[  276.259494] systemd[1]: Listening on udev Kernel Socket.
[  276.478956] systemd[1]: Mounting Huge Pages File System...
[  276.678183] systemd[1]: Mounting POSIX Message Queue File System...
[  276.706677] systemd[1]: Condition check resulted in Xen ProcFS being skipped.
[  276.907126] systemd[1]: Mounting Kernel Debug File System...
[  276.951631] systemd[1]: Condition check resulted in Kernel Trace File System being skipped.
[  277.146392] systemd[1]: Condition check resulted in Set the console keyboard layout being skipped.
[  277.498556] systemd[1]: Starting Create list of static device nodes for the current kernel...
[  277.707398] systemd[1]: Starting Load Kernel Module configfs...
[  277.716143] systemd[1]: Starting Load Kernel Module drm...
[  277.936499] systemd[1]: Starting Load Kernel Module fuse...
[  278.005613] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[  278.018502] fuse: init (API version 7.34)
[  278.019926] systemd[1]: Starting Journal Service...
[  278.034846] systemd[1]: Starting Load Kernel Modules...
[  278.075430] systemd[1]: Starting Remount Root and Kernel File Systems...
[  278.125117] systemd[1]: Starting Coldplug All udev Devices...
[  278.256317] systemd[1]: Mounted Huge Pages File System.
[  278.262404] systemd[1]: Mounted POSIX Message Queue File System.
[  278.269254] systemd[1]: Mounted Kernel Debug File System.
[  278.280405] systemd[1]: Finished Create list of static device nodes for the current kernel.
[  278.340664] systemd[1]: modprobe@configfs.service: Succeeded.
[  278.357352] systemd[1]: Finished Load Kernel Module configfs.
[  278.378144] systemd[1]: modprobe@drm.service: Succeeded.
[  278.390198] systemd[1]: Finished Load Kernel Module drm.
[  278.402224] systemd[1]: modprobe@fuse.service: Succeeded.
[  278.410427] systemd[1]: Finished Load Kernel Module fuse.
[  278.442206] systemd[1]: Finished Remount Root and Kernel File Systems.
[  278.477182] systemd[1]: Mounting FUSE Control File System...
[  278.505178] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[  278.525085] systemd[1]: Mounting Kernel Configuration File System...
[  278.532004] Bridge firewalling registered
[  278.576218] systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
[  278.597516] systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
[  278.630814] systemd[1]: Starting Load/Save Random Seed...
[  278.684060] systemd[1]: Starting Create System Users...
[  278.707010] systemd[1]: Started VyOS configuration daemon.
[  278.735297] systemd[1]: Started VyOS DNS configuration keeper.
[  278.787080] systemd[1]: Finished Load Kernel Modules.
[  278.804809] systemd[1]: Mounted FUSE Control File System.
[  278.829967] systemd[1]: Mounted Kernel Configuration File System.
[  278.846919] systemd[1]: Started Journal Service.
[  278.972881] systemd-journald[354]: Received client request to flush runtime journal.
[  286.311647] EDAC pnd2: Failed to register device with error -22.
[  286.332181] EDAC pnd2: Failed to register device with error -22.

^^^ hangs here ^^^

vvv after short power button press vvv

[ 2445.065355] systemd-journald[354]: Failed to send WATCHDOG=1 notification message: Connection refused
[ 2455.470502] systemd-shutdown[1]: Waiting for process: python3
[ 2457.214241] [3723]: Failed to unmount /usr/lib/live/mount/medium: Device or resource busy
[ 2457.226272] systemd-shutdown[1]: Could not detach loopback /dev/loop0: Device or resource busy
[ 2463.423688] systemd-shutdown[1]: Failed to finalize file systems, loop devices, ignoring.
[ 2463.599301] reboot: Power down

Here is a full boot up log captured over serial interface:

I tried pfSense (pfSense-CE-memstick-serial-2.6.0-RELEASE-amd64.img) and it boots up fine on this appliance. Here is pfSense dmesg which might be of interest:

I would appreciate any hints or ideas.

Thank you.

c-po · September 18, 2022, 3:11pm

Can you please try booting the oldest rolling image? There was a Kernel upgrade (5.10 → 5.15) during the last week.

hb.vyos.usr · September 18, 2022, 5:49pm

Thank you for you suggestions.

I just tried vyos-1.4-rolling-202208170740-amd64.iso kernel 5.10 and it behaves the same as vyos-1.4-rolling-202209160217-amd64.iso kernel 5.15.

Here is the full log:

c-po · September 18, 2022, 7:21pm

Does the device by any chance have a second serial port? Did you check alternative baud rate settings?

hb.vyos.usr · September 18, 2022, 8:53pm

Yes, this device has two serial ports, micro usb and RJ45. Both of these ports behave identically.

I just tried switching to a different baud rate. I’m getting some scrambled characters at 38400 and 19200. This is after I hit Enter few times. See here:

$ picocom --baud 115200 --databits 8 --parity n --flow n /dev/ttyUSB0

[  129.522506] systemd[1]: Starting Create System Users...
[  129.543614] systemd[1]: Started VyOS configuration daemon.
[  129.559147] systemd[1]: Started VyOS DNS configuration keeper.
[  129.576014] systemd[1]: Started Journal Service.
[  129.657257] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[  129.671296] systemd-journald[352]: Received client request to flush runtime journal.
[  129.757186] Bridge firewalling registered
[  136.823241] EDAC pnd2: Failed to register device with error -22.
[  136.844322] EDAC pnd2: Failed to register device with error -22.

*** baud: 57600 ***

*** baud: 38400 ***

��qaܹ1�0{�m�8rc�s���
�x���13���u�\����yC�D.�:{gs�;u����dʽã���\Y9��ƹÃ��^�g�;�^���8ȣ��Q�
�4��,���               �+�����82�Fs���
        ��(φX�����O
H^Ã82�O��9��{l     �r8��-ÃO^ֹ��
              xՔr��9,��Ǘ��
                          ���C�D�q����̯��r�Fs��;������y�{
                                                        s��u��G
                                                               ���?���2c�e�L��O��e���
                                                                                     T
                                                                                      9��\��\~����l��k���`e��u���;�{�V�yC�

*** baud: 19200 ***

���$d�R�Z:�
           �2��o6rxIX�R,�d������,
                                 ",>Gl$���n����flw�6btn&��$f.��&�lt<�#���"��R
                                                                             �Z&��z�#:#����FX"�
                                                                                               |z��sn�

hb.vyos.usr · September 19, 2022, 8:36pm

I tried debian-11.5.0-amd64-netinst.iso with the following options and it booted up fine.

install console=ttyS0,115200n8

Here is the screenshot

@c-po, would you happen to have other suggestions? Or maybe any debug I could provide?
Thanks

hb.vyos.usr · September 19, 2022, 9:14pm

I see VyOS has ‘console’ boot parameter defined twice and with different values:

console=ttyS0,115200
console=tty0

Here is BOOT_IMAGE snippet from the log I posted earlier:

[    0.000000] Command line: BOOT_IMAGE=/live/vmlinuz boot=live components hostname=vyos username=live nopersistence noautologin nonetworking union=overlay console=ttyS0,115200 console=tty0 net.ifnames=0 biosdevname=0 initrd=/live/initrd.img

Would that cause the issue?