[systemd-devel] Serial console issue.

[Yann Le Mouel]

Hello,



I've been following your guidelines (serial-console.html) about serial
console. I'm testing this function via AMT on Intel NUC'S on Centos 7.4. I'm
using AMTTERM package for the test.



I managed to get the serial working until certain point, as below, I can see
the boot which is really fast until set hostname, and then so slow, lines by
lines,



[ 1.781570] hid-generic 0003:03F0:0024.0002: input,hidraw1: USB HID v1.10
Keyboard [CHICONY HP Basic USB Keyboard] on usb-0000:00:14.0-4/input
0

[ 31.333620] systemd[1]: Set hostname to <XXXXXx>.





Then for the first time I see this message truncated "Welcome to emergive
root passo", but I don't see this message in journalctl (log are persistent)



[[[[[[[[[[Welcome to emergGive root passwo[ 4952.329920] EXT4-fs
(sda5): mounted filesystem with ordered data mode. Opts: (null)





From journactl, few logs about not being able to start ttyS1



I enabled ttyS1 as below:

systemctl enable serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service>

systemctl start serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service>





Nov 06 09:37:02 systemd[1]: serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service> holdoff time over, scheduling restart.

Nov 06 09:37:02 systemd[1]: Started Serial Getty on ttyS1.

Nov 06 09:37:02 systemd[1]: Starting Serial Getty on ttyS1...

Nov 06 09:37:02 systemd[1]: ***@ttyS1.service <mailto:***@ttyS1.service>
has no holdoff time, scheduling restart.

Nov 06 09:37:02 systemd[1]: Started Getty on ttyS1.

Nov 06 09:37:02 systemd[1]: Starting Getty on ttyS1...

Nov 06 09:37:02 systemd[1]: serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service> holdoff time over, scheduling restart.

Nov 06 09:37:02 systemd[1]: start request repeated too quickly for
serial-***@ttyS1.service <mailto:serial-***@ttyS1.service>

Nov 06 09:37:02 systemd[1]: Failed to start Serial Getty on ttyS1.

Nov 06 09:37:02 systemd[1]: Unit serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service> entered failed state.

Nov 06 09:37:02 systemd[1]: serial-***@ttyS1.service
<mailto:serial-***@ttyS1.service> failed.



Are you able to help, I may have been missing something? I've been doing the
same test on SLC6, I could to a full reboot via serial console and see all
the ouput, but not getting login prompt as the end.



Hopefully you could help getting this fix, as we are going to use a lot of
Front End devices running on CC 7.4 with serial console compatibility.



Many thanks for your help.

Yann

[Mantas Mikulėnas]

*Nov 06 09:37:02 systemd[1]: Started Serial Getty on ttyS1.*
*Nov 06 09:37:02 systemd[1]: Starting Serial Getty on ttyS1...*
no holdoff time, scheduling restart.*
*Nov 06 09:37:02 systemd[1]: Started Getty on ttyS1.*
*Nov 06 09:37:02 systemd[1]: Starting Getty on ttyS1...*
*Nov 06 09:37:02 systemd[1]: start request repeated too quickly for
*Nov 06 09:37:02 systemd[1]: Failed to start Serial Getty on ttyS1.*

You have two services (getty@ and serial-getty@) fighting over the tty
device. Start by disabling the former.

(Actually, since you're getting dmesg output to the serial console, you
might even have a *third* service, console-getty, doing the same...)

[Lennart Poettering]

Post by Yann Le Mouel
Hello,
I've been following your guidelines (serial-console.html) about serial
console. I'm testing this function via AMT on Intel NUC'S on Centos 7.4. I'm
using AMTTERM package for the test.
I managed to get the serial working until certain point, as below, I can see
the boot which is really fast until set hostname, and then so slow, lines by
lines,

Normally, it should suffice to set the kernel console to ttyS0 (or
whichever device you use) via the kernel cmdline. The rest should then
happen fully automatically, as systemd contains an automatic genreator
which uses this to also invoke a serial getty on the same serial port
you used for the console.

Note that if multiple processes fight for console ownership you will
experience all kinds of problems. The log you pasted shows that you
have ***@.service and serial-***@.service fighting for access to
ttyS1. That's already indication of a problem, and most likely
happened because you enabled these units manually? First of all, that
should not be necessary, as things should work automatically anyway,
as mentioned above. Moreover, enable "***@.service" (as opposed to
serial-***@.service) is incorrect anyway, as that unit is for VTs
only, not for serial ttys.

Hence, I am not entirely sure what changes you made. My recommendation
would be to undo them all, and just set console= on the kernel
cmdline, and all should be good.

Lennart

[Yann Le Mouel]

Hello,

I rebuilt my machine just to make sure it's all clean, now the machine boot
ok with console=ttyS1 on the kernel. But now I've got no output nor login
prompt.

Dmesg | grep tyy
[ 0.000000] console [tty0] enabled
[ 0.464947] 00:01: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 0.485527] 0000:00:16.3: ttyS1 at I/O 0x30e0 (irq = 17) is a 16550A

Grub:
RUB_TIMEOUT=5
GRUB_DISTRIBUTOR="$(sed 's, release .*$,,g' /etc/system-release)"
GRUB_DEFAULT=saved
GRUB_DISABLE_SUBMENU=true
GRUB_TERMINAL_OUTPUT="serial console"
GRUB_SERIAL_COMMAND="serial --speed=115200"
GRUB_CMDLINE_LINUX="biosdevname=0 net.ifnames=0 rhgb
rd.shell=0,console=ttyS1"
GRUB_DISABLE_RECOVERY="true"
GRUB_GFXMODE=text

Output from amtterm for connecting to the machine

~ # amtterm hostname
amtterm: NONE -> CONNECT (connection to host)
16994 open
amtterm: CONNECT -> INIT (redirection initialization)
amtterm: INIT -> AUTH (session authentication)
amtterm: AUTH -> INIT_SOL (serial-over-lan initialization)
amtterm: INIT_SOL -> RUN_SOL (serial-over-lan active)
serial-over-lan redirection ok
connected now, use ^] to escape
The system is powered off.
The system is powered on.
Warning, SOL device is running in loopback mode. Text input may not be
accepted
SOL device is no longer running in loopback mode

Thanks.


-----Original Message-----
From: Lennart Poettering [mailto:***@poettering.net]
Sent: 08 November 2017 13:56
To: Yann Le Mouel <***@lemouel.ch>
Cc: systemd-***@lists.freedesktop.org
Subject: Re: [systemd-devel] Serial console issue.

Post by Yann Le Mouel
Hello,
I've been following your guidelines (serial-console.html) about serial
console. I'm testing this function via AMT on Intel NUC'S on Centos
7.4. I'm using AMTTERM package for the test.
I managed to get the serial working until certain point, as below, I
can see the boot which is really fast until set hostname, and then so
slow, lines by lines,

Normally, it should suffice to set the kernel console to ttyS0 (or whichever
device you use) via the kernel cmdline. The rest should then happen fully
automatically, as systemd contains an automatic genreator which uses this to
also invoke a serial getty on the same serial port you used for the console.

Note that if multiple processes fight for console ownership you will
experience all kinds of problems. The log you pasted shows that you have
***@.service and serial-***@.service fighting for access to ttyS1.
That's already indication of a problem, and most likely happened because you
enabled these units manually? First of all, that should not be necessary, as
things should work automatically anyway, as mentioned above. Moreover,
enable "***@.service" (as opposed to
serial-***@.service) is incorrect anyway, as that unit is for VTs only,
not for serial ttys.

Hence, I am not entirely sure what changes you made. My recommendation would
be to undo them all, and just set console= on the kernel cmdline, and all
should be good.

Lennart

--
Lennart Poettering, Red Hat

[Yann Le Mouel]

There was an extra coma in the grub, which I removed now I'm getting an
output, but still the same, all the output in one shot until : [
1.773708] hid-generic 0003:03F0:0024.0002: input,hidraw1: USB HID v1.10
Keyboard [CHICONY HP Basic USB Keyboard] on usb-0000:00:14.0-4/input0

Then it goes slowly lines by lines from set hostname, then stuck.
At this moment, I can't ping nor access it by ssh.

[ 31.325083] systemd[1]: Set hostname to <XXX>.

# amtterm XXXXX
amtterm: NONE -> CONNECT (connection to host)
16994 open
amtterm: CONNECT -> INIT (redirection initialization)
amtterm: INIT -> AUTH (session authentication)
amtterm: AUTH -> INIT_SOL (serial-over-lan initialization)
amtterm: INIT_SOL -> RUN_SOL (serial-over-lan active)
serial-over-lan redirection ok
connected now, use ^] to escape
The system is powered off.
The system is powered on.
Warning, SOL device is running in loopback mode. Text input may not be
accepted
SOL device is no longer running in loopback mode
[ 0.481486] 0000:00:16.3: ttyS1 at I/O 0x30e0 (irq = 17) is a 16550A
[ 0.483817] Non-volatile memory driver v1.3
[ 0.485314] Linux agpgart interface v0.103
[ 0.516340] tpm_tis MSFT0101:00: 2.0 TPM (device-id 0x1A, rev-id 16)
[ 0.764496] crash memory driver: version 1.1
[ 0.765780] rdac: device handler registered
[ 0.767143] hp_sw: device handler registered
[ 0.768644] emc: device handler registered
[ 0.769923] alua: device handler registered
[ 0.771264] libphy: Fixed MDIO Bus: probed
[ 0.772573] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 0.774926] ehci-pci: EHCI PCI platform driver
[ 0.776424] ehci-pci 0000:00:1d.0: EHCI Host Controller
[ 0.778110] ehci-pci 0000:00:1d.0: new USB bus registered, assigned bus
number 1
[ 0.780596] ehci-pci 0000:00:1d.0: debug port 2
[ 0.785957] ehci-pci 0000:00:1d.0: irq 23, io mem 0xaa03a000
[ 0.793287] ehci-pci 0000:00:1d.0: USB 2.0 started, EHCI 1.00
[ 0.795242] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.797405] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 0.799997] usb usb1: Product: EHCI Host Controller
[ 0.801523] usb usb1: Manufacturer: Linux 3.10.0-514.26.2.el7.x86_64
ehci_hcd
[ 0.804560] usb usb1: SerialNumber: 0000:00:1d.0
[ 0.806081] hub 1-0:1.0: USB hub found
[ 0.807283] hub 1-0:1.0: 3 ports detected
[ 0.808914] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 0.810876] ohci-pci: OHCI PCI platform driver
[ 0.812299] uhci_hcd: USB Universal Host Controller Interface driver
[ 0.814612] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 0.816298] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus
number 2
[ 0.820865] xhci_hcd 0000:00:14.0: hcc params 0x200077c1 hci version
0x100 quirks 0x00009810
[ 0.823879] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.826027] usb usb2: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 0.828309] usb usb2: Product: xHCI Host Controller
[ 0.829960] usb usb2: Manufacturer: Linux 3.10.0-514.26.2.el7.x86_64
xhci-hcd
[ 0.832213] usb usb2: SerialNumber: 0000:00:14.0
[ 0.833843] hub 2-0:1.0: USB hub found
[ 0.835291] hub 2-0:1.0: 11 ports detected
[ 0.838630] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 0.840319] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus
number 3
[ 0.842697] usb usb3: New USB device found, idVendor=1d6b, idProduct=0003
[ 0.845042] usb usb3: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 0.847317] usb usb3: Product: xHCI Host Controller
[ 0.849125] usb usb3: Manufacturer: Linux 3.10.0-514.26.2.el7.x86_64
xhci-hcd
[ 0.851383] usb usb3: SerialNumber: 0000:00:14.0
[ 0.852870] hub 3-0:1.0: USB hub found
[ 0.854291] hub 3-0:1.0: 4 ports detected
[ 0.856500] usbcore: registered new interface driver usbserial
[ 0.858626] usbcore: registered new interface driver usbserial_generic
[ 0.860705] usbserial: USB Serial support registered for generic
[ 0.862639] i8042: PNP: No PS/2 controller found. Probing ports directly.
[ 0.868072] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 0.869831] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 0.871762] mousedev: PS/2 mouse device common for all mice
[ 0.873896] rtc_cmos 00:03: RTC can wake from S4
[ 0.875477] rtc_cmos 00:03: rtc core: registered rtc_cmos as rtc0
[ 0.877444] rtc_cmos 00:03: alarms up to one month, y3k, 242 bytes nvram,
hpet irqs
[ 0.880039] Intel P-state driver initializing.
[ 0.881800] cpuidle: using governor menu
[ 0.883499] hidraw: raw HID events driver (C) Jiri Kosina
[ 0.885443] usbcore: registered new interface driver usbhid
[ 0.887209] usbhid: USB HID core driver
[ 0.888721] drop_monitor: Initializing network drop monitor service
[ 0.890863] TCP: cubic registered
[ 0.891940] Initializing XFRM netlink socket
[ 0.893354] NET: Registered protocol family 10
[ 0.895017] NET: Registered protocol family 17
[ 0.896503] microcode: CPU0 sig=0x306d4, pf=0x40, revision=0x24
[ 0.898651] microcode: CPU1 sig=0x306d4, pf=0x40, revision=0x24
[ 0.900416] microcode: CPU2 sig=0x306d4, pf=0x40, revision=0x24
[ 0.902495] microcode: CPU3 sig=0x306d4, pf=0x40, revision=0x24
[ 0.904692] microcode: Microcode Update Driver: v2.01
<***@aivazian.fsnet.co.uk>, Peter Oruba
[ 0.907222] Loading compiled-in X.509 certificates
[ 0.908809] Loaded X.509 cert 'CentOS Linux kpatch signing key:
ea0413152cde1d98ebdca3fe6f0230904c9ef717'
[ 0.911860] Loaded X.509 cert 'CentOS Linux Driver update signing key:
7f421ee0ab69461574bb358861dbe77762a4201b'
[ 0.915648] Loaded X.509 cert 'CentOS Linux kernel signing key:
618f5ddf772e4be825fb1bb09591862724ed1e97'
[ 0.918822] registered taskstats version 1
[ 0.921877] Key type trusted registered
[ 0.924585] Key type encrypted registered
[ 1.110346] usb 1-1: new high-speed USB device number 2 using ehci-pci
[ 1.191352] usb 2-3: new low-speed USB device number 2 using xhci_hcd
[ 1.226775] usb 1-1: New USB device found, idVendor=8087, idProduct=8001
[ 1.229013] usb 1-1: New USB device strings: Mfr=0, Product=0,
SerialNumber=0
[ 1.231545] hub 1-1:1.0: USB hub found
[ 1.232893] hub 1-1:1.0: 8 ports detected
[ 1.304882] rtc_cmos 00:03: setting system clock to 2017-11-13 16:00:31
UTC (1510588831)
[ 1.307982] Freeing unused kernel memory: 1684k freed
[ 1.313132] systemd[1]: systemd 219 running in system mode. (+PAM +AUDIT
+SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT
+GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 1.319168] systemd[1]: Detected architecture x86-64.
[ 1.320767] systemd[1]: Running in initial RAM disk.

