https://progress.opensuse.org/https://progress.opensuse.org/themes/openSUSE/favicon/favicon.ico?15829177842020-09-02T16:58:54ZopenSUSE Project Management ToolopenQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3222552020-09-02T16:58:54Zokurzokurz@suse.com
<ul><li><strong>Related to</strong> <i><a class="issue tracker-4 status-3 priority-4 priority-default closed child" href="/issues/67342">action #67342</a>: Support using a "generic" video encoder like ffmpeg instead of only relying on the one provided by os-autoinst itself</i> added</li></ul> openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3222612020-09-02T16:59:04Zokurzokurz@suse.com
<ul><li><strong>Related to</strong> <i><a class="issue tracker-6 status-3 priority-4 priority-default closed child parent" href="/issues/68923">coordination #68923</a>: [epic] Use external videoencoder in production auto_review:"External encoder not accepting data"</i> added</li></ul> openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3222642020-09-02T17:01:05Zokurzokurz@suse.com
<ul><li><strong>Category</strong> set to <i>Regressions/Crashes</i></li><li><strong>Target version</strong> set to <i>Ready</i></li></ul><p>I added the two related tickets regarding "external encoder" not assuming that any external encoder is used but that related code changes could have caused this.</p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3222702020-09-02T17:05:27Zokurzokurz@suse.com
<ul><li><strong>Subject</strong> changed from <i>Test fails because auto_review:"Encoder not accepting data", video is missing</i> to <i>Test fails because auto_review:"Encoder not accepting data":retry, video is missing</i></li></ul><p>retriggered jobs seem fine, e.g. <a href="https://openqa.suse.de/admin/workers/669" class="external">https://openqa.suse.de/admin/workers/669</a> and <a href="https://openqa.suse.de/tests/4629502" class="external">https://openqa.suse.de/tests/4629502</a> are ok</p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3224262020-09-03T13:57:41Zmkittlermarius.kittler@suse.com
<ul></ul><blockquote>
<p>but that related code changes could have caused this</p>
</blockquote>
<p>It looks more like the video encoder couldn't be started in the first place or failed very early after startup. Unfortunately we don't have good error handling when starting the video encoder.</p>
<p>Note that my changes for the external video encoder mainly did more of the same but did not change the way the video encoder is launched. And yes, the final "Unable to pass remaining frames to video encoder" messages comes from my code but it is just logged after the stack has already started to terminate due to the previous "Encoder not accepting data" error (which is recorded as reason).</p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3329412020-10-11T09:18:24Zokurzokurz@suse.com
<ul><li><strong>Description</strong> updated (<a title="View differences" href="/journals/332941/diff?detail_id=328417">diff</a>)</li><li><strong>Status</strong> changed from <i>New</i> to <i>Feedback</i></li><li><strong>Assignee</strong> set to <i>okurz</i></li></ul><p>I conducted the DB search that I added to the ticket description to find further occurrences and found</p>
<p>on o3 and osd (in this order):</p>
<pre><code> id | t_finished | state | result | test | reason | host
---------+---------------------+-------+------------+-------+-------------------------------------------------------------------------------------------------+---------------
1409732 | 2020-09-28 01:12:01 | done | incomplete | gnome | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker4
(1 row)
id | t_finished | state | result | test | reason | host
---------+---------------------+-------+------------+-----------------------------------------------+-------------------------------------------------------------------------------------------------+---------------
4744792 | 2020-09-29 00:20:34 | done | incomplete | mru-iscsi_client_normal_auth_backstore_fileio | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker6
4742850 | 2020-09-28 00:29:22 | done | incomplete | qam-rsync-client | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker5
4628195 | 2020-09-02 02:31:20 | done | incomplete | mau-qa_kernel_lynis | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker5
(3 rows)
</code></pre>
<p>One example is <a href="https://openqa.opensuse.org/tests/1409732">https://openqa.opensuse.org/tests/1409732</a> with log details:</p>
<pre><code>�[0m[2020-09-28T03:11:04.065 CEST] [debug] tests/installation/bootloader.pm:57 called bootloader_setup::bootmenu_default_params -> lib/bootloader_setup.pm:478 called bootloader_setup::type_boot_parameters -> lib/bootloader_setup.pm:1330 called testapi::type_string
[2020-09-28T03:11:04.065 CEST] [debug] <<< testapi::type_string(string=" Y2DEBUG=1 vga=791 video=1024x768 plymouth.ignore-serial-consoles console=ttyS0 console=tty linuxrc.log=/dev/ttyS0 linuxrc.core=/dev/ttyS0 linuxrc.debug=4,trace reboot_timeout=0 ", max_interval=4, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
�[37m[2020-09-28T03:11:56.918 CEST] [debug] Backend process died, backend errors are reported below in the following lines:
Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157.
</code></pre>
<p>Notice the timestamp difference between mm:ss 11:04.1 and mm:ss 11:56.9 .<br>
The relevant code in backend/baseclass.pm is:</p>
<pre><code>sub _write_buffered_data_to_file_handle {
my ($self, $program_name, $array_of_buffers, $fh) = @_;
# write as much data as possible (this is called when $fh is ready to write)
my $data = shift @$array_of_buffers;
my $data_written = $fh->syswrite($data);
die "$program_name not accepting data" unless defined $data_written;
# put remaining data it back into the queue
unshift @$array_of_buffers, substr($data, $data_written) unless $data_written == length($data);
</code></pre>
<p>What we could do is check the status of the videoencoder process, e.g. output the PID and check if the process is still running.<br>
Note that "Encoder" means the internal encoder, different than "External encoder" which we would see if any custom configurable video encoder would fail here.</p>
<p>I found out that syswrite sets the errno variable in case of errors, see <a href="https://perldoc.perl.org/functions/syswrite">https://perldoc.perl.org/functions/syswrite</a> . So we should output this to have more details in the case of problems:<br>
<a href="https://github.com/os-autoinst/os-autoinst/pull/1550">https://github.com/os-autoinst/os-autoinst/pull/1550</a></p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3332472020-10-12T11:24:09Zokurzokurz@suse.com
<ul><li><strong>Due date</strong> set to <i>2020-11-14</i></li><li><strong>Priority</strong> changed from <i>Normal</i> to <i>Low</i></li></ul><p>PR merged. I guess we should wait couple of weeks and check if we see the error recorded. Then we might have more information.</p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3468702020-11-04T17:38:17Zokurzokurz@suse.com
<ul><li><strong>Status</strong> changed from <i>Feedback</i> to <i>Resolved</i></li></ul><pre><code>$ for i in o3 osd; do ssh $i "sudo -u geekotest psql openqa -c \"select jobs.id,t_finished,state,result,test,reason,host from jobs, comments, workers where t_finished >= '2020-01-01' and jobs.assigned_worker_id = workers.id and jobs.id = comments.job_id and comments.text ~ 'poo#70873' order by t_finished desc limit 20;\""; done
id | t_finished | state | result | test | reason | host
---------+---------------------+-------+------------+-------+-------------------------------------------------------------------------------------------------+---------------
1409732 | 2020-09-28 01:12:01 | done | incomplete | gnome | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker4
(1 row)
id | t_finished | state | result | test | reason | host
---------+---------------------+-------+------------+-----------------------------------------------+-------------------------------------------------------------------------------------------------+---------------
4744792 | 2020-09-29 00:20:34 | done | incomplete | mru-iscsi_client_normal_auth_backstore_fileio | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker6
4742850 | 2020-09-28 00:29:22 | done | incomplete | qam-rsync-client | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker5
4628195 | 2020-09-02 02:31:20 | done | incomplete | mau-qa_kernel_lynis | backend died: Encoder not accepting data at /usr/lib/os-autoinst/backend/baseclass.pm line 157. | openqaworker5
(3 rows)
</code></pre>
<p>so no more occurences since more than a month</p>
openQA Project - action #70873: Test fails because auto_review:"Encoder not accepting data":retry, video is missinghttps://progress.opensuse.org/issues/70873?journal_id=3578262020-12-11T19:33:04Zokurzokurz@suse.com
<ul><li><strong>Copied to</strong> <i><a class="issue tracker-4 status-1 priority-3 priority-lowest" href="/issues/81002">action #81002</a>: Test incompletes with auto_review:"(?s)openqa.suse.de.*Encoder not accepting data.*Uploading video":retry but video is there</i> added</li></ul>