| Summary: | ltp tests fail with ssh connection lost error intermittently | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [QA/Testing] Runtime Testing | Reporter: | Richard Purdie <richard.purdie> | ||||||||||
| Component: | general | Assignee: | Sakib Sajal <sakib.sajal> | ||||||||||
| Status: | RESOLVED FIXED | QA Contact: | |||||||||||
| Severity: | normal | ||||||||||||
| Priority: | Medium+ | CC: | akuster808, akuster, alejandro, alexandre.belloni, anibal, anuj.mittal, bluelightning, chee.yang.lee, flowergom, Jagadheesan_Duraisamy, kory.maincent, matthewzmd, naveen.kumar.saini, Oleg.Polyakov, oobitots, randy.macleod, steve, yang.wang | ||||||||||
| Version: | unspecified | ||||||||||||
| Target Milestone: | 3.4 M1 | ||||||||||||
| Hardware: | x86 | ||||||||||||
| OS: | Multiple | ||||||||||||
| Whiteboard: | AB-INT AB-INT-TMPFS | ||||||||||||
| OS type for building Yocto: | --- | Type of Regression: | --- | ||||||||||
| Verified: | Documentation change: | No (bug/feature does not impact docs) | |||||||||||
| Bug Depends on: | |||||||||||||
| Bug Blocks: | 14391 | ||||||||||||
| Attachments: |
|
||||||||||||
|
Description
Richard Purdie
2020-02-19 18:52:08 UTC
I'd note that sometimes ltp test runs take extremely long times (18 hours) on both x86 and arm builders. Armin also notes that some test may be causing OOM or otherwise interfering with the ssh connection. Same error on qemuarm64: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/489 ltp build running for 1 day 11 hours so far: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/565 - related? Add Yang. Yang, do you ever see this problem when running ltp in your Lava farm? Armin has a theory that tests may be OOM and killing random processes which sometimes cause the connection reset failure. Not sure if its related to the hang or if that is a separate issue. Are there "known bad" tests we should skip instead? Can we narrow down which test is running when these things happen? (In reply to comment #5) > Add Yang. Yang, do you ever see this problem when running ltp in your Lava > farm? We haven't run LTP test in LAVA since it takes very long time. Testing team should be running it regularly. i was thinking running two selftests and the ltp test on the same system would stress it enough to trigger the failure. Yang, can you add some debugging so that when this happens again, we know more. The arm builder had a hang with ltp running, https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/715 I wasn't able to ssh to the qemu process which was using ~100% cpu. The command which was running was pokybuild@ubuntu1804-arm-1:~/yocto-worker/qemuarm64-ltp/build/build$ cat /proc/3938/cmdline ssh-lroot-oUserKnownHostsFile=/dev/null-oStrictHostKeyChecking=no-oLogLevel=ERROR192.168.7.2export PATH=/usr/sbin:/sbin:/usr/bin:/bin; /opt/ltp/runltp -f controllers -p -q -r /opt/ltp -l /opt/ltp/results/controllers -I 1 -d /opt/ltp so it was running the controllers test suite. Created attachment 4683 [details]
Logs from hung ltp test
I've attached the logs from that run, the ssh connection ones and the test results from those tests that had already run. Created attachment 4684 [details]
Additional logs from /opt/ltp
I was able to get into the qemu machine by killing the ssh command and the build by leaving the qemu process alive. Once in, I was able to get these log files from /opt/ltp
Created attachment 4685 [details]
Additional logs from the system
This file has a dump from /var/log and dmesg of the system, basically trying to record as much state as I could. You can see my attempts to ssh in to debug, for some reason the outside world never saw a reply though.
Nicely done. We can exclude the "controllers" from the ltp_groups list. Yang, Please consider the following: 1.log dmesg before and after the ltp tests (dmesg -c maybe?) for OOM and other problems. 2. Monitor ssh connection https://www.google.com/search?client=ubuntu&channel=fs&q=monitor+ssh+connnection&ie=utf-8&oe=utf-8 https://unix.stackexchange.com/questions/466313/how-to-monitor-what-happens-over-an-ssh-session Richard has increased the memory allocation so there should be fewer OOM events. Richard, Yang and I were discussing how ltp is run and if I understand correctly, systems like Lava use a process that runs on the target to orchestrate running tests. This is done so that if the network connection has a problem, the test can continue and the external monitor can re-connect later to gather test results. Would such a solution make sense for YP and if so is there an existing proxy or framework that would make sense to use? The only things that come to mind for me are tmux/screen which is probably not appropriate or perhaps mosh [1] which might be useful in this case. I still think that gathering/clearing dmesg output before and after tests would be worthwhile. 1) https://mosh.org/ Re-designing the test comms would be nice but it's lots of work so handle seperately if at all. Any demon either the custom proxy or the sshd should be protected from the OOM killer. We need to remove the OOM tests to confirm that this will make the tests more stable. Yang, Please collect the dmesg output before and after the test and remove the other OOM tests in ltp from being run. Yang, do you expect to be able to work on this in the coming few weeks? Hi Randy, Sorry for the very late response. I will try to find some time to work on this in the next sprint. -Yang Yang has to work on something else so I want Matthew to work with guidance from Yang and me. New occurrence https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/964 sadly no new debug added as yet. https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/868 (arm this time but looks like a similar issue) In the latest 2 occurrences: qemux86-64-ltp: AssertionError: Command '['scp', '-o', 'UserKnownHostsFile=/dev/null', '-o', 'StrictHostKeyChecking=no', '-o', 'LogLevel=ERROR', 'root@192.168.7.2:/opt/ltp/results/controllers', '/home/pokybuild/yocto-worker/qemux86-64-ltp/build/build/tmp/work/qemux86_64-poky-linux/core-image-sato/1.0-r0/testimage/ltp_log.20200714230219/controllers']' returned non-zero exit status 1: ssh_exchange_identification: read: Connection reset by peer qemuarm64-ltp: AssertionError: Command '['scp', '-o', 'UserKnownHostsFile=/dev/null', '-o', 'StrictHostKeyChecking=no', '-o', 'LogLevel=ERROR', 'root@192.168.7.2:/opt/ltp/results/filecaps', '/home/pokybuild/yocto-worker/qemuarm64-ltp/build/build/tmp/work/qemuarm64-poky-linux/core-image-sato/1.0-r0/testimage/ltp_log.20200716135742/filecaps']' returned non-zero exit status 1: scp: /opt/ltp/results/filecaps: No such file or directory They fail at the same command, but seem to be a different issue. Hi Richard, Is it possible to run the ltp test on master for a couple hours to see how often does this problem occur? Matthew, can't we run the test on Trevor's YP AB instance? Created attachment 4710 [details]
log.do_testimage of my local environment
This is the result when i run
$ bitbake -c testimage core-image-sato
given the local.conf
```
INHERIT += "testimage"
TEST_SUITES = "ping ssh ltp"
IMAGE_INSTALL_append = " ltp"
TEST_SERVER_IP = "localhost"
TEST_TARGET_IP = "localhost"
IMAGE_INSTALL_append = " python3-pkgutil python3-unittest python3-multiprocessing"
```
Within log.do_testimage in the first attachment, the only appearance of keyword "OOM" is at line 39089:
```
mem.c:218: INFO: start normal OOM testing.
```
By diffing with the log.do_testimage of my local environment, the entire section has been replaced with
```
zoo_clear() did not find pid(0)
```
And this error appeared 46 times.
I need to find out why isn't pid(0) been found in my local environment.
I found that OOM tests are located in mm
See ltp-git/runtest/mm:
oom01 oom01
oom02 oom02
oom03 oom03
oom04 oom04
oom05 oom05
I just submitted a patch removing mm from ltp_groups, I suggest merge this patch and wait for a week or two to see if this error still occurs.
Move to 3.2 M3. Also submitted a patch to make copyFrom scp command non-fatal. Updated ltp failure after this patch: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/949 @Richard, can you send me the log.do_testimage? May be less freqent but it has happened at least once in the last two weeks so we need to keep digging. The "scp: /opt/ltp/results/filecaps: No such file or directory" flavor of this bug occurred on a dunfell build (ubuntu18.04-arm-1): https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1099 Lower to M+ since we removed the OOM tests and that has helped. Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1249/steps/8/logs/step1c I noticed this today on gatesgarth: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1390/steps/10/logs/step1c Another occurrence on dunfell (qemux86-64-ltp, fedora32-ty-1): https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1442/steps/10/logs/step1c Observed same issue on qemux86-64 (debian) https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1476 happen again (qemuarm64-ltp, master) https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1400 Sakib, Send Richard the local.conf change you'd like to use to monitor this an other bugs and he'll add it to the auto-builder. Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1553/steps/12/logs/stdio Also happened here: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1403/steps/12/logs/stdio Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1567/steps/12 As a side note, it went from a timeout to ssh: connect to host 192.168.7.2 port 22: No route to host Which may indicate a different bug or that it needs a different resolution. Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1468/steps/12/logs/stdio As a side note, it went from a timeout to ssh: connect to host 192.168.7.2 port 22: No route to host Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1470/steps/12/logs/stdio Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1479/steps/12/logs/stdio Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1619/steps/12/logs/stdio Happened again: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1619/steps/12/logs/stdio (In reply to comment #42) > Sakib, Send Richard the local.conf change you'd like to use to monitor this > an other bugs and he'll add it to the auto-builder. # set the time interval for logging data BB_HEARTBEAT_EVENT = "<interval>" # boolean to log host data at each <interval> BB_LOG_HOST_STAT_ON_INTERVAL = "1" # boolean to log host data on failure BB_LOG_HOST_STAT_ON_FAILURE = "1" # command to run BB_LOG_HOST_STAT_CMDS = "pwd ; ls ; ifconfig" https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1766 Bitbake still alive (5000s) WARNING: core-image-sato-1.0-r0 do_testimage: Copy returned non-zero exit status 1: ssh: connect to host 192.168.7.2 port 22: No route to host WARNING: core-image-sato-1.0-r0 do_testimage: File could not be copied. Output: ssh: connect to host 192.168.7.2 port 22: No route to host Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 115, in test_ltp_groups self.runltp(ltp_group) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 87, in runltp results, sections = parser.parse(dst) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/utils/logparser.py", line 116, in parse with open(logfile, errors='replace') as f: FileNotFoundError: [Errno 2] No such file or directory: '/home/pokybuild/yocto-worker/qemux86-64-ltp/build/build/tmp/work/qemux86_64-poky-linux/core-image-sato/1.0-r0/testimage/ltp_log.20210326015329/math' Test case ltp.LtpTest.test_ltp_runltp_cve depends on ltp.LtpTest.test_ltp_groups but it didn't pass/run. RESULTS: RESULTS - ltp.LtpTest.test_ltp_help: PASSED (0.08s) RESULTS - ltp_compliance.LtpPosixTest.test_posix_groups: PASSED (4829.91s) RESULTS - ping.PingTest.test_ping: PASSED (0.16s) RESULTS - ssh.SSHTest.test_ssh: PASSED (0.18s) RESULTS - ltp.LtpTest.test_ltp_runltp_cve: SKIPPED (0.00s) RESULTS - ltp.LtpTest.test_ltp_groups: ERROR (8053.68s) SUMMARY: core-image-sato () - Ran 6 tests in 13488.612s core-image-sato - FAIL - Required tests failed (successes=4, skipped=1, failures=0, errors=1) ERROR: core-image-sato-1.0-r0 do_testimage: core-image-sato - FAILED - check the task log and the ssh log ERROR: Logfile of failure stored in: /home/pokybuild/yocto-worker/qemux86-64-ltp/build/build/tmp/work/qemux86_64-poky-linux/core-image-sato/1.0-r0/temp/log.do_testimage.38545 NOTE: recipe core-image-sato-1.0-r0: task do_testimage: Failed ERROR: Task (/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/recipes-sato/images/core-image-sato.bb:do_testimage) failed with exit code '1' https://autobuilder.yoctoproject.org/typhoon/#builders/96/builds/1622 WARNING: core-image-sato-1.0-r0 do_testimage: Copy returned non-zero exit status 1: ssh: connect to host 192.168.7.2 port 22: No route to host WARNING: core-image-sato-1.0-r0 do_testimage: File could not be copied. Output: ssh: connect to host 192.168.7.2 port 22: No route to host Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemuarm64-ltp/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 115, in test_ltp_groups self.runltp(ltp_group) File "/home/pokybuild/yocto-worker/qemuarm64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 87, in runltp results, sections = parser.parse(dst) File "/home/pokybuild/yocto-worker/qemuarm64-ltp/build/meta/lib/oeqa/utils/logparser.py", line 116, in parse with open(logfile, errors='replace') as f: FileNotFoundError: [Errno 2] No such file or directory: '/home/pokybuild/yocto-worker/qemuarm64-ltp/build/build/tmp/work/qemuarm64-poky-linux/core-image-sato/1.0-r0/testimage/ltp_log.20210328011630/controllers' Test case ltp.LtpTest.test_ltp_runltp_cve depends on ltp.LtpTest.test_ltp_groups but it didn't pass/run. RESULTS: RESULTS - ltp.LtpTest.test_ltp_help: PASSED (0.07s) RESULTS - ltp_compliance.LtpPosixTest.test_posix_groups: PASSED (4829.60s) RESULTS - ping.PingTest.test_ping: PASSED (0.07s) RESULTS - ssh.SSHTest.test_ssh: PASSED (0.25s) RESULTS - ltp.LtpTest.test_ltp_runltp_cve: SKIPPED (0.00s) RESULTS - ltp.LtpTest.test_ltp_groups: ERROR (18206.94s) SUMMARY: core-image-sato () - Ran 6 tests in 23640.659s core-image-sato - FAIL - Required tests failed (successes=4, skipped=1, failures=0, errors=1) ERROR: core-image-sato-1.0-r0 do_testimage: core-image-sato - FAILED - check the task log and the ssh log ERROR: Logfile of failure stored in: /home/pokybuild/yocto-worker/qemuarm64-ltp/build/build/tmp/work/qemuarm64-poky-linux/core-image-sato/1.0-r0/temp/log.do_testimage.40610 NOTE: recipe core-image-sato-1.0-r0: task do_testimage: Failed One more: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1774/steps/10/logs/step1c Found the "No such file or directory" variant: https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1798/steps/12/logs/stdio Found again (different file): https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1652/steps/12/logs/stdio https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1685/steps/12/logs/stdio master on ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/96/builds/1728/steps/12/logs/stdio qemuarm64 master-next on ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1902/steps/13/logs/stdio centos7-ty-4 qemux86-64-ltp https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1898/steps/12/logs/stdio debian10-ty-2 qemux86-64-ltp https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1889/steps/12/logs/stdio ubuntu2004-ty-1 qemux86-64-ltp https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1942/steps/12/logs/stdio qemux86-64-ltp centos8-ty-2 https://autobuilder.yoctoproject.org/typhoon/#/builders/95/builds/1969/steps/12/logs/stdio qemux86-64-ltp ubuntu2004-ty-1 ssh: connect to host 192.168.7.2 port 22: No route to host WARNING: core-image-sato-1.0-r0 do_testimage: File could not be copied. Output: ssh: connect to host 192.168.7.2 port 22: No route to host Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 115, in test_ltp_groups self.runltp(ltp_group) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/runtime/cases/ltp.py", line 87, in runltp results, sections = parser.parse(dst) File "/home/pokybuild/yocto-worker/qemux86-64-ltp/build/meta/lib/oeqa/utils/logparser.py", line 116, in parse with open(logfile, errors='replace') as f: FileNotFoundError: [Errno 2] No such file or directory: '/home/pokybuild/yocto-worker/qemux86-64-ltp/build/build/tmp/work/qemux86_64-poky-linux/core-image-sato/1.0-r0/testimage/ltp_log.20210602224847/controllers' Test case ltp.LtpTest.test_ltp_runltp_cve depends on ltp.LtpTest.test_ltp_groups but it didn't pass/run. At least some of the ltp hangs are caused by http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=529bb922c786f1acd041ff9a8d2b675d067e2ae3 which is now fixed. There is probably another arm specific issue lurking however this bug is now quite confused. We'll mark this one as resolved by the above fix and open new bugs for any renaming issues. |