[U-Boot] qemu and u-boot-console and other ports?

[U-Boot] qemu and u-boot-console and other ports?

[Tom Rini]

Hey,

I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
current round of testing is applied you'll need
http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
for us to get a functional U-Boot.  After that, I have a "normal" conf
file for the board for QEMU that looks like:
console_impl=qemu
qemu_machine="r2d"
qemu_binary="qemu-system-sh4"
qemu_extra_args="-nographic -serial null -serial mon:stdio"
qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
reset_impl=none
flash_impl=none

And here's where things get funny.  When I kick off test.py with --bd
r2dplus --id qemu --build -s -k sleep it will build and launch the board
and since I have -s I can see stdio and I see U-Boot come up and give me
the prompt, and then test.py says it times out waiting for the prompt.
Any ideas where to poke next?  I want to say something is funny with
respect to what we see and where we see it (in terms of pipes) due to
having to say -serial null -serial mon:stdio so that we see port #2 on
the "board" rather than port #1 as this is the port that U-Boot and
Linux use by default.  Thanks!

-- 
Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20161202/6e5db49f/attachment.sig>

[U-Boot] qemu and u-boot-console and other ports?

[Stephen Warren]

On 12/02/2016 07:40 AM, Tom Rini wrote:
> Hey,
>
> I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
> current round of testing is applied you'll need
> http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
> for us to get a functional U-Boot.  After that, I have a "normal" conf
> file for the board for QEMU that looks like:
> console_impl=qemu
> qemu_machine="r2d"
> qemu_binary="qemu-system-sh4"
> qemu_extra_args="-nographic -serial null -serial mon:stdio"
> qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
> reset_impl=none
> flash_impl=none
>
> And here's where things get funny.  When I kick off test.py with --bd
> r2dplus --id qemu --build -s -k sleep it will build and launch the board
> and since I have -s I can see stdio and I see U-Boot come up and give me
> the prompt, and then test.py says it times out waiting for the prompt.
> Any ideas where to poke next?  I want to say something is funny with
> respect to what we see and where we see it (in terms of pipes) due to
> having to say -serial null -serial mon:stdio so that we see port #2 on
> the "board" rather than port #1 as this is the port that U-Boot and
> Linux use by default.  Thanks!

Does "-serial null -serial mon:stdio" cause qemu to re-open file 
descriptors rather than just using stdout directly, or something like 
that? If so, perhaps its output is getting into the overall script's 
stdout (e.g. your terminal/console?) rather than the pipe that test/py 
is reading. If so, you'd see the qemu output but test/py wouldn't.

I think you can test this assumption by removing the -s option. If you 
still see qemu output, then qemu is sending it directly to wherever the 
overall stdout is going. If you no longer see qemu's output, then 
test/py must be reading it and only echo'ing it due to the -s option, 
and so you'd have to look somewhere else.

Is test/py waiting for the exact prompt that U-Boot is actually emitting?

In the past I've debugged such things by editing test/py/u_boot_spawn.py 
expect() to print some debug spew; I made it dump the current unmatched 
buffer content and the strings/regexes it was waiting for.

[U-Boot] qemu and u-boot-console and other ports?

[Tom Rini]

