859867 - Need to check out one of the new linux hardware slaves to troubleshoot B2G emulator problems

Status: RESOLVED FIXED

(Infrastructure & Operations Graveyard :: CIDuty, task)

Description

[Jonathan Griffin (:jgriffin)]

The new Ubuntu 12.04 hardware slaves do not cooperate with B2G tests:  https://tbpl.mozilla.org/?tree=Cedar&jobname=b2g_ics_armv7a_gecko_emulator_hw

The logs show that the emulator is failing to start.  I'll need to check out one of these new machines in order to figure out what's going on.

Comment 1

[Kim Moir [:kmoir] ET]

talos-linux64-ix-004.test.releng.scl3.mozilla.com has been allocated for this purpose, I'll send you the information on how to connect.

Comment 2

[Jonathan Griffin (:jgriffin)]

So basically the problem on these slaves has something to do with compiz.  When I logged into this slave, and tried to launch the emulator, it just hung hard.  I noticed that compiz was taking 100% of 1 core.

After I killed the emulator, and killed compiz (which caused it to be automatically restarted), I could launch and kill the emulator successfully as many times as I wanted to, and compiz stayed at a reasonable CPU consumption (< 30%).

So either the window manager/Xorg is in some bad state initially, or attempting to launch the emulator puts it in a bad state initially, but killing compiz is enough to "fix" it.

I don't really know how to troubleshoot it beyond this, not being an expert at linux window manager configs.

Comment 3

[Jonathan Griffin (:jgriffin)]

This sounds potentially relevant:

https://bugs.launchpad.net/ubuntu/+source/compiz/+bug/995118

Are the slaves configured as the default, to blank the screen after X seconds of inactivity?

Comment 4

[Jonathan Griffin (:jgriffin)]

Also see:

https://bugs.launchpad.net/ubuntu/+source/compiz/+bug/969860/comments/96

Comment 5

[Rail Aliiev [:rail]]