[ 1.361084] usb 2-3: New USB device found, idVendor=046d, idProduct=c018
[ 1.363402] usb 2-3: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[ 1.365661] usb 2-3: Product: USB Optical Mouse
[ 1.367083] usb 2-3: Manufacturer: Logitech
[ 1.370711] input: Logitech USB Optical Mouse as
/devices/pci0000:00/0000:00:14.0/usb2/2-3/2-3:1.0/input/input3
[ 1.374483] hid-generic 0003:046D:C018.0001: input,hidraw0: USB HID v1.11
Mouse [Logitech USB Optical Mouse] on usb-0000:00:14.0-3/input0
[ 1.415361] tsc: Refined TSC clocksource calibration: 2294.691 MHz
[ 1.417345] Switched to clocksource tsc
[ 1.531387] usb 2-4: new low-speed USB device number 3 using xhci_hcd
[ 1.706830] usb 2-4: New USB device found, idVendor=03f0, idProduct=0024
[ 1.709220] usb 2-4: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[ 1.711474] usb 2-4: Product: HP Basic USB Keyboard
[ 1.713190] usb 2-4: Manufacturer: CHICONY
[ 1.719733] input: CHICONY HP Basic USB Keyboard as
/devices/pci0000:00/0000:00:14.0/usb2/2-4/2-4:1.0/input/input4
[ 1.773708] hid-generic 0003:03F0:0024.0002: input,hidraw1: USB HID v1.10
Keyboard [CHICONY HP Basic USB Keyboard] on usb-0000:00:14.0-4/input0
[ 31.325083] systemd[1]: Set hostname to <XXX>.

