serial uart1/2/3 isn't ready for the first 30 seconds

[att2]

Hello,

I installed Debian Buster with Kernel 4.9.241 on an Odroid C4;
Basically, I installed from: https://oph.mdrjr.net/meveric/images/Buster/ -> https://oph.mdrjr.net/meveric/images/Bu ... -C4.img.xz
and simply did a "apt-get update", "apt-get upgrade" and "setup-odroid" (i.e. I did not change much).

I found out that uart1, uart2, uart3 are not getting ready after booting. They are in the overlays in my boot.ini.
In fact they are only getting ready after 30 seconds, i.e. 10 seconds after booting to GUI/auto-login of one graphical user.

That's not quite what I want because I need the serial lines /dev/ttyS1,2,3 be ready as soon as possible. I guess there is a bug in the overlays.

Any suggestions of what to do ... ?

[odroid]

Do you have a serial console access?
If yes, the raw booting log from the serial console output will be helpful to know when the UART ports are activated.

BTW, is that the UART slow readiness issue existing in HK's Ubuntu 20.04 image too?

[att2]

Yes, the same slow readiness issue is across all kernels 4.9.x, all kernels 5.x, and ofcourse in Ubuntu 20.04 too.
Edit: is a "dmesg --human" boot log not enough ?

[att2]

Raw serial console output from u-boot stage to kernel logs might give you more detail information to know when the Device-tree overlays are loaded and enabled.

[att2]

Hello,
Here is the serial boot log. I also can confirm another serial kernel issue - the kernel is not enabling the serial lines THE FIRST BOOT. Every second, third reboot, it works properly :

Here is case one: After 5 seconds the ttyS0 speed is switched to something incorrect : https://pastebin.com/7Cx4gztJ

Here is case two: After typing reboot - all ttyS0 logs are fine : https://pastebin.com/fm6fwYJS

So the first time booting, most problems appear. Obviously something is wrong in some kind of register init near the UARTS. Can you fix it please ?

Also, please take note that in case 1:

(I am not giving up and trying to change serial settings in putty:)
(I change it to 115200, 8 data bits, 0 stop bits, parity:none, flowcontrol:none)

test

reseodijpv$[ 512.663585@0] meson_uart ff803000^ 512.666739@0] meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 115200 to 115200
[ 512.934138@3] meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 115200 to 115200

after 512 seconds, the ttyS0 is getting the right speed ? Is this some sort of timeout-bug ? Please clarify.

[mctom]

Here is case one: After 5 seconds the ttyS0 speed is switched to something incorrect : https://pastebin.com/7Cx4gztJ

The ttyS0 settings appear correct, you're getting characters typical for dmesg (for example, uh, letters). If you changed baudrate to something else, you'd get a much worse mess. What you're getting looks like caused by a buffer overflow, on whichever end of a link.
Which begs the question - what serial to USB converter are you using? Do you read data in raw mode, or canonical?
Changing to raw may help significantly with this kind of errors.

If you take console output from around 4.43s mark to 5.53s mark, that's 193 lines taking 10788 bytes. The transmission speed is 115200bps. Each byte in 8n1 setting is worth 10 bits. So it's getting really close to the link cap, even ignoring the fact these are not sent in a steady stream.

(By the way, the "default" setting is 1 stop bit, not 0, but theoretically the receiver could still work and just ignore stop bits)

Here is case two: After typing reboot - all ttyS0 logs are fine : https://pastebin.com/fm6fwYJS

Are they?

Code: Select all

[    5.6\    5.653964@0] meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 115200 to 115200

Code: Select all

Begin: Running /scripts/init-premount ... [    6.011929@0] meson_uart ff803000.serial: ttyS0 use xtal(24M) 24000000 change 115200 to 115200
done.

So indeed there is something weird going on every time it does report changing baudrates from 115k2 to 115k2 AND sending more data at the same time (pretty much inevitable during boot)...
Probably the hardware part of meson_uart stops working for a while to update its settings and output buffer gets corrupted.

And with a corrupted buffer, it's just one step away from missing a few line breaks and filling the output buffer and corrupting it even more.
My guess is that's a freak accident it happens on the first boot - it changes ttyS0 settings at the point when a lot of data is being transferred.
I agree ttyS0 settings shouldn't be changed multiple times during the boot, and I can't explain why that happens.

but anyway, what you could try is to read data in raw mode on the first boot and see if that's acceptable.

[att2]

Hi McTom,
Thanks for the super-fast help, much appreciated!
To clarify some points, I am using the "USB - UART Module Kit for Odroid" , by Hardkernel themselves, part number G134111883934. The device driver used is a Silicon Labs CP210x USB to UART Bridge, which seems to work fine.
I'm using putty on Windows7/64 bit to receive the data from the Odroid C4; I have no option "raw" or "canonical" there....

[att2]

Oh noez... I found out something. It seems that "chmod 777 /dev/ttyS*" in /etc/rc.local is nice, but somehow the rc.local event is delayed somehow, and that explains why there is no permission to read or write the device file for the first 30 seconds. Is systemd so slow.... ? (No idea!)
So I added user odroid to the dialout group with "usermod -a -G dialout odroid" and then the serial line was immidately ready. ...... *oh, shit*

However, the serial log is still a bit strange shall I say.

[mctom]

Oh, right, rc.local is not the best idea for time critical stuff.

At this point this is not entirely clear which side of serial link is to blame. I suggest you try and read that serial data on a Linux machine (might be another SBC, why not)
To change ttySx settings (on the receiver side), try this:

Code: Select all

sudo stty -F /dev/ttySxxx raw
sudo stty -F /dev/ttySxxx -icanon
sudo stty -F /dev/ttySxxx 115200

And read with:
cat /dev/ttySxxx

I'm not sure if all these parameters would work if given all at the same time, so just to make sure I separated them.