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

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!

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.

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?

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.

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!

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?
participants (2)
-
Stephen Warren
-
Tom Rini