Bug 14170 - glib-2.0 codegen ptest failure
Summary: glib-2.0 codegen ptest failure
Status: RESOLVED FIXED
Alias: None
Product: Package Testing (ptest)
Classification: QA/Testing
Component: ptest (show other bugs)
Version: 3.3
Hardware: x86 Multiple
: Medium+ normal
Target Milestone: 3.4 M1
Assignee: Yi Fan Yu
QA Contact:
URL:
Whiteboard: AB-INT
Depends on: 14220
Blocks:
  Show dependency tree
 
Reported: 2020-12-30 08:54 UTC by Naveen Saini
Modified: 2021-04-20 18:02 UTC (History)
5 users (show)

See Also:
OS type for building Yocto: ---
Type of Regression: ---
Verified:
Documentation change: No (bug/feature does not impact docs)


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Naveen Saini 2020-12-30 08:54:57 UTC
AssertionError: Failed ptests:
{'glib-2.0': ['glib/codegen.py.test']}

https://autobuilder.yoctoproject.org/typhoon/#/builders/83/builds/1711

Failure observed in both glib-2.0 v2.66.2 and v2.66.4 versions.
Comment 1 Randy MacLeod 2021-01-07 15:55:02 UTC
Ross has fixed a number of glib ptest so he may provide advice.
Comment 2 Ross Burton 2021-01-11 12:49:33 UTC
Now seen on the arm host too.
Comment 4 Yi Fan Yu 2021-01-29 15:35:08 UTC
was able to reproduce 
standard build of core-image-sato-sdk
although it has flaky/intermittent behaviour
Run 3 times, fails once
```
ERROR: Exit status is 512
DURATION: 3
END: /usr/lib/glib-2.0/ptest
2021-01-29T15:32
STOP: ptest-runner
```
Comment 5 Yi Fan Yu 2021-01-29 17:36:01 UTC
was able to narrow it down to
__main__.TestCodegen.test_reproducible failing
Comment 6 Yi Fan Yu 2021-02-01 20:45:28 UTC
I think this is an issue with the amount of output generated by this particular test.


if i pipe the output of the ptest-runner into a file
`ptest-runner > test.log`, the test passes

however,
if i do `ptest-runner`, the test fails saying exit status 512.

i think this is related to `TestCodegen.test_reproducible` generating around 6000 lines of just boiler plate code.
Comment 7 Yi Fan Yu 2021-02-02 16:44:30 UTC
root cause is in `ptest-runner`. it seems to have trouble dealing with large amount of data coming from the child process.

this does not happen if you do `ptest-runner > filename`

to reproduce this type of issue:

use `ptest-runner` to run the following script

echo -e {1..100000}\\n 


ptrace shows this before failing (child process probably crashed)
```
read(3, 0x7ffc8e9a08c0, 1024)           = -1 EAGAIN (Resource temporarily unavailable)
wait4(21170, [{WIFEXITED(s) && WEXITSTATUS(s) == 1}], WNOHANG, NULL) = 21170
poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, 200) = 0 (Timeout)
write(1, "\n", 1
)                       = 1                                    
write(1, "ERROR: Exit status is 256\n", 26ERROR: Exit status is 256

```
Comment 8 Yi Fan Yu 2021-02-02 17:35:16 UTC
2 proposed fix for this:

1. remove unecessary print statements from glib


2. change `ptest-runner` to do blocking IO on pipes. this will make sure the child process stalls if the pipe is full.
Comment 9 Randy MacLeod 2021-02-03 00:53:46 UTC
option 2 of fixing ptest-runner would be better so that we don't have to find and tweak other programs that behave the same way.
Comment 10 Yi Fan Yu 2021-02-03 19:37:56 UTC
ok the root_root cause of the issue is a 

*read from a non-blocking pipe, but
*write to a blocking stdout

so when the data becomes too large, it would block the write and the pipe will be full.

The child process writing to the non-blocking pipe will sometimes crash because it gets an error EAGAIN. It doesn't handle it well because it thinks it is writing to blocking stdout

```
/home/yyu1/ptest-runner2/lol/ptest/run-ptest: line 10: echo: write error: Resource temporarily unavailable
```
Comment 11 Yi Fan Yu 2021-02-04 20:44:53 UTC
although not mentioned in the patch, i did submit the change to upstream
https://gitlab.gnome.org/GNOME/glib/-/merge_requests/1929
Comment 12 Yi Fan Yu 2021-02-12 15:23:43 UTC
glib rejected the change. see previous link for a response.

one interesting suggestion is to have testrunner ignore certain outputs since all output glib creates follow the tap convention of commenting out these debugging outputs with '#'

so run-ptest for glibc could specifically ignore with grep -v '^#'
Comment 13 Randy MacLeod 2021-02-12 19:35:58 UTC
Note that a work-around for this bug is already in oe-core master:

http://cgit.openembedded.org/openembedded-core/commit/?id=afc9ba7d546f3f2e60fb6f46f740dc925542df16

We're waiting on a fix from Anibal for ptest-runner to revert the work-around.
Comment 14 Aníbal Limón 2021-03-23 17:45:45 UTC
(In reply to comment #13)
> Note that a work-around for this bug is already in oe-core master:
> 
> http://cgit.openembedded.org/openembedded-core/commit/
> ?id=afc9ba7d546f3f2e60fb6f46f740dc925542df16
> 
> We're waiting on a fix from Anibal for ptest-runner to revert the
> work-around.

I have the patches [1] and tested  with glib-2.0 ptest but fails after 958 secs on qemuarm64 in glib-threading tests, that will require to implement per test timeouts because only global timeout is supported default to 300 secs can be override by -t.

The idea is to add a special file under ptest folder like for example in glib-2.0,

/usr/lib/glib-2.0/ptest/timeout

If that file exists in the ptest use the timeout from there if not use global one.


[1] https://github.com/alimon/ptest-runner2/tree/ptest_fixes
Comment 15 Yi Fan Yu 2021-04-07 14:24:21 UTC
(In reply to comment #14)
> I have the patches [1] and tested  with glib-2.0 ptest but fails after 958
> secs on qemuarm64 in glib-threading tests, that will require to implement
> per test timeouts because only global timeout is supported default to 300
> secs can be override by -t.

I think if we do the "reset timeout timer as long as there is output", we are fine for glib-2.0

preparing a patch to revert the workaround.