On Fri, Dec 02, 2016 at 11:03:00AM -0700, Stephen Warren wrote:
> On 12/02/2016 07:40 AM, Tom Rini wrote:
> >Hey,
> >
> >I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
> >current round of testing is applied you'll need
> >http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
> >for us to get a functional U-Boot.  After that, I have a "normal" conf
> >file for the board for QEMU that looks like:
> >console_impl=qemu
> >qemu_machine="r2d"
> >qemu_binary="qemu-system-sh4"
> >qemu_extra_args="-nographic -serial null -serial mon:stdio"
> >qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
> >reset_impl=none
> >flash_impl=none
> >
> >And here's where things get funny.  When I kick off test.py with --bd
> >r2dplus --id qemu --build -s -k sleep it will build and launch the board
> >and since I have -s I can see stdio and I see U-Boot come up and give me
> >the prompt, and then test.py says it times out waiting for the prompt.
> >Any ideas where to poke next?  I want to say something is funny with
> >respect to what we see and where we see it (in terms of pipes) due to
> >having to say -serial null -serial mon:stdio so that we see port #2 on
> >the "board" rather than port #1 as this is the port that U-Boot and
> >Linux use by default.  Thanks!
> 
> Does "-serial null -serial mon:stdio" cause qemu to re-open file
> descriptors rather than just using stdout directly, or something
> like that? If so, perhaps its output is getting into the overall
> script's stdout (e.g. your terminal/console?) rather than the pipe
> that test/py is reading. If so, you'd see the qemu output but
> test/py wouldn't.
> 
> I think you can test this assumption by removing the -s option. If
> you still see qemu output, then qemu is sending it directly to
> wherever the overall stdout is going. If you no longer see qemu's
> output, then test/py must be reading it and only echo'ing it due to
> the -s option, and so you'd have to look somewhere else.

When I drop out -s instead I get:
----------------------------------- Captured stdout ------------------------------------
+u-boot-test-reset r2dplus qemu
long write to SH7750_WCR1_A7 (0x000000001f800008) ignored
long write to SH7750_WCR2_A7 (0x000000001f80000c) ignored
long write to SH7750_WCR3_A7 (0x000000001f800010) ignored
long write to SH7750_MCR_A7 (0x000000001f800014) ignored
word write to SH7750_RTCNT_A7 (0x000000001f800020) ignored
word write to SH7750_RTCOR_A7 (0x000000001f800024) ignored
Write access to refresh count register
word write to SH7750_RTCSR_A7 (0x000000001f80001c) ignored
Read access to refresh count register, incrementing
long write to SH7750_MCR_A7 (0x000000001f800014) ignored


U-Boot 2016.11-00492-ged6a1e9bbf0c (Dec 02 2016 - 14:14:17 -0500)

CPU: SH4
BOARD: Renesas Solutions R2D Plus
DRAM:  64 MiB
Flash: ERROR: too many flash sectors
8 MiB
*** Warning - bad CRC, using default environment

PCI: SH7751 PCI host bridge found.
long read to SH7750_WCR1_A7 (0x000000001f800008) ignored
long read to SH7750_WCR2_A7 (0x000000001f80000c) ignored
long read to SH7750_WCR3_A7 (0x000000001f800010) ignored
long read to SH7750_MCR_A7 (0x000000001f800014) ignored
PCI:   Bus Dev VenId DevId Class Int
PCI:
  00:00.0     - 1054:350e - Bridge device
  00:02.0     - 10ec:8139 - Network controller
In:    serial
Out:   serial
Err:   serial
Net:   RTL8139#0
Error: RTL8139#0 address not set.

IDE:   Bus 0: not available
=> => s
=========================== 92 tests deselected by '-ksleep' ===========================
======================= 1 failed, 92 deselected in 31.20 seconds =======================

So it's seeing output, but for some reason not matching on it?

-- 
Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20161202/4b26c2f8/attachment.sig>

[U-Boot] qemu and u-boot-console and other ports?

[Stephen Warren]

