[U-Boot] test.py and tftp crc32 test?

[Heiko Schocher <hs@denx.de>]

Hello Stephen,

Am 16.08.2016 um 05:35 schrieb Stephen Warren:
> On 08/15/2016 05:20 PM, Tom Rini wrote:
>> On Mon, Aug 15, 2016 at 04:59:02PM -0600, Stephen Warren wrote:
>>> On 08/15/2016 04:49 PM, Tom Rini wrote:
>>>> Hey guys,
>>>>
>>>> Is anyone else running the crc32 tftp tests with test.py?  I'm trying to
>>>> do it locally but even with a 2MiB file it looks like somehow the crc32
>>>> is never captured in the output.  I've already made sure that the crc32
>>>> value is in lowercase to match the U-Boot output and running the test
>>>> steps in console gives me the expected output.  And the rest of the
>>>> network tests pass, any ideas?  Thanks!
>>>
>>> I'm not certain that anyone other than myself is running test.py on
>>> real HW (vs. sandbox where it's trivial).
>>>
>>> If you look at test-log.html it should show what U-Boot outputs on
>>> the console, and where any error was detected in the test.
>>> Alternativeluy, add "-s" to the invocation and U-Boot output should
>>> show up on stdout while the tests are running. What's the error
>>> reported there; just a timeout waiting for the CRC? Here's an
>>> example of what test_net_tftpboot looks like for me:
>>>
>>>> Tegra210 (P2371-2180) # tftpboot 80000000 ubtest-readable.bin
>>>> Using eth_rtl8169 device
>>>> TFTP from server 10.20.204.51; our IP address is 10.20.204.52
>>>> Filename 'ubtest-readable.bin'.
>>>> Load address: 0x80000000
>>>> Loading: *%08#################################################################
>>>>      #################################################################
>>>>      #################################################################
>>>>      #################################################################
>>>>      #################################################################
>>>>      ####################
>>>>      2.9 MiB/s
>>>> done
>>>> Bytes transferred = 5058624 (4d3040 hex)
>>>> Tegra210 (P2371-2180) # crc32 80000000 $filesize
>>>> crc32 for 80000000 ... 804d303f ==> c2244b26
>>>> Tegra210 (P2371-2180) #
>>>
>>> In the past, I have seen tests pass when run manually but not under
>>> test.py, e.g. due to heap fragmentation, state, or corrupted memory
>>> due to earlier tests, which weren't run in the manual case. Might
>>> that be the issue?
>>
>> Adding in -s this is part of what I see:
>>
>> => .s=> ping $serverip
>> Waiting for Ethernet connection... done.
>> Using sms0 device
>> host 192.168.0.3 is alive
>> => .=> tftpboot 80000000 1MiBtest.bin
>> Waiting for Ethernet connection... done.
>> Using sms0 device
>> TFTP from server 192.168.0.3; our IP address is 192.168.0.140
>> Filename '1MiBtest.bin'.
>> Load address: 0x80000000
>> Loading: #################################################################
>>          #################################################################
>>          #################################################################
>>          ##########
>>          171.9 KiB/s
>> done
>> Bytes transferred = 1048576 (100000 hex)
>> => crc32 80000000 $filesize
>> CRC32 for 80000000 ... 800fffff ==> F2fa737e0
>> =>
>>
>> For some reason there's an extra 'F' at the start of the crc32 output.
>> Looking at it in the html file, it looks all correct there.  In the
>> output from test.py the captured stdout end just before the CRC32 value
>> would be.  I've tried larger test binaries and get the same output so
>> I'd assume if there was some heap corruption or similar, I'd not tickle
>> it with bigger files too (2MiB, 4MiB and I think even 8MiB are small
>> enough to be downloaded in the time the test allows).  Thanks!
>
> The "F" is coming from the test infrastructure, not U-Boot's output. A character is printed per
> test, such as "." for pass, "s" for skip, and "F" for fail. For some reason, the test is seeing a
> failure before it's read the output from the crc32 command.
>
> Ah, I see the issue now: the command prompt (=>) in use is part of the output from the crc32
> command, so the test infra-structure thinks the ==> printed by crc32 is the end of the crc32 output.
> Perhaps test.py should look for "[\r\n]${prompt}" rather than "${prompt}", or this board could have
> a prompt that's slightly less likely to trigger false matches.

Argh, yes, I had the same problem and added an "ignore list" to
tbot, see:
https://github.com/hsdenx/tbot/blob/master/src/common/tbot_connection_paramiko.py#L39

bye,
Heiko
-- 
DENX Software Engineering GmbH,      Managing Director: Wolfgang Denk
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany