https://progress.opensuse.org/https://progress.opensuse.org/themes/openSUSE/favicon/favicon.ico?15829177842020-10-02T08:51:51ZopenSUSE Project Management ToolopenQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3282972020-10-02T08:51:51Zokurzokurz@suse.com
<ul><li><strong>Target version</strong> set to <i>Ready</i></li></ul> openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3286422020-10-03T10:59:24Zokurzokurz@suse.com
<ul><li><strong>Related to</strong> <i><a class="issue tracker-4 status-3 priority-5 priority-high3 closed behind-schedule" href="/issues/72139">action #72139</a>: openQA services on OSD failed to connect to database</i> added</li></ul> openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3286482020-10-03T11:12:45Zokurzokurz@suse.com
<ul><li><strong>Related to</strong> <i><a class="issue tracker-4 status-3 priority-3 priority-lowest closed child" href="/issues/69160">action #69160</a>: Improve package and base OS version support: Enable tests for more repos</i> added</li></ul> openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3286512020-10-03T11:16:50Zokurzokurz@suse.com
<ul><li><strong>Status</strong> changed from <i>Workable</i> to <i>Blocked</i></li><li><strong>Assignee</strong> set to <i>okurz</i></li></ul><p>Running <code>env runs=200 count_fail_ratio prove -l t/24-worker-jobs.t</code> locally does not fail the test. But after upgrading to perl-Mojolicious-8.60 (from 8.59) I get:</p>
<pre><code>## Run 1
t/24-worker-jobs.t .. 1/? Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Mojo::Reactor::Poll: Timer failed: Can't call method "unsubscribe" on an undefined value at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop.pm line 98.
Forked inside subtest, but subtest never finished!
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Forked inside subtest, but subtest never finished!
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Mojo::Reactor::Poll: I/O watcher failed: Label not found for "last T2_SUBTEST_WRAPPER" at /usr/lib/perl5/vendor_perl/5.26.1/Test2/Hub/Subtest.pm line 67.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
Forked inside subtest, but subtest never finished!
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
Forked inside subtest, but subtest never finished!
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
Use of uninitialized value in numeric ne (!=) at /home/okurz/local/os-autoinst/openQA/lib/OpenQA/Worker/Job.pm line 752.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
Forked inside subtest, but subtest never finished!
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
Forked inside subtest, but subtest never finished!
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
[ERROR] Upload images subprocess error: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "(end of string)") at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/JSON.pm line 31.
# Failed test 'no error waiting for 'job status changed to stopped''
# at t/24-worker-jobs.t line 79.
# got: ''job status changed to stopped' not happened after 15 seconds'
# expected: undef
# Looks like you failed 1 test of 11
</code></pre>
<p>Probably tests within OBS would have shown this problem before deployment on o3 and/or osd if tests would have been enabled. Waiting for <a class="issue tracker-4 status-3 priority-5 priority-high3 closed behind-schedule" title="action: openQA services on OSD failed to connect to database (Resolved)" href="https://progress.opensuse.org/issues/72139">#72139</a> . As an alternative we could link an old package of perl-Mojolicious to devel:openQA</p>
<p>EDIT: Created <a href="https://build.opensuse.org/package/show/home:okurz:branches:devel:languages:perl/perl-Mojolicious">https://build.opensuse.org/package/show/home:okurz:branches:devel:languages:perl/perl-Mojolicious</a> with an update to the fixed version of perl-Mojolicious. I tried to fix <a href="https://build.opensuse.org/projects/devel:openQA:TestGithub:PR-3421/meta">https://build.opensuse.org/projects/devel:openQA:TestGithub:PR-3421/meta</a> with</p>
<pre><code> <repository name="openSUSE_Factory">
<path project="home:okurz:branches:devel:languages:perl" repository="pure_factory"/>
<path project="devel:openQA" repository="openSUSE_Factory"/>
<arch>x86_64</arch>
</repository>
</code></pre>
<p>as well as with</p>
<pre><code> <repository name="openSUSE_Factory">
<path project="home:okurz:openQA" repository="pure_factory"/>
<arch>x86_64</arch>
</repository>
</code></pre>
<p>with a new repo that links to the new package version as well as devel:openQA but newly triggered builds seem to still not pick up the new repo config. And unfortunately I don't know where the project meta config template resides when we create new pull requests.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3286632020-10-03T12:14:12Zokurzokurz@suse.com
<ul><li><strong>Description</strong> updated (<a title="View differences" href="/journals/328663/diff?detail_id=326095">diff</a>)</li></ul> openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3292002020-10-06T10:42:26Zmkittlermarius.kittler@suse.com
<ul></ul><blockquote>
<p>But after upgrading to perl-Mojolicious-8.60 (from 8.59) I get:</p>
</blockquote>
<p>I get the same when running the test locally. Updating to <code>perl-Mojolicious</code> 8.61 fixes it. Likely the "Fix fork-safety featureā¦" commit is relevant for this test and not the other fix for connection leaks. So this test shows a different issue with Mojolicious 8.60 than the issue we've seen in production. (See <a href="https://github.com/mojolicious/mojo/compare/v8.60...v8.61" class="external">https://github.com/mojolicious/mojo/compare/v8.60...v8.61</a> for the mentioned commits.)</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3292872020-10-06T15:16:18Zkraihsebastian.riedel@suse.com
<ul></ul><p>Aside from the problem with Mojolicious 8.60 there is more broken here in the test. It has quite a few fails, but ends up passing in a local dev environment. The reason is that all the failing tests happen in forked processes and the TAP output from those forked processes is for some reason redirected to STDERR. There the TAP parser (prove) can't see it and the test passes. Generating TAP from more than one process is usually a really bad idea anyway (bad TAP output) and we should probably avoid that. Easiest solution would be to remove the <code>is</code> check in <code>wait_for_job</code>. And then we could look into increasing the test coverage another way.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3293112020-10-07T04:41:52Zokurzokurz@suse.com
<ul><li><strong>Status</strong> changed from <i>Blocked</i> to <i>Workable</i></li><li><strong>Assignee</strong> changed from <i>okurz</i> to <i>kraih</i></li><li><strong>Priority</strong> changed from <i>High</i> to <i>Normal</i></li></ul><p><a class="user active user-mention" href="https://progress.opensuse.org/users/23018">@kraih</a> as we found a workaround and a fix is on the way I can give the ticket over to you as you suggested in chat that you could pick up the ticket to improve the test in the way you suggested in <a class="issue tracker-4 status-3 priority-4 priority-default closed" title="action: t/24-worker-jobs.t fails in OBS (Resolved)" href="https://progress.opensuse.org/issues/72196#note-7">#72196#note-7</a></p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3351702020-10-12T14:20:52Zkraihsebastian.riedel@suse.com
<ul><li><strong>Status</strong> changed from <i>Workable</i> to <i>In Progress</i></li></ul><p>I'm slowly getting closer to the root problem, but it's quite a bit more annoying than i expected. The test runs an event loop until a certain job event happens that it is waiting for and then stops the event loop. But while it is waiting the job forks one or more processes. And for some reason a bunch of those do not exit properly and end up returning back into the test. Now we have multiple processes running the remaining tests in parallel. This happens more than once, so in the end we have multiple forks of the main test process. Tracking it down is not so easy, since it all goes through the event loop without a call stack to follow.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3352032020-10-12T16:45:24Zkraihsebastian.riedel@suse.com
<ul></ul><p>I did manage to locate the root problem, and it was another upstream issue in Mojolicious. <a href="https://github.com/mojolicious/mojo/compare/5fb9f808f043...2286d3c7eb82" class="external">https://github.com/mojolicious/mojo/compare/5fb9f808f043...2286d3c7eb82</a> An exception raised by the event loop reset caused the <code>POSIX::_exit</code> call to be bypassed. That allowed the event loop to recover with a warning and the process broke out of its subprocess context back into the main test file.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3352092020-10-12T17:00:02Zokurzokurz@suse.com
<ul></ul><p>This is promising news.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3386502020-10-21T10:52:29Zkraihsebastian.riedel@suse.com
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Feedback</i></li></ul><p>I expect this to be completely resolved with Mojolicious 8.63.</p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3388962020-10-21T12:56:09Zokurzokurz@suse.com
<ul></ul><p>right, so this needs to wait for <a href="https://build.opensuse.org/request/show/841736" class="external">https://build.opensuse.org/request/show/841736</a></p>
openQA Project - action #72196: t/24-worker-jobs.t fails in OBShttps://progress.opensuse.org/issues/72196?journal_id=3448602020-10-29T17:04:57Zlivdywanliv.dywan@suse.com
<ul><li><strong>Status</strong> changed from <i>Feedback</i> to <i>Resolved</i></li></ul><p>okurz wrote:</p>
<blockquote>
<p>right, so this needs to wait for <a href="https://build.opensuse.org/request/show/841736" class="external">https://build.opensuse.org/request/show/841736</a></p>
</blockquote>
<p>The request got accepted so I assume we're good</p>