On 12/02/2016 12:18 PM, Tom Rini wrote:
> On Fri, Dec 02, 2016 at 11:03:00AM -0700, Stephen Warren wrote:
>> On 12/02/2016 07:40 AM, Tom Rini wrote:
>>> Hey,
>>>
>>> I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
>>> current round of testing is applied you'll need
>>> http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
>>> for us to get a functional U-Boot.  After that, I have a "normal" conf
>>> file for the board for QEMU that looks like:
>>> console_impl=qemu
>>> qemu_machine="r2d"
>>> qemu_binary="qemu-system-sh4"
>>> qemu_extra_args="-nographic -serial null -serial mon:stdio"
>>> qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
>>> reset_impl=none
>>> flash_impl=none
>>>
>>> And here's where things get funny.  When I kick off test.py with --bd
>>> r2dplus --id qemu --build -s -k sleep it will build and launch the board
>>> and since I have -s I can see stdio and I see U-Boot come up and give me
>>> the prompt, and then test.py says it times out waiting for the prompt.
>>> Any ideas where to poke next?  I want to say something is funny with
>>> respect to what we see and where we see it (in terms of pipes) due to
>>> having to say -serial null -serial mon:stdio so that we see port #2 on
>>> the "board" rather than port #1 as this is the port that U-Boot and
>>> Linux use by default.  Thanks!
>>
>> Does "-serial null -serial mon:stdio" cause qemu to re-open file
>> descriptors rather than just using stdout directly, or something
>> like that? If so, perhaps its output is getting into the overall
>> script's stdout (e.g. your terminal/console?) rather than the pipe
>> that test/py is reading. If so, you'd see the qemu output but
>> test/py wouldn't.
>>
>> I think you can test this assumption by removing the -s option. If
>> you still see qemu output, then qemu is sending it directly to
>> wherever the overall stdout is going. If you no longer see qemu's
>> output, then test/py must be reading it and only echo'ing it due to
>> the -s option, and so you'd have to look somewhere else.
>
> When I drop out -s instead I get:
> ----------------------------------- Captured stdout ------------------------------------
> +u-boot-test-reset r2dplus qemu
> long write to SH7750_WCR1_A7 (0x000000001f800008) ignored
> long write to SH7750_WCR2_A7 (0x000000001f80000c) ignored
> long write to SH7750_WCR3_A7 (0x000000001f800010) ignored
> long write to SH7750_MCR_A7 (0x000000001f800014) ignored
> word write to SH7750_RTCNT_A7 (0x000000001f800020) ignored
> word write to SH7750_RTCOR_A7 (0x000000001f800024) ignored
> Write access to refresh count register
> word write to SH7750_RTCSR_A7 (0x000000001f80001c) ignored
> Read access to refresh count register, incrementing
> long write to SH7750_MCR_A7 (0x000000001f800014) ignored
>
>
> U-Boot 2016.11-00492-ged6a1e9bbf0c (Dec 02 2016 - 14:14:17 -0500)
>
> CPU: SH4
> BOARD: Renesas Solutions R2D Plus
> DRAM:  64 MiB
> Flash: ERROR: too many flash sectors
> 8 MiB
> *** Warning - bad CRC, using default environment
>
> PCI: SH7751 PCI host bridge found.
> long read to SH7750_WCR1_A7 (0x000000001f800008) ignored
> long read to SH7750_WCR2_A7 (0x000000001f80000c) ignored
> long read to SH7750_WCR3_A7 (0x000000001f800010) ignored
> long read to SH7750_MCR_A7 (0x000000001f800014) ignored
> PCI:   Bus Dev VenId DevId Class Int
> PCI:
>   00:00.0     - 1054:350e - Bridge device
>   00:02.0     - 10ec:8139 - Network controller
> In:    serial
> Out:   serial
> Err:   serial
> Net:   RTL8139#0
> Error: RTL8139#0 address not set.
>
> IDE:   Bus 0: not available
> => => s
> =========================== 92 tests deselected by '-ksleep' ===========================
> ======================= 1 failed, 92 deselected in 31.20 seconds =======================
>
> So it's seeing output, but for some reason not matching on it?

If you drop -s, you shouldn't see any of U-Boot's output. It looks like 
qemu is writing its serial port output to a file descriptor other than 
the stdout that's fed to its parent.

Oh, you can also confirm this by looking in the test-log.html generated 
by test/py; that will show you whether test/py sees qemu's output at 
all, since all of qemu's output is logged to that file. I guess this 
assumes you're running locally, since Travis doesn't save that file for 
you to look at. Perhaps you could cat it after running test/py though.