-----Original Message-----
From: Yann Le Mouel [mailto:***@lemouel.ch]
Sent: 13 November 2017 14:04
To: 'Lennart Poettering' <***@poettering.net>
Cc: 'systemd-***@lists.freedesktop.org'
<systemd-***@lists.freedesktop.org>
Subject: RE: [systemd-devel] Serial console issue.

Hello,

I rebuilt my machine just to make sure it's all clean, now the machine boot
ok with console=ttyS1 on the kernel. But now I've got no output nor login
prompt.

Dmesg | grep tyy
[ 0.000000] console [tty0] enabled
[ 0.464947] 00:01: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[ 0.485527] 0000:00:16.3: ttyS1 at I/O 0x30e0 (irq = 17) is a 16550A

Grub:
RUB_TIMEOUT=5
GRUB_DISTRIBUTOR="$(sed 's, release .*$,,g' /etc/system-release)"
GRUB_DEFAULT=saved
GRUB_DISABLE_SUBMENU=true
GRUB_TERMINAL_OUTPUT="serial console"
GRUB_SERIAL_COMMAND="serial --speed=115200"
GRUB_CMDLINE_LINUX="biosdevname=0 net.ifnames=0 rhgb
rd.shell=0,console=ttyS1"
GRUB_DISABLE_RECOVERY="true"
GRUB_GFXMODE=text

