Re: [OE-core] [PATCH 2/2] qemurunner: Impove handling of serial port output blocking

["Alex Bennée" <alex.bennee@linaro.org>]

Richard Purdie <richard.purdie@linuxfoundation.org> writes:

> On Tue, 2023-12-19 at 15:10 +0000, Alex Bennée wrote:
>> "Richard Purdie" <richard.purdie@linuxfoundation.org> writes:
>> 
>> > Similar to stdout in the previous commit, we need to ensure serial output
>> > if written is read and put somewhere, else qemu might block on writes to
>> > the serial port leading to hangs in the kernel. Use our existing logging
>> > thread to log data when run_serial is not in use.
>> > 
>> > Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
>> 
>> I'm still seeing hanging with my test case:
>> 
>>   o regression_1010.5 Invalid memory access 5
>>     regression_1010.5 OK
>>   o regression_1010.6 Invalid memory access 6
>> 
>>   Stdout:
>>   Tried to dump info from target but serial console failed
>>   Failed CMD: top -bn1
>>   Tried to dump info from target but serial console failed
>>   Failed CMD: ps
>>   Tried to dump info from target but serial console failed
>>   Failed CMD: free
>> 
>>   NOTE: test_soafee (soafeetestsuite.SoafeeTestSuite.test_soafee)
>>   DEBUG: Checking if at least one of soafee-test-suite is installed
>>   DEBUG: Setting up a 400 second(s) timeout
>>   DEBUG: [Running]$ ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR -p 2222 127.0.0.1 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; sudo -i -u trs soafee-test-suite run -r -t -T ; rm -rf /tmp/soafee-test-suite
>>   DEBUG: Waiting for process output: time: 1702998407.0291, endtime: 1702998707.0285847
>>   DEBUG: Waiting for process output: time: 1702998412.0338314, endtime: 1702998707.0285847
>>   DEBUG: Waiting for process output: time: 1702998417.0378022, endtime: 1702998707.0285847
>>   DEBUG: Waiting for process output: time: 1702998422.0417945, endtime: 1702998707.0285847
>>   <snip>
>> 
>> The regression tests are hanging because that has triggered output on
>> the serial port as the firmware attempted to service the test and the
>> port isn't being drained. Then when that times out we start spinning
>> waiting for more output.
>
> I don't really understand where it might be hanging unfortunately as in
> my local tests it is draining stdout and the serial ports. Does it
> login to the serial console correctly? Are there any WARNING messages?
>
> I did use this debug patch:
>
> https://git.yoctoproject.org/poky-contrib/commit/?h=rpurdie/t222&id=0d9029bad610736c114e0770d2433b53133fa620
>
> to prove that it can interleave serial commands with left over output
> successfully. A similar patch may help work out where your setup may be
> hanging?

Yeah I'm only seeing A10/A11:

  o regression_1010.5 Invalid memory access 5
    regression_1010.5 OK
  o regression_1010.6 Invalid memory access 6

  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  NOTE:  ... FAIL
  DEBUG: Removed SIGALRM handler
  Traceback (most recent call last):
    File "/home/alex/lsrc/tests/trs/build/../poky/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
      return func(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^
    File "/home/alex/lsrc/tests/trs/build/../poky/meta/lib/oeqa/core/decorator/__init__.py", line 35, in wrapped_f
      return func(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^
    File "/home/alex/lsrc/tests/trs/meta-trs/lib/oeqa/runtime/cases/opteetest.py", line 27, in test_opteetest_xtest
      self.assertEqual(status, 0, msg='\n'.join([cmd, output]))
  AssertionError: 255 != 0 :  xtest               
  Run test suite with level=0

Those are the only two bits hit in the logging:

  grep "WARNING: here" build/tmp_trs-qemuarm64/work/trs_qemuarm64-trs-linux/trs-image/1.0/temp/log.do_testimage
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11
  WARNING: here A10
  WARNING: here A11

>
> Cheers,
>
> Richard 

-- 
Alex Bennée
Virtualisation Tech Lead @ Linaro