(In reply to Jonathan Griffin (:jgriffin) from comment #3)
> This sounds potentially relevant:
> 
> https://bugs.launchpad.net/ubuntu/+source/compiz/+bug/995118
> 
> Are the slaves configured as the default, to blank the screen after X
> seconds of inactivity?

No, we disable that in 
http://hg.mozilla.org/build/puppet/file/6355249ba9a5/modules/gui/files/gsettings.gschema.override

Comment 6

[Jonathan Griffin (:jgriffin)]

Logging into this VM later, compiz isn't running at all.  :(

Comment 7

[Rail Aliiev [:rail]]

(In reply to Jonathan Griffin (:jgriffin) from comment #6)
> Logging into this VM later, compiz isn't running at all.  :(

Can you try now? It turns out that some of the loaning steps are not documented properly for this platform yet...

Comment 8

[Chris Cooper [:coop] (he/him)]

jgriffin: did you successfully get access to this machine?

Comment 9

[Jonathan Griffin (:jgriffin)]

(In reply to Chris Cooper [:coop] from comment #8)
> jgriffin: did you successfully get access to this machine?

I did, and compiz was running again, and the emulator behaved fine.  The only time I had any problems was the very first time I launched the emulator, at which point compiz got stuck at 100% cpu and the emulator hung.

It might be worthwhile rebooting this VM (I can't do it since I don't have sudo) and see if the problem recurs.

Comment 10

[Rail Aliiev [:rail]]

I rebooted the machine. BTW, "sudo reboot" is allowed for cltbld.

Comment 11

[Jonathan Griffin (:jgriffin)]

I have still not been able to reproduce this problem, except for the very first time I attempted.  After a reboot, the tests still function normally.  Is it possible compiz gets in a weird state somehow when the test slave is first connected to buildbot?

The only things I can think of to help debug this are:

1] - add some output to the mozharness script to dump the process list, to see if these are all cases caused by compiz misbehaving (something like ps -eo pcpu,pid,user,args | sort -k 1 -r | head -10)

2] - add some debugging output to Marionette on cedar to see if the emulator is dumping any error messages to stdout that we're not seeing

Comment 12

[Jonathan Griffin (:jgriffin)]

I've just added some 'ps' logging to mozharness for this, and I've also bumped the emulator launch timeout on cedar from 60s to 180s.  We'll see if either of these give us more info.

Comment 13

[Jonathan Griffin (:jgriffin)]

emulator launch timeout increased:  https://hg.mozilla.org/projects/cedar/rev/f48348119595

Comment 14

[Jonathan Griffin (:jgriffin)]

(In reply to Jonathan Griffin (:jgriffin) from comment #12)
> I've just added some 'ps' logging to mozharness for this, and I've also
> bumped the emulator launch timeout on cedar from 60s to 180s.  We'll see if
> either of these give us more info.

This shows that compiz doesn't seem to be the problem:

16:57:55     INFO - %CPU   PID USER     COMMAND
16:57:55     INFO -  1.5  2655 cltbld   /tools/buildbot/bin/python scripts/scripts/b2g_emulator_unittest.py --cfg b2g/emulator_automation_config.py --test-suite crashtest --this-chunk 3 --total-chunks 3 --download-symbols true
16:57:55     INFO -  0.5  2658 root     [flush-8:0]
16:57:55     INFO -  0.4  1117 root     [kipmi0]
16:57:55     INFO -  0.1  2335 cltbld   compiz
16:57:55     INFO -  0.1  1921 root     X :0 -nolisten tcp
16:57:55     INFO -  0.0  2764 cltbld   ps -eo pcpu,pid,user,args
16:57:55     INFO -  0.0  2640 cltbld   /usr/lib/deja-dup/deja-dup/deja-dup-monitor
16:57:55     INFO -  0.0  2633 cltbld   /usr/bin/python /usr/lib/unity-scope-video-remote/unity-scope-video-remote
16:57:55     INFO -  0.0  2605 cltbld   /usr/lib/unity-lens-music/unity-musicstore-daemon

Comment 15

[Jonathan Griffin (:jgriffin)]

(In reply to Jonathan Griffin (:jgriffin) from comment #13)
> emulator launch timeout increased: 
> https://hg.mozilla.org/projects/cedar/rev/f48348119595

Increasing the timeout didn't help.

Comment 16

[Jonathan Griffin (:jgriffin)]

Added some more debugging output to cedar: https://hg.mozilla.org/projects/cedar/rev/8d27a357c892

Comment 17

[Jonathan Griffin (:jgriffin)]

(In reply to Jonathan Griffin (:jgriffin) from comment #16)
> Added some more debugging output to cedar:
> https://hg.mozilla.org/projects/cedar/rev/8d27a357c892

No help here either.

I have to assume this has something to do with a difference in how we're starting a session.  I'm using ssh to the console, and then invoking the emulator from there.  Buildbot seems to be using a remote X session; but I can't quite tell what it's doing.  :rail, can you describe how buildbot invokes commands on the slave?

Comment 18

[Jonathan Griffin (:jgriffin)]

:rail, can you explain how buildbot connects to and invokes commands on the slave?  It seems like it's setting up a remote X session, but I'd like to know how exactly, so I can try to reproduce that way.

Comment 19

[Rail Aliiev [:rail]]

Buildbot (buildslave actually) starts from a running X session: Unity starts ~/.config/autostart/gnome-terminal.desktop which starts gnome-terminal, which runs runslave.py (it talks to slavealloc and download buildbot startup file). So, basically buildbot inherits all variables from existing X sessions.

See also:
http://hg.mozilla.org/build/puppet/file/e6e380e85cb1/modules/buildslave/manifests/startup/desktop.pp#l16
http://hg.mozilla.org/build/puppet/file/e6e380e85cb1/modules/buildslave/templates/gnome-terminal.desktop.erb
http://hg.mozilla.org/build/puppet/file/e6e380e85cb1/modules/buildslave/files/runslave.py

The best way to reproduce the existing environment would be VNCing and running gnome-terminal.

Let me know (or ping on IRC) if you need more details.

Comment 20

[Jonathan Griffin (:jgriffin)]

I did just that and the problem still doesn't reproduce.  Are there any other differences in how buildbot uses/configures the slave that could be relevant?

Comment 21

[Rail Aliiev [:rail]]

jgrifin, did you try to reproduce the steps from the logs, including the same environment variables? We can try to reproduce this together, maybe I'll have some ideas...

Comment 22

[Jonathan Griffin (:jgriffin)]

Yes, I did set all the same environment variables, at least the ones that made sense.  If you want to try and reproduce it together, ping me on irc.

Comment 23

[Rail Aliiev [:rail]]

I managed to reproduce the issue mentioned in comment 2 (compiz eating 100% of CPU).

I straced the compiz process and it was trying to sched_yiled() in loop.

I think, the problem is the nvidia driver's default OpenGL yield behavior, which uses sched_yiled().

We can change this behaviour by setting __GL_YIELD env variable to "NOTHING" or "USLEEP". I tried both and they worked. 

I'll try to reproduce the same on the slave loaned to jgriffin.

Comment 24

[Jonathan Griffin (:jgriffin)]

I couldn't repro this on my slave (even after reboot), but it sounds like the problem.  Can we add this env variable to the slave config and see if it fixes this?

Comment 25

[Rail Aliiev [:rail]]

I would prefer to set this variable from mozharness to avoid possible issues with desktop Talos tests. I'll prep a patch.

Comment 26

[Rail Aliiev [:rail]]

Attachment: mozharness env

Comment 27

[Aki Sasaki (not active)]

Comment on attachment 746956 [details] [diff] [review]
mozharness env

I'm going to guess this line needs changing to

env = self.config.get('env', {})

http://hg.mozilla.org/build/mozharness/file/1287327b0f15/scripts/b2g_emulator_unittest.py#l351

Comment 28

[Rail Aliiev [:rail]]

Comment on attachment 746956 [details] [diff] [review]
mozharness env

(In reply to Aki Sasaki [:aki] from comment #27)
> Comment on attachment 746956 [details] [diff] [review]
> mozharness env
> 
> I'm going to guess this line needs changing to
> 
> env = self.config.get('env', {})
> 
> http://hg.mozilla.org/build/mozharness/file/1287327b0f15/scripts/
> b2g_emulator_unittest.py#l351

Ah, I missed that point. https://hg.mozilla.org/build/mozharness/rev/f08c264808e7

Comment 29

[Rail Aliiev [:rail]]

I backed out this patch because it didn't really help. It turns out that the bug is not 100% reproducible. Sometimes compiz behaves correctly, sometimes not. To make it work properly we need to set the variable *before* compiz starts, as a part of X start up. This change may affect desktop Talos results and requires some testing before we land it to all machines. Patch for puppet incoming.

Comment 30

[Rail Aliiev [:rail]]

Attachment: puppet

I' not going to deploy the patch before we test Talos.

Comment 31

[Dustin J. Mitchell [:dustin] (he/him)]

Comment on attachment 747431 [details] [diff] [review]
puppet

Review of attachment 747431 [details] [diff] [review]:
-----------------------------------------------------------------

::: modules/gui/manifests/init.pp
@@ +65,5 @@
>                  "/etc/X11/edid.bin":
>                      source => "puppet:///modules/${module_name}/edid.bin";
> +                "/etc/X11/Xsession.d/98nvidia":
> +                    content => "export __GL_YIELD=NOTHING\n",
> +                    notify => Service['x11'];

This should *definitely* have a comment with a brief explanation and pointing to this bug :)

Fine with that change.

Comment 32

[Rail Aliiev [:rail]]

Comment on attachment 747431 [details] [diff] [review]
puppet

https://hg.mozilla.org/build/puppet/rev/3ea4d1800d7c

Comment 33

[Jonathan Griffin (:jgriffin)]

I don't think there's any need for this slave any longer; rail, let me know if there's anything left for me to do.

Comment 34

[Rail Aliiev [:rail]]

I filed bug 895425 to reimage the machine.