Re: [OE-core] [PATCH 5/5] qemurunner: Show both the login console log and all logging upon failure

[Mikko Rapeli <mikko.rapeli@linaro.org>]

Hi,

On Thu, Oct 05, 2023 at 04:47:16PM +0100, Richard Purdie wrote:
> On Thu, 2023-10-05 at 18:27 +0300, Mikko Rapeli wrote:
> > Hi,
> > 
> > On Wed, Oct 04, 2023 at 09:35:20PM +0100, Richard Purdie wrote:
> > > On Wed, 2023-10-04 at 22:34 +0300, Mikko Rapeli wrote:
> > > > Hi,
> > > > 
> > > > On Wed, Oct 04, 2023 at 02:29:40PM +0100, Richard Purdie wrote:
> > > > > On Wed, 2023-10-04 at 16:07 +0300, Mikko Rapeli wrote:
> > > > > > Hi,
> > > > > > 
> > > > > > Acked-by: Mikko Rapeli <mikko.rapeli@linaro.org>
> > > > > > 
> > > > > > for the full series. I hope our discussion over #yocto irc channel
> > > > > > helped resolve these and the test failures seen with master-next.
> > > > > 
> > > > > Yes, thanks! It was useful to have someone to talk the issues through
> > > > > with and much appreciated.
> > > > > 
> > > > > Sadly I don't think we've found all the issues yet.
> > > > > 
> > > > > On the build N-1 we have a selftest failure on debian12-ty-1:
> > > > > 
> > > > > https://autobuilder.yoctoproject.org/typhoon/#/builders/80/builds/5803/steps/14/logs/stdio
> > > > 
> > > > Can I get from this test run stdio to the more detailed task, qemurunner or qemu boot logs somehow?
> > > > Or do you have to dig into the system manually to capture them, like in the example below?
> > > > 
> > > > I would like to check into the detailed logs from both passing and failing test runs.
> > > > Of course kernel dmesg would need to be there so maybe after your patch to the runqemu
> > > > side at least.
> > > > 
> > > > If there is a regression in kernel to the serial device detection and numbering,
> > > > then we need some way to see e.g. 8250 uart/tty0/ttyAMA0 related dmesg messages.
> > > 
> > > I can't capture everything in time in each case but I did grab:
> > > 
> > > https://autobuilder.yocto.io/pub/failed-builds-data/6.5%20kernel/e/
> > > 
> > > which is from
> > > 
> > > https://autobuilder.yoctoproject.org/typhoon/#/builders/76/builds/7863/steps/21/logs/stdio
> > > 
> > > which has this threads patches applied.
> > > 
> > > I've put two sets of logs there from the same builds, one success, one
> > > is missing the getty on one log.
> > > 
> > > 
> > > I also have the logs from:
> > > 
> > > https://autobuilder.yoctoproject.org/typhoon/#/builders/86/builds/5848/steps/14/logs/stdio
> > > 
> > > which I've saved here:
> > > 
> > > https://autobuilder.yocto.io/pub/failed-builds-data/6.5%20kernel/f/
> > > 
> > > noting that:�
> > > 
> > > https://autobuilder.yocto.io/pub/failed-builds-data/6.5%20kernel/f/qemu_boot_log.20231004134427
> > > 
> > > is 3 bytes in size.
> > 
> > All this is very confusing indeed. I sent another version of the detect login prompt without
> > utf-8 conversion, with some luck that could help. At least on some of the logs the login prompt
> > is there but with lots of garbage around it. Serial port core got refactored in 6.5 and diff to
> > 6.4 is quite large so there could be bugs there, and those could be triggering new
> > errors visible to userspace too.
> 
> With the changes I've made to the logging and the raw log files we have
> without any utf-8 conversion, I'm now 99% certain this isn't any utf
> conversion issue since the login prompts are not in the raw binary
> files and those are written with no conversion. It is much more likely
> the getty isn't running or isn't communicating somehow.
> 
> I'm trying to work out how to add some further debug/testing when this
> fails in a way it will help us debug.

Alright, I was confused by logs from working login detection. I presume
qemu is configured with two serial ports to avoid mixing kernel messages with
the login prompt. It would be easy to grep for the login prompt also from the first
serial output though it would not explain the root cause for these issues
but could allow testing to move forward to the ssh connection. In all of the logs
I saw, the first serial port had a login prompt.

The serial ports are not used in testing, AFAIK. Oh now there are the debug
commands in master-next. Nice, I was hoping for this kind of data in logs when
things go horribly wrong.

Cheers,

-Mikko