[U-Boot] qemu and u-boot-console and other ports?

[Tom Rini]

On Fri, Dec 02, 2016 at 12:21:43PM -0700, Stephen Warren wrote:
> On 12/02/2016 12:18 PM, Tom Rini wrote:
> >On Fri, Dec 02, 2016 at 11:03:00AM -0700, Stephen Warren wrote:
> >>On 12/02/2016 07:40 AM, Tom Rini wrote:
> >>>Hey,
> >>>
> >>>I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
> >>>current round of testing is applied you'll need
> >>>http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
> >>>for us to get a functional U-Boot.  After that, I have a "normal" conf
> >>>file for the board for QEMU that looks like:
> >>>console_impl=qemu
> >>>qemu_machine="r2d"
> >>>qemu_binary="qemu-system-sh4"
> >>>qemu_extra_args="-nographic -serial null -serial mon:stdio"
> >>>qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
> >>>reset_impl=none
> >>>flash_impl=none
> >>>
> >>>And here's where things get funny.  When I kick off test.py with --bd
> >>>r2dplus --id qemu --build -s -k sleep it will build and launch the board
> >>>and since I have -s I can see stdio and I see U-Boot come up and give me
> >>>the prompt, and then test.py says it times out waiting for the prompt.
> >>>Any ideas where to poke next?  I want to say something is funny with
> >>>respect to what we see and where we see it (in terms of pipes) due to
> >>>having to say -serial null -serial mon:stdio so that we see port #2 on
> >>>the "board" rather than port #1 as this is the port that U-Boot and
> >>>Linux use by default.  Thanks!
> >>
> >>Does "-serial null -serial mon:stdio" cause qemu to re-open file
> >>descriptors rather than just using stdout directly, or something
> >>like that? If so, perhaps its output is getting into the overall
> >>script's stdout (e.g. your terminal/console?) rather than the pipe
> >>that test/py is reading. If so, you'd see the qemu output but
> >>test/py wouldn't.
> >>
> >>I think you can test this assumption by removing the -s option. If
> >>you still see qemu output, then qemu is sending it directly to
> >>wherever the overall stdout is going. If you no longer see qemu's
> >>output, then test/py must be reading it and only echo'ing it due to
> >>the -s option, and so you'd have to look somewhere else.
> >
> >When I drop out -s instead I get:
> >----------------------------------- Captured stdout ------------------------------------
> >+u-boot-test-reset r2dplus qemu
> >long write to SH7750_WCR1_A7 (0x000000001f800008) ignored
> >long write to SH7750_WCR2_A7 (0x000000001f80000c) ignored
> >long write to SH7750_WCR3_A7 (0x000000001f800010) ignored
> >long write to SH7750_MCR_A7 (0x000000001f800014) ignored
> >word write to SH7750_RTCNT_A7 (0x000000001f800020) ignored
> >word write to SH7750_RTCOR_A7 (0x000000001f800024) ignored
> >Write access to refresh count register
> >word write to SH7750_RTCSR_A7 (0x000000001f80001c) ignored
> >Read access to refresh count register, incrementing
> >long write to SH7750_MCR_A7 (0x000000001f800014) ignored
> >
> >
> >U-Boot 2016.11-00492-ged6a1e9bbf0c (Dec 02 2016 - 14:14:17 -0500)
> >
> >CPU: SH4
> >BOARD: Renesas Solutions R2D Plus
> >DRAM:  64 MiB
> >Flash: ERROR: too many flash sectors
> >8 MiB
> >*** Warning - bad CRC, using default environment
> >
> >PCI: SH7751 PCI host bridge found.
> >long read to SH7750_WCR1_A7 (0x000000001f800008) ignored
> >long read to SH7750_WCR2_A7 (0x000000001f80000c) ignored
> >long read to SH7750_WCR3_A7 (0x000000001f800010) ignored
> >long read to SH7750_MCR_A7 (0x000000001f800014) ignored
> >PCI:   Bus Dev VenId DevId Class Int
> >PCI:
> >  00:00.0     - 1054:350e - Bridge device
> >  00:02.0     - 10ec:8139 - Network controller
> >In:    serial
> >Out:   serial
> >Err:   serial
> >Net:   RTL8139#0
> >Error: RTL8139#0 address not set.
> >
> >IDE:   Bus 0: not available
> >=> => s
> >=========================== 92 tests deselected by '-ksleep' ===========================
> >======================= 1 failed, 92 deselected in 31.20 seconds =======================
> >
> >So it's seeing output, but for some reason not matching on it?
> 
> If you drop -s, you shouldn't see any of U-Boot's output. It looks
> like qemu is writing its serial port output to a file descriptor
> other than the stdout that's fed to its parent.

