9:22 a.m.
--Apple-Mail=_97530516-BF1E-4F4D-B41F-969FA1E8F891
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
charset=utf-8
On 19 Dec 2017, at 07:53, Eyal Edri <eedri(a)redhat.com> wrote:
=20
=20
=20
On Dec 19, 2017 00:20, "Michal Skrivanek" <michal.skrivanek(a)redhat.com =
<mailto:michal.skrivanek@redhat.com>> wrote:
=20
> On 18 Dec 2017, at 13:21, Milan Zamazal <mzamazal(a)redhat.com =
<mailto:mzamazal@redhat.com>> wrote:
>
> Yedidyah Bar David <didi(a)redhat.com <mailto:didi@redhat.com>> =
writes:
>
>> On Mon, Dec 18, 2017 at 10:17 AM, Code Review <gerrit(a)ovirt.org =
<mailto:gerrit@ovirt.org>> wrote:
>>> Jenkins CI posted comments on this change.
>>>
>>
>>> View Change
>>>
>>> Patch set 3:Continuous-Integration -1
>>>
>>> Build Failed
>>>
>>> =
http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86=
_64/2882/ =
<http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x8=
6_64/2882/>
>>> : FAILURE
>>
>> Console output of above job says:
>>
>> 08:13:34 # migrate_vm:
>> 08:16:37 * Collect artifacts:
>> 08:16:40 * Collect artifacts: Success (in 0:00:03)
>> 08:16:40 # migrate_vm: Success (in 0:03:06)
>> 08:16:40 # Results located at
>> =
/dev/shm/ost/deployment-basic-suite-master/default/006_migrations.py.junit=
.xml
>> 08:16:40 @ Run test: 006_migrations.py: Success (in
0:03:50)
>> 08:16:40 Error occured, aborting
>>
>> The file 006_migrations.py.junit.xml [1] says:
>>
>> <failure type=3D"exceptions.AssertionError" message=3D"False
!=3D =
True after
>> 180 seconds">
>
> Reading the logs, I can see the VM migrates normally and seems to be
> reported to Engine correctly. When Engine receives end-of-migration
> event, it sends Destroy to the source (which is correct), calls =
dumpxmls
> on the destination in the meantime (looks fine to me) and then
calls
=20
looks like a race between getallvmstats reporting VM as Down =
(statusTime:
4296271980) being processed, while there is a =
Down/MigrationSucceeded event arriving (with notify_time 4296273170) at =
about the same time
Unfortunately the vdsm.log is not in DEBUG level so there=E2=80=99s =
very little information as to why and what exactly did it send out.
@infra - can you enable debug log level for vdsm by default?
=20
How do you enable debug mode for vdsm ?
Can be permanently set in /etc/vdsm/logger.conf
I suppose enabling for all loggers would be useful
see https://access.redhat.com/articles/2919931 =
<https://access.redhat.com/articles/2919931>
Thanks,
michal
=20
=20
It does look like a race to me - does it reproduce?
=20
> Destroy on the destination, which is weird and I don't understand =
why
> the Destroy is invoked.
>
> Arik, would you like to take a look? Maybe I overlooked something =
or
> maybe there's a bug. The logs are at
> =
http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86=
_64/2882/artifact/exported-artifacts/basic-suite-master__logs/test_logs/ba=
sic-suite-master/post-006_migrations.py/ =
<http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x8=
6_64/2882/artifact/exported-artifacts/basic-suite-master__logs/test_logs/b=
asic-suite-master/post-006_migrations.py/>
> and the interesting things happen around 2017-12-18
03:13:43,758-05.
>
>> Can someone please have a look? Thanks.
>>
>> As a side note, if indeed this is the cause for the failure for the
>> job, it's misleading to say "migrate_vm: Success".
>>
>> [1]
>> =
http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86=
_64/2882/artifact/exported-artifacts/basic-suite-master__logs/006_migratio=
ns.py.junit.xml =
<http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x8=
6_64/2882/artifact/exported-artifacts/basic-suite-master__logs/006_migrati=
ons.py.junit.xml>
>>
>>>
>>> To view, visit change 85177. To unsubscribe, visit settings.
>>>
>>> Gerrit-Project: ovirt-system-tests
>>> Gerrit-Branch: master
>>> Gerrit-MessageType: comment
>>> Gerrit-Change-Id: I7eb386744a2a2faf0acd734e0ba44be22dd590b5
>>> Gerrit-Change-Number: 85177
>>> Gerrit-PatchSet: 3
>>> Gerrit-Owner: Yedidyah Bar David <didi(a)redhat.com =
<mailto:didi@redhat.com>>
>>> Gerrit-Reviewer: Dafna Ron <dron(a)redhat.com =
<mailto:dron@redhat.com>>
>>> Gerrit-Reviewer: Eyal Edri <eedri(a)redhat.com =
<mailto:eedri@redhat.com>>
>>> Gerrit-Reviewer: Jenkins CI
>>> Gerrit-Reviewer: Sandro Bonazzola <sbonazzo(a)redhat.com =
<mailto:sbonazzo@redhat.com>>
>>> Gerrit-Reviewer: Yedidyah Bar David <didi(a)redhat.com
=
<mailto:didi@redhat.com>>
>>> Gerrit-Comment-Date: Mon, 18 Dec 2017 08:17:11 +0000
>>> Gerrit-HasComments: No
> _______________________________________________
> Devel mailing list
> Devel(a)ovirt.org <mailto:Devel@ovirt.org>
> http://lists.ovirt.org/mailman/listinfo/devel =
<http://lists.ovirt.org/mailman/listinfo/devel>
>
>
=20
_______________________________________________
Infra mailing list
Infra(a)ovirt.org <mailto:Infra@ovirt.org>
http://lists.ovirt.org/mailman/listinfo/infra =
<http://lists.ovirt.org/mailman/listinfo/infra>
=20
--Apple-Mail=_97530516-BF1E-4F4D-B41F-969FA1E8F891
Content-Transfer-Encoding: quoted-printable
Content-Type: text/html;
charset=utf-8
<html><head><meta http-equiv=3D"Content-Type"
content=3D"text/html =
charset=3Dutf-8"></head><body style=3D"word-wrap: break-word; =
-webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" =
class=3D""><br class=3D""><div><blockquote
type=3D"cite" class=3D""><div =
class=3D"">On 19 Dec 2017, at 07:53, Eyal Edri <<a =
href=3D"mailto:eedri@redhat.com"
class=3D"">eedri(a)redhat.com</a>&gt; =
wrote:</div><br class=3D"Apple-interchange-newline"><div
class=3D""><div =
dir=3D"auto" class=3D""><div class=3D""><br
class=3D""><div =
class=3D"gmail_extra"><br class=3D""><div
class=3D"gmail_quote">On Dec =
19, 2017 00:20, "Michal Skrivanek" <<a =
href=3D"mailto:michal.skrivanek@redhat.com" =
class=3D"">michal.skrivanek(a)redhat.com</a>&gt; wrote:<br =
type=3D"attribution" class=3D""><blockquote
class=3D"quote" =
style=3D"margin:0 0 0 .8ex;border-left:1px #ccc =
solid;padding-left:1ex"><div class=3D"elided-text"><br
class=3D"">
> On 18 Dec 2017, at 13:21, Milan Zamazal <<a =
href=3D"mailto:mzamazal@redhat.com"
class=3D"">mzamazal(a)redhat.com</a>&gt;=
wrote:<br class=3D"">
><br class=3D"">
> Yedidyah Bar David <<a href=3D"mailto:didi@redhat.com" =
class=3D"">didi(a)redhat.com</a>&gt; writes:<br
class=3D"">
><br class=3D"">
>> On Mon, Dec 18, 2017 at 10:17 AM, Code Review <<a =
href=3D"mailto:gerrit@ovirt.org"
class=3D"">gerrit(a)ovirt.org</a>&gt; =
wrote:<br class=3D"">
>>> Jenkins CI posted comments on this change.<br
class=3D"">
>>><br class=3D"">
>><br class=3D"">
>>> View Change<br class=3D"">
>>><br class=3D"">
>>> Patch set 3:Continuous-Integration -1<br
class=3D"">
>>><br class=3D"">
>>> Build Failed<br class=3D"">
>>><br class=3D"">
>>> <a =
href=3D"http://jenkins.ovirt.org/job/ovirt-system-tests_master_check...
-el7-x86_64/2882/" rel=3D"noreferrer" target=3D"_blank" =
class=3D"">http://jenkins.ovirt.org/job/<wbr =
class=3D"">ovirt-system-tests_master_<wbr =
class=3D"">check-patch-el7-x86_64/2882/</a><br
class=3D"">
>>> : FAILURE<br class=3D"">
>><br class=3D"">
>> Console output of above job says:<br class=3D"">
>><br class=3D"">
>> 08:13:34 # migrate_vm:<br
class=3D"">
>> 08:16:37 * Collect artifacts:<br
class=3D"">
>> 08:16:40 * Collect artifacts: Success (in
=
0:00:03)<br class=3D"">
>> 08:16:40 # migrate_vm: Success (in 0:03:06)<br =
class=3D"">
>> 08:16:40 # Results located at<br
class=3D"">
>> /dev/shm/ost/deployment-basic-<wbr =
class=3D"">suite-master/default/006_<wbr =
class=3D"">migrations.py.junit.xml<br class=3D"">
>> 08:16:40 @ Run test: 006_migrations.py: Success (in 0:03:50)<br =
class=3D"">
>> 08:16:40 Error occured, aborting<br class=3D"">
>><br class=3D"">
>> The file 006_migrations.py.junit.xml [1] says:<br
class=3D"">
>><br class=3D"">
>> <failure type=3D"exceptions.<wbr
class=3D"">AssertionError" =
message=3D"False !=3D True after<br class=3D"">
>> 180 seconds"><br class=3D"">
><br class=3D"">
> Reading the logs, I can see the VM migrates normally and seems to =
be<br class=3D"">
> reported to Engine correctly. When Engine receives =
end-of-migration<br class=3D"">
> event, it sends Destroy to the source (which is correct), calls =
dumpxmls<br class=3D"">
> on the destination in the meantime (looks fine to me) and then =
calls<br class=3D"">
<br class=3D"">
</div>looks like a race between getallvmstats reporting VM as Down =
(statusTime: 4296271980) being processed, while there is a =
Down/MigrationSucceeded event arriving (with notify_time 4296273170) at =
about the same time<br class=3D"">
Unfortunately the vdsm.log is not in DEBUG level so there=E2=80=99s very =
little information as to why and what exactly did it send out.<br =
class=3D"">
@infra - can you enable debug log level for vdsm by default?<br =
class=3D""></blockquote></div></div></div><div
dir=3D"auto" class=3D""><br=
class=3D""></div><div dir=3D"auto"
class=3D"">How do you enable debug =
mode for vdsm ?</div></div></div></blockquote><div><br =
class=3D""></div>Can be permanently set in =
/etc/vdsm/logger.conf</div><div>I suppose enabling for all loggers would =
be useful</div><div><br
class=3D""></div><div>see <a =
href=3D"https://access.redhat.com/articles/2919931" =
class=3D"">https://access.redhat.com/articles/2919931</a&...
=
class=3D""></div><div>Thanks,</div><div>michal</div><div><br
=
class=3D""><blockquote type=3D"cite"
class=3D""><div class=3D""><div =
dir=3D"auto" class=3D""><div dir=3D"auto"
class=3D""><br =
class=3D""></div><div dir=3D"auto"
class=3D""><div =
class=3D"gmail_extra"><div
class=3D"gmail_quote"><blockquote =
class=3D"quote" style=3D"margin:0 0 0 .8ex;border-left:1px #ccc =
solid;padding-left:1ex">
<br class=3D"">
It does look like a race to me - does it reproduce?<br class=3D"">
<div class=3D"elided-text"><br class=3D"">
> Destroy on the destination, which is weird and I don't understand =
why<br class=3D"">
> the Destroy is invoked.<br class=3D"">
><br class=3D"">
> Arik, would you like to take a look? Maybe I overlooked =
something or<br class=3D"">
> maybe there's a bug. The logs are at<br
class=3D"">
> <a =
href=3D"http://jenkins.ovirt.org/job/ovirt-system-tests_master_check...
-el7-x86_64/2882/artifact/exported-artifacts/basic-suite-master__logs/test=
_logs/basic-suite-master/post-006_migrations.py/" rel=3D"noreferrer" =
target=3D"_blank" class=3D"">http://jenkins.ovirt.org/job/<wbr
=
class=3D"">ovirt-system-tests_master_<wbr =
class=3D"">check-patch-el7-x86_64/2882/<wbr =
class=3D"">artifact/exported-artifacts/<wbr =
class=3D"">basic-suite-master__logs/test_<wbr =
class=3D"">logs/basic-suite-master/post-<wbr =
class=3D"">006_migrations.py/</a><br class=3D"">
> and the interesting things happen around 2017-12-18 =
03:13:43,758-05.<br class=3D"">
><br class=3D"">
>> Can someone please have a look? Thanks.<br class=3D"">
>><br class=3D"">
>> As a side note, if indeed this is the cause for the failure for =
the<br class=3D"">
>> job, it's misleading to say "migrate_vm: Success".<br
class=3D"">=
>><br class=3D"">
>> [1]<br class=3D"">
>> <a =
href=3D"http://jenkins.ovirt.org/job/ovirt-system-tests_master_check...
-el7-x86_64/2882/artifact/exported-artifacts/basic-suite-master__logs/006_=
migrations.py.junit.xml" rel=3D"noreferrer" target=3D"_blank" =
class=3D"">http://jenkins.ovirt.org/job/<wbr =
class=3D"">ovirt-system-tests_master_<wbr =
class=3D"">check-patch-el7-x86_64/2882/<wbr =
class=3D"">artifact/exported-artifacts/<wbr =
class=3D"">basic-suite-master__logs/006_<wbr =
class=3D"">migrations.py.junit.xml</a><br class=3D"">
>><br class=3D"">
>>><br class=3D"">
>>> To view, visit change 85177. To unsubscribe, visit =
settings.<br class=3D"">
>>><br class=3D"">
>>> Gerrit-Project: ovirt-system-tests<br
class=3D"">
>>> Gerrit-Branch: master<br class=3D"">
>>> Gerrit-MessageType: comment<br class=3D"">
>>> Gerrit-Change-Id: I7eb386744a2a2faf0acd734e0ba44<wbr =
class=3D"">be22dd590b5<br class=3D"">
>>> Gerrit-Change-Number: 85177<br class=3D"">
>>> Gerrit-PatchSet: 3<br class=3D"">
>>> Gerrit-Owner: Yedidyah Bar David <<a =
href=3D"mailto:didi@redhat.com"
class=3D"">didi(a)redhat.com</a>&gt;<br =
class=3D"">
>>> Gerrit-Reviewer: Dafna Ron <<a =
href=3D"mailto:dron@redhat.com"
class=3D"">dron(a)redhat.com</a>&gt;<br =
class=3D"">
>>> Gerrit-Reviewer: Eyal Edri <<a =
href=3D"mailto:eedri@redhat.com"
class=3D"">eedri(a)redhat.com</a>&gt;<br =
class=3D"">
>>> Gerrit-Reviewer: Jenkins CI<br class=3D"">
>>> Gerrit-Reviewer: Sandro Bonazzola <<a =
href=3D"mailto:sbonazzo@redhat.com" =
class=3D"">sbonazzo(a)redhat.com</a>&gt;<br
class=3D"">
>>> Gerrit-Reviewer: Yedidyah Bar David <<a =
href=3D"mailto:didi@redhat.com"
class=3D"">didi(a)redhat.com</a>&gt;<br =
class=3D"">
>>> Gerrit-Comment-Date: Mon, 18 Dec 2017 08:17:11 +0000<br =
class=3D"">
>>> Gerrit-HasComments: No<br class=3D"">
> ______________________________<wbr
class=3D"">_________________<br =
class=3D"">
</div>> Devel mailing list<br class=3D"">
> <a href=3D"mailto:Devel@ovirt.org"
class=3D"">Devel(a)ovirt.org</a><br =
class=3D"">
> <a href=3D"http://lists.ovirt.org/mailman/listinfo/devel" =
rel=3D"noreferrer" target=3D"_blank" =
class=3D"">http://lists.ovirt.org/<wbr =
class=3D"">mailman/listinfo/devel</a><br class=3D"">
<div class=3D"elided-text">><br class=3D"">
><br class=3D"">
<br class=3D"">
______________________________<wbr class=3D"">_________________<br =
class=3D"">
Infra mailing list<br class=3D"">
<a href=3D"mailto:Infra@ovirt.org"
class=3D"">Infra(a)ovirt.org</a><br =
class=3D"">
<a href=3D"http://lists.ovirt.org/mailman/listinfo/infra" =
rel=3D"noreferrer" target=3D"_blank" =
class=3D"">http://lists.ovirt.org/<wbr =
class=3D"">mailman/listinfo/infra</a><br class=3D"">
</div></blockquote></div><br
class=3D""></div></div></div>
</div></blockquote></div><br
class=3D""></body></html>=
--Apple-Mail=_97530516-BF1E-4F4D-B41F-969FA1E8F891--