Output from amtterm for connecting to the machine

~ # amtterm hostname
amtterm: NONE -> CONNECT (connection to host)
16994 open
amtterm: CONNECT -> INIT (redirection initialization)
amtterm: INIT -> AUTH (session authentication)
amtterm: AUTH -> INIT_SOL (serial-over-lan initialization)
amtterm: INIT_SOL -> RUN_SOL (serial-over-lan active) serial-over-lan
redirection ok connected now, use ^] to escape The system is powered off.
The system is powered on.
Warning, SOL device is running in loopback mode. Text input may not be
accepted SOL device is no longer running in loopback mode

Thanks.


-----Original Message-----
From: Lennart Poettering [mailto:***@poettering.net]
Sent: 08 November 2017 13:56
To: Yann Le Mouel <***@lemouel.ch>
Cc: systemd-***@lists.freedesktop.org
Subject: Re: [systemd-devel] Serial console issue.

Post by Yann Le Mouel
Hello,
I've been following your guidelines (serial-console.html) about serial
console. I'm testing this function via AMT on Intel NUC'S on Centos
7.4. I'm using AMTTERM package for the test.
I managed to get the serial working until certain point, as below, I
can see the boot which is really fast until set hostname, and then so
slow, lines by lines,

Normally, it should suffice to set the kernel console to ttyS0 (or whichever
device you use) via the kernel cmdline. The rest should then happen fully
automatically, as systemd contains an automatic genreator which uses this to
also invoke a serial getty on the same serial port you used for the console.

Note that if multiple processes fight for console ownership you will
experience all kinds of problems. The log you pasted shows that you have
***@.service and serial-***@.service fighting for access to ttyS1.
That's already indication of a problem, and most likely happened because you
enabled these units manually? First of all, that should not be necessary, as
things should work automatically anyway, as mentioned above. Moreover,
enable "***@.service" (as opposed to
serial-***@.service) is incorrect anyway, as that unit is for VTs only,
not for serial ttys.

Hence, I am not entirely sure what changes you made. My recommendation would
be to undo them all, and just set console= on the kernel cmdline, and all
should be good.

Lennart

--
Lennart Poettering, Red Hat