Well, it doesn't give me output until it times out and then dumps that.

> Oh, you can also confirm this by looking in the test-log.html
> generated by test/py; that will show you whether test/py sees qemu's
> output at all, since all of qemu's output is logged to that file. I
> guess this assumes you're running locally, since Travis doesn't save
> that file for you to look at. Perhaps you could cat it after running
> test/py though.

I'm not quite sure what I should (not) be seeing,
http://hastebin.com/upimerumaz.xml is the file.  Thanks!

-- 
Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20161202/a7d515e0/attachment.sig>

[U-Boot] qemu and u-boot-console and other ports?

[Stephen Warren]

On 12/02/2016 01:01 PM, Tom Rini wrote:
> On Fri, Dec 02, 2016 at 12:21:43PM -0700, Stephen Warren wrote:
>> On 12/02/2016 12:18 PM, Tom Rini wrote:
>>> On Fri, Dec 02, 2016 at 11:03:00AM -0700, Stephen Warren wrote:
>>>> On 12/02/2016 07:40 AM, Tom Rini wrote:
>>>>> Hey,
>>>>>
>>>>> I'm trying to debug adding sh4 and r2dplus support to test.py.  Until my
>>>>> current round of testing is applied you'll need
>>>>> http://patchwork.ozlabs.org/bundle/trini/fix-sh4-support-v2/ in order
>>>>> for us to get a functional U-Boot.  After that, I have a "normal" conf
>>>>> file for the board for QEMU that looks like:
>>>>> console_impl=qemu
>>>>> qemu_machine="r2d"
>>>>> qemu_binary="qemu-system-sh4"
>>>>> qemu_extra_args="-nographic -serial null -serial mon:stdio"
>>>>> qemu_kernel_args="-kernel ${U_BOOT_BUILD_DIR}/u-boot.bin"
>>>>> reset_impl=none
>>>>> flash_impl=none
>>>>>
>>>>> And here's where things get funny.  When I kick off test.py with --bd
>>>>> r2dplus --id qemu --build -s -k sleep it will build and launch the board
>>>>> and since I have -s I can see stdio and I see U-Boot come up and give me
>>>>> the prompt, and then test.py says it times out waiting for the prompt.
>>>>> Any ideas where to poke next?  I want to say something is funny with
>>>>> respect to what we see and where we see it (in terms of pipes) due to
>>>>> having to say -serial null -serial mon:stdio so that we see port #2 on
>>>>> the "board" rather than port #1 as this is the port that U-Boot and
>>>>> Linux use by default.  Thanks!
>>>>
>>>> Does "-serial null -serial mon:stdio" cause qemu to re-open file
>>>> descriptors rather than just using stdout directly, or something
>>>> like that? If so, perhaps its output is getting into the overall
>>>> script's stdout (e.g. your terminal/console?) rather than the pipe
>>>> that test/py is reading. If so, you'd see the qemu output but
>>>> test/py wouldn't.
>>>>
>>>> I think you can test this assumption by removing the -s option. If
>>>> you still see qemu output, then qemu is sending it directly to
>>>> wherever the overall stdout is going. If you no longer see qemu's
>>>> output, then test/py must be reading it and only echo'ing it due to
>>>> the -s option, and so you'd have to look somewhere else.
>>>
>>> When I drop out -s instead I get:
>>> ----------------------------------- Captured stdout ------------------------------------
>>> +u-boot-test-reset r2dplus qemu
>>> long write to SH7750_WCR1_A7 (0x000000001f800008) ignored
>>> long write to SH7750_WCR2_A7 (0x000000001f80000c) ignored
>>> long write to SH7750_WCR3_A7 (0x000000001f800010) ignored
>>> long write to SH7750_MCR_A7 (0x000000001f800014) ignored
>>> word write to SH7750_RTCNT_A7 (0x000000001f800020) ignored
>>> word write to SH7750_RTCOR_A7 (0x000000001f800024) ignored
>>> Write access to refresh count register
>>> word write to SH7750_RTCSR_A7 (0x000000001f80001c) ignored
>>> Read access to refresh count register, incrementing
>>> long write to SH7750_MCR_A7 (0x000000001f800014) ignored
>>>
>>>
>>> U-Boot 2016.11-00492-ged6a1e9bbf0c (Dec 02 2016 - 14:14:17 -0500)
>>>
>>> CPU: SH4
>>> BOARD: Renesas Solutions R2D Plus
>>> DRAM:  64 MiB
>>> Flash: ERROR: too many flash sectors
>>> 8 MiB
>>> *** Warning - bad CRC, using default environment
>>>
>>> PCI: SH7751 PCI host bridge found.
>>> long read to SH7750_WCR1_A7 (0x000000001f800008) ignored
>>> long read to SH7750_WCR2_A7 (0x000000001f80000c) ignored
>>> long read to SH7750_WCR3_A7 (0x000000001f800010) ignored
>>> long read to SH7750_MCR_A7 (0x000000001f800014) ignored
>>> PCI:   Bus Dev VenId DevId Class Int
>>> PCI:
>>>  00:00.0     - 1054:350e - Bridge device
>>>  00:02.0     - 10ec:8139 - Network controller
>>> In:    serial
>>> Out:   serial
>>> Err:   serial
>>> Net:   RTL8139#0
>>> Error: RTL8139#0 address not set.
>>>
>>> IDE:   Bus 0: not available
>>> => => s
>>> =========================== 92 tests deselected by '-ksleep' ===========================
>>> ======================= 1 failed, 92 deselected in 31.20 seconds =======================
>>>
>>> So it's seeing output, but for some reason not matching on it?
>>
>> If you drop -s, you shouldn't see any of U-Boot's output. It looks
>> like qemu is writing its serial port output to a file descriptor
>> other than the stdout that's fed to its parent.
>
> Well, it doesn't give me output until it times out and then dumps that.
>
>> Oh, you can also confirm this by looking in the test-log.html
>> generated by test/py; that will show you whether test/py sees qemu's
>> output at all, since all of qemu's output is logged to that file. I
>> guess this assumes you're running locally, since Travis doesn't save
>> that file for you to look at. Perhaps you could cat it after running
>> test/py though.
>
> I'm not quite sure what I should (not) be seeing,
> http://hastebin.com/upimerumaz.xml is the file.  Thanks!

The qemu output is getting into test/py; I see the U-Boot boot output 
all the way up to the first shell prompt.

It looks like some test is attempting to execute a "sleep" command. The 
code sends the command text to the target in chunks and waits for it to 
echo back. The chunk size is 16 characters so I believe would included 
the entire command and trailing \n in this cae. I can see that qemu has 
only echo'd back the first character "s", so I think U-Boot hung and 
stopped responding, or there's some issue getting the command string 
into/out-of qemu?