https://progress.opensuse.org/https://progress.opensuse.org/themes/openSUSE/favicon/favicon.ico?15829177842021-07-29T15:39:10ZopenSUSE Project Management ToolopenQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4316692021-07-29T15:39:10Zokurzokurz@suse.com
<ul><li><strong>Subject</strong> changed from <i>Test failed incomplete: auto_review:"Reason: backend died: QEMU exited unexpectedly, see log for details":retry</i> to <i>Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details"</i></li><li><strong>Category</strong> set to <i>Infrastructure</i></li><li><strong>Priority</strong> changed from <i>Normal</i> to <i>High</i></li></ul><p>The details are actually very important. Here it says:</p>
<pre><code>Could not find '/usr/sbin/smbd', please install it
</code></pre>
<p>That's a pretty clear message :)</p>
<p>I tried to make that line more clear but unfortunately it's not very obvious as a "debug" message. Will create separate ticket for that.</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4316722021-07-29T15:40:50Zokurzokurz@suse.com
<ul><li><strong>Copied to</strong> <i><a class="issue tracker-4 status-3 priority-4 priority-default closed" href="/issues/96311">action #96311</a>: qemu error message is still "debug", should be "warn" or more severe size:S</i> added</li></ul> openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4401112021-09-01T07:09:19Zokurzokurz@suse.com
<ul><li><strong>Project</strong> changed from <i>openQA Tests</i> to <i>openQA Infrastructure</i></li><li><strong>Category</strong> deleted (<del><i>Infrastructure</i></del>)</li><li><strong>Target version</strong> set to <i>Ready</i></li></ul> openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4401712021-09-01T08:53:02Zlivdywanliv.dywan@suse.com
<ul><li><strong>Subject</strong> changed from <i>Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details"</i> to <i>Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:M</i></li><li><strong>Description</strong> updated (<a title="View differences" href="/journals/440171/diff?detail_id=417401">diff</a>)</li><li><strong>Status</strong> changed from <i>New</i> to <i>Workable</i></li><li><strong>Priority</strong> changed from <i>High</i> to <i>Normal</i></li></ul><p>Lowering Priority as it's basically about the error, not a problem with failing tests</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4420132021-09-03T07:45:10Zosukup
<ul></ul><p>this is missing samba on worker in WSL (Windows) test, which was problem on imgtester. Now is probably irrelevant</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4516292021-10-01T16:08:15Zlivdywanliv.dywan@suse.com
<ul></ul><p>I'm unsure what the best approach is, so I'm documenting what I was pondering on:</p>
<p>The logs reveal the use of Samba in two places, the arguments passed to qemu as well as the error which looks like a "debug" message:</p>
<pre><code>[2021-07-29T11:35:34.940 UTC] [debug] starting: /usr/bin/qemu-system-x86_64 -vga qxl -only-migratable -chardev ringbuf,id=serial0,logfile=serial0,logappend=on -serial chardev:serial0 -audiodev none,id=snd0 -device intel-hda -device hda-output,audiodev=snd0 -global isa-fdc.fdtypeA=none -m 2048 -machine q35 -cpu host -netdev user,id=qanet0,smb=/var/lib/openqa/pool/2 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -device usb-ehci -device usb-tablet -smp 1 -enable-kvm -no-shutdown -vnc :92,share=force-shared -device virtio-serial -chardev
[...]
[2021-07-29T11:35:35.132 UTC] [debug] QEMU: QEMU emulator version 4.2.1 (openSUSE Leap 15.2)
[2021-07-29T11:35:35.132 UTC] [debug] QEMU: Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers
[2021-07-29T11:35:35.132 UTC] [debug] QEMU: qemu-system-x86_64: Could not find '/usr/sbin/smbd', please install it
</code></pre>
<ul>
<li>The arguments are added in <code>qemu.pm</code> iff <code>QEMU_ENABLE_SMBD</code> is defined. We could presumably check wether Samba's available here before we even do that.</li>
<li>We could <code>die "QEMU: $line" if $line =~ m/Could not find.+please install it/;</code> in <code>process_qemu_output</code>.
<ul>
<li>One step further, we could error on anything that's not related to version or copyright.</li>
<li>A test based on what's already in <code>18-qemu-options.t</code> could assert that "please install" or other messages result in a clean failure.</li>
</ul></li>
<li>Should we make Samba a dep and use it in tests? I can't think of an easy way to mock it.</li>
</ul>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4520042021-10-04T16:18:30Zosukup
<ul></ul><p>cdywan wrote:</p>
<blockquote>
<ul>
<li>Should we make Samba a dep and use it in tests? I can't think of an easy way to mock it.</li>
</ul>
</blockquote>
<p>is should be dependency of <em>os-autoinst-distri-opensuse</em></p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4520432021-10-04T20:59:29Zokurzokurz@suse.com
<ul></ul><p>please keep <a href="https://progress.opensuse.org/issues/96272#Acceptance-criteria" class="external">https://progress.opensuse.org/issues/96272#Acceptance-criteria</a> in mind, the primary object is to make the error message appear in the job reason, not necessarily fix the problem :)</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4526522021-10-06T08:48:51Zosukup
<ul><li><strong>Assignee</strong> set to <i>osukup</i></li></ul> openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4526972021-10-06T09:39:23Zosukup
<ul><li><strong>Status</strong> changed from <i>Workable</i> to <i>In Progress</i></li></ul> openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4527842021-10-06T12:49:32Zosukup
<ul></ul><p>It seems be bigger problem than I excepted.</p>
<p>Code for this is in <code>os-autoinst/OpenQA/Qemu/Proc.pm</code>:</p>
<pre><code class="perl syntaxhl" data-language="perl"><span class="k">sub </span><span class="nf">exec_qemu</span> <span class="p">{</span>
<span class="k">my</span> <span class="p">(</span><span class="nv">$self</span><span class="p">)</span> <span class="o">=</span> <span class="nv">@_</span><span class="p">;</span>
<span class="k">my</span> <span class="nv">@params</span> <span class="o">=</span> <span class="nv">$self</span><span class="o">-></span><span class="nv">gen_cmdline</span><span class="p">();</span>
<span class="nv">session</span><span class="o">-></span><span class="nv">enable</span><span class="p">;</span>
<span class="nn">bmwqemu::</span><span class="nv">diag</span><span class="p">('</span><span class="s1">starting: </span><span class="p">'</span> <span class="o">.</span> <span class="nb">join</span><span class="p">('</span><span class="s1"> </span><span class="p">',</span> <span class="nv">@params</span><span class="p">));</span>
<span class="nv">session</span><span class="o">-></span><span class="nv">enable_subreaper</span><span class="p">;</span>
<span class="k">my</span> <span class="nv">$process</span> <span class="o">=</span> <span class="nv">$self</span><span class="o">-></span><span class="nv">_process</span><span class="p">;</span>
<span class="nv">$self</span><span class="o">-></span><span class="p">{</span><span class="nv">_qemu_terminated</span><span class="p">}</span> <span class="o">=</span> <span class="mi">0</span><span class="p">;</span>
<span class="nv">$process</span><span class="o">-></span><span class="nv">on</span><span class="p">(</span>
<span class="s">collected</span> <span class="o">=></span> <span class="k">sub </span><span class="p">{</span>
<span class="nv">$self</span><span class="o">-></span><span class="p">{</span><span class="nv">_qemu_terminated</span><span class="p">}</span> <span class="o">=</span> <span class="mi">1</span><span class="p">;</span>
<span class="k">unless</span> <span class="p">(</span><span class="nv">$self</span><span class="o">-></span><span class="p">{</span><span class="nv">_stopping</span><span class="p">})</span> <span class="p">{</span>
<span class="k">my</span> <span class="nv">$msg</span> <span class="o">=</span> <span class="p">'</span><span class="s1">QEMU exited unexpectedly, see log for details</span><span class="p">';</span>
<span class="nv">$msg</span> <span class="o">=</span> <span class="p">'</span><span class="s1">QEMU was killed due to the system being out of memory</span><span class="p">'</span> <span class="k">if</span> <span class="p">(</span><span class="nv">$self</span><span class="o">-></span><span class="nv">check_qemu_oom</span> <span class="o">==</span> <span class="mi">0</span><span class="p">);</span>
<span class="nn">bmwqemu::</span><span class="nv">serialize_state</span><span class="p">(</span><span class="s">component</span> <span class="o">=></span> <span class="p">'</span><span class="s1">backend</span><span class="p">',</span> <span class="s">msg</span> <span class="o">=></span> <span class="nv">$msg</span><span class="p">);</span>
<span class="p">}</span>
<span class="p">});</span>
<span class="nv">$process</span><span class="o">-></span><span class="nv">code</span><span class="p">(</span><span class="k">sub </span><span class="p">{</span>
<span class="nv">$SIG</span><span class="p">{</span><span class="bp">__DIE__</span><span class="p">}</span> <span class="o">=</span> <span class="nb">undef</span><span class="p">;</span> <span class="c1"># overwrite the default - just exit</span>
<span class="nb">system</span> <span class="nv">$self</span><span class="o">-></span><span class="nv">qemu_bin</span><span class="p">,</span> <span class="p">'</span><span class="s1">-version</span><span class="p">';</span>
<span class="c1"># don't try to talk to the host's PA</span>
<span class="nv">$ENV</span><span class="p">{</span><span class="nv">QEMU_AUDIO_DRV</span><span class="p">}</span> <span class="o">=</span> <span class="p">"</span><span class="s2">none</span><span class="p">";</span>
<span class="nb">exec</span><span class="p">(</span><span class="nv">@params</span><span class="p">);</span>
<span class="p">});</span>
</code></pre>
<p>we can get stdout from <code>$proc</code> but this will break our logging to <code>autoinst-log.txt</code> which is unacceptable --> see <a href="http://quasar.suse.cz/tests/7268#details" class="external">http://quasar.suse.cz/tests/7268#details</a></p>
<p><code>$process->read_all_stdout</code> flush stdoud .. so channel for our logger will be empty..</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4528892021-10-07T04:10:12Zopenqa_reviewopenqa-review@suse.de
<ul><li><strong>Due date</strong> set to <i>2021-10-21</i></li></ul><p>Setting due date based on mean cycle time of SUSE QE Tools</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4540012021-10-11T11:45:17Zlivdywanliv.dywan@suse.com
<ul></ul><p>osukup wrote:</p>
<blockquote>
<p>we can get stdout from <code>$proc</code> but this will break our logging to <code>autoinst-log.txt</code> which is unacceptable --> see <a href="http://quasar.suse.cz/tests/7268#details" class="external">http://quasar.suse.cz/tests/7268#details</a></p>
<p><code>$process->read_all_stdout</code> flush stdoud .. so channel for our logger will be empty..</p>
</blockquote>
<p>What I see here is this:</p>
<pre><code>[2021-10-06T14:44:21.320 CEST] [debug] DIAGGG:'QEMU emulator version 5.2.0 (SUSE Linux Enterprise 15)
'
'Copyright (c) 2003-2020 Fabrice Bellard and the QEMU Project developers
'
'qemu-system-x86_64: Could not find \'/usr/sbin/smbd\', please install it
'
dmesg: read kernel buffer failed: Operation not permitted
</code></pre>
<p>So I can see the error we want to catch. The whitespace just looks garbled. Maybe you can just strip it?</p>
<p>I'd say push what you have and it should make it easier to spot the problem</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4544362021-10-12T08:40:10Zosukup
<ul></ul><p>cdywan wrote:</p>
<blockquote>
<p>osukup wrote:</p>
<blockquote>
<p>we can get stdout from <code>$proc</code> but this will break our logging to <code>autoinst-log.txt</code> which is unacceptable --> see <a href="http://quasar.suse.cz/tests/7268#details" class="external">http://quasar.suse.cz/tests/7268#details</a></p>
<p><code>$process->read_all_stdout</code> flush stdoud .. so channel for our logger will be empty..</p>
</blockquote>
<p>What I see here is this:</p>
<pre><code>[2021-10-06T14:44:21.320 CEST] [debug] DIAGGG:'QEMU emulator version 5.2.0 (SUSE Linux Enterprise 15)
'
'Copyright (c) 2003-2020 Fabrice Bellard and the QEMU Project developers
'
'qemu-system-x86_64: Could not find \'/usr/sbin/smbd\', please install it
'
dmesg: read kernel buffer failed: Operation not permitted
</code></pre>
<p>So I can see the error we want to catch. The whitespace just looks garbled. Maybe you can just strip it?</p>
<p>I'd say push what you have and it should make it easier to spot the problem</p>
</blockquote>
<p>Look at <code>autoinst-log.txt</code> ... exactly this info is missing from log (<code>DIAGG: ....</code> is Data::Dumper in Callback) , which is exactly why we can't use this way</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4544452021-10-12T08:44:38Zosukup
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Workable</i></li><li><strong>Assignee</strong> deleted (<del><i>osukup</i></del>)</li></ul><p>I'm giving up on this poo:(</p>
<p>there isn't the way to get needed info without broking our logging, or a bigger rewrite of how is qemu executed and controlled.</p>
<p>Other way would be analysis of logs in openQA ... but this change will be also pretty big. So I don't think is worth this amount of work for too small effect in webgui which applies only in small amount cases</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4544542021-10-12T08:48:57Zokurzokurz@suse.com
<ul><li><strong>Due date</strong> deleted (<del><i>2021-10-21</i></del>)</li></ul> openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4544842021-10-12T09:05:57Zokurzokurz@suse.com
<ul></ul><p>So originally I hoped we could improve the "log gathering" within os-autoinst but I would be ok to parse the logs in openQA and update the reason retroactively. We already do something similar in <a href="https://github.com/os-autoinst/openQA/blob/7ea206aff0f8cf33abb039bb12ab0da25e90fcbc/lib/OpenQA/Worker/Job.pm#L567" class="external">https://github.com/os-autoinst/openQA/blob/7ea206aff0f8cf33abb039bb12ab0da25e90fcbc/lib/OpenQA/Worker/Job.pm#L567</a> for special cases</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4559822021-10-18T08:02:56ZXiaojing_liuxliu1@suse.com
<ul><li><strong>Status</strong> changed from <i>Workable</i> to <i>In Progress</i></li><li><strong>Assignee</strong> set to <i>Xiaojing_liu</i></li></ul><p>Here is a pr to override the reason with more details: <a href="https://github.com/os-autoinst/openQA/pull/4298" class="external">https://github.com/os-autoinst/openQA/pull/4298</a></p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4564292021-10-19T04:10:17Zopenqa_reviewopenqa-review@suse.de
<ul><li><strong>Due date</strong> set to <i>2021-11-02</i></li></ul><p>Setting due date based on mean cycle time of SUSE QE Tools</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4569192021-10-21T03:02:47ZXiaojing_liuxliu1@suse.com
<ul><li><strong>Status</strong> changed from <i>In Progress</i> to <i>Feedback</i></li></ul><p>PR got merged</p>
openQA Infrastructure - action #96272: Test failed incomplete: "Reason: backend died: QEMU exited unexpectedly, see log for details" size:Mhttps://progress.opensuse.org/issues/96272?journal_id=4580102021-10-22T11:31:34ZXiaojing_liuxliu1@suse.com
<ul><li><strong>Status</strong> changed from <i>Feedback</i> to <i>Resolved</i></li></ul><p>We could track this ticket by seeing monitor results.</p>