Cleaned again jenkins-3 on integration-slave-trusty-1016.eqiad.wmflabs.

So seems mwext-Wikibase-qunit does a few curl requests to the web host before the tmpfs directory had a change to be created by jenkins-bot and chmod 777 happen.

The dir is usually created by global-setup.sh but it is invoked after the curl requests. The build flow from JJB definition:

zuul-cloner
composer
mw-install-sqlite
apply setting functions
update

Then we invoke qunit-karma which does:

• prepare-localhost
  • source mw-set-env-localhost.sh
    • Inject conf in LocalSettings.php
    • ln -s workspace /srv/localhost/..
    • curl Special:BlankPage
    • curl /load.php?debug=true&modules=startup&only=scripts

At this point the tmpfs dir has not been created / made 777. I believe one of the curl command ends up triggering the LocalizationCache which fallback its cache dir to TMPDIR (which is set) and does a wfMkdirParents(). Thus the dir would belong to www-data

Then the flow continue:

• some inline shell:
  • source mw-set-env-localhost.sh
  • source npm-setup.sh
    • source global-setup.sh
      • source global-set-env.sh
        • export TMPDIR=/mnt/home/jenkins-deploy/tmpfs/jenkins-3
      • mkdir -p "$TMPDIR"
      • chmod 777 "$TMPDIR"

At this point the command fails because $TMPDIR belongs to www-data

• grunt karma:main

At the end of the build we invoke:

• mw-teardown.sh
  • source global-teardown.sh
    • source global-set-env.sh
      • export TMPDIR=/mnt/home/jenkins-deploy/tmpfs/jenkins-3
    • rm -rf "$TMPDIR"

Which would fail as well.

So in short, we need to ensure prepare-localhost calls global-setup.sh before the curl queries are conducted.

If the problem is in mwext-Wikibase-qunit but not in mwext-qunit-composer, the first can just be replaced by the later.

Seems mwext-Wikibase-qunit has the issue. I haven't looked at mwext-qunit-composer though but it might well suffer from the same issue (i.e. prepare-localhost called before global-setup.sh is invoked to create it).

mwext-Wikibase-qunit has some specific macro to inject Wikibase related settings in LocalSettings.php. But maybe it is no more needed?

Yea all qunit jobs have that problem as they all use the qunit-karma macro.

In T120824#1865542, @hashar wrote:

So seems mwext-Wikibase-qunit does a few curl requests to the web host before the tmpfs directory had a change to be created by jenkins-bot and chmod 777 happen.

The dir is usually created by global-setup.sh but it is invoked after the curl requests. The build flow from JJB definition:

That's incorrect. global-setup.sh is already run much earlier as part of mw-install-sqlite. The flow is as follows.

• wikidata.yaml#mwext-{ext-name}-qunit
  • zuul-cloner-extdeps
  • wd-mw-composer-merged-install
  • mw-install-sqlite. This runs mw-setup.sh which includes global-setup.sh and chmod 777
  • ...
  • qunit-karma

The problem has nothing to do with the macro order. That's been fine and working for over a year without issues. If that were the problem, it also wouldn't be a race condition.

As stated in the opening post, the problem is unrelated to the commands being executed. It is not failing on curl or php, it is failing in the actual script that sets and created the temporary directory.

That script is failing because the directory already exists and contains files from a previous build that used the same job executor number. So there is a regression in our Jenkins jobs that is causing some jobs to not clean up their temporary directory before Jenkins slave starts a new build in the same executor.

outdated comment

Change 258140 had a related patch set uploaded (by JanZerebecki):
Work around race condition in TMPDIR creation/cleanup

https://gerrit.wikimedia.org/r/258140

Even if it is true that post-build runs concurrent with the next build (which I can't reproduce yet), why would that cause chmod problems? The creator of the directory is the same as the one cleaning it up in this case. Shouldn't be a problem.

Change 258140 abandoned by JanZerebecki:
Avoid race condition with EXECUTOR_NUMBER for TMPDIR

https://gerrit.wikimedia.org/r/258140

I misunderstood your comment T120824#1865989 .

I just marked integration-slave-trusty-1011 as offline because all jobs on it were failing.

I have put integration-slave-trusty-1011 after deleting all the tmpfs leftover files with:

salt --show-timeout '*slave*' cmd.run 'rm -fR /mnt/home/jenkins-deploy/tmpfs/jenkins-?/*'

Random thoughts from this morning

To follow up on @JanZerebecki , the post build action do block the build and keep the executor busy until completion. So there are never two builds running concurrently on the same executor.

With the hypothesis that our job always have the tmp dir created very early and belonging to jenkins-deploy with mode 777, when the Apache running process creates material in the directory jenkins-deploy would be able to delete them since it own the dir. Eg:

# Create jenkins-deploy  tmp dir
$ sudo -u jenkins-deploy mkdir /tmp/bla
$ sudo -u jenkins-deploy chmod 777 /tmp/bla

# Create a file as Apache user
$ sudo -u www-data touch /tmp/bla/www-data.txt

# Result
$ ls -ld /tmp/bla
drwxrwxrwx 2 jenkins-deploy root 4096 Dec 11 11:50 bla/
$ ls -l /tmp/bla
-rw-r--r-- 1 www-data       www-data 0 Dec 11 11:50 www-data.txt

# Deletion works:
$ rm -v -fR /tmp/bla
removed ‘/tmp/bla/www-data.txt’
removed directory: ‘/tmp/bla/’
$

What we can see is the temp directory belong to www-data. That is why I supposed the curl to Special:Blankpage is creating it and global-setup.sh was missing. But Timo confirmed it is run (the call doesn't show up in the console because the invoking script has set +x).

So under the hypothesis the jobs always create the tmp dir has jenkins-deploy, how do we explain it to be magically owned by www-data?

$ ls -ld /mnt/home/jenkins-deploy/tmpfs/jenkins-0
drwxr-xr-x 2 www-data www-data 60 Dec  9 10:47 /mnt/home/jenkins-deploy/tmpfs/jenkins-0

Timo is right that it all worked fine until now. A change I made recently was to point the LocalizationCache to use the tmpfs directory instead of the shared /tmp (subject to race condition between jobs).

That leads me to suspect the LocalizationCache code chown the cache destination, but there are no chmod() calls in MediaWiki core. The cache does initialize the directory though with:

if ( !file_exists( $this->directory ) ) {
     if ( !wfMkdirParents( $this->directory, null, __METHOD__ ) ) {

On gallium I have looked for mediawiki-* jobs having:

rm: cannot remove ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-1/lessphp_2116pao1z3hcc88400gc04so40ogcc8.lesscache’: Permission denied

I used grep -lR 2116pao1z3hcc8840 /var/lib/jenkins/jobs/mediawiki-* did some sorting:

Dec 11 07:36 mediawiki-extensions-qunit/builds/22834/log
Dec 11 08:27 mediawiki-extensions-qunit/builds/22835/log
Dec 11 09:31 mediawiki-phpunit-hhvm/builds/20611/log
Dec 11 09:48 mediawiki-core-qunit/builds/55051/log
Dec 11 09:59 mediawiki-extensions-qunit/builds/22838/log
Dec 11 10:30 mediawiki-phpunit-hhvm/builds/20614/log

I got the whole history of builds from /var/log/jenkins/jenkins.log and jenkins.log.1:

Note the _exec# suffix is the Gearman worker, it is most probably different from Jenkins own EXECUTOR_NUMBER.

One of the job behind must have created the tmpdir as www-data.

Based on previous comment forensic, I have looked back at an issue reported earlier:

integration-slave-trusty-1011 Dec 9 10:47 /mnt/home/jenkins-deploy/tmpfs/jenkins-0

https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/42276/ failed with:

10:48:13 chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’: Operation not permitted

https://integration.wikimedia.org/ci/job/mwext-mw-selenium/2375/ has been canceled at 10:47:31 and has some interesting stuff:

It does invoke mw-install-mysql.sh then mw-apply-settings.sh which reports:

10:41:24 Setting $wgTmpDirectory = '/mnt/home/jenkins-deploy/tmpfs/jenkins-0';

Later export TMPDIR=/mnt/home/jenkins-deploy/tmpfs/jenkins-0

So far all good. Then we invoke the selenium test runner which has export SKIP_TMPFS=1 and thus export TMPDIR=/tmp/jenkins-0 and export MW_TMPDIR=/tmp/jenkins-0.

The browser tests are then run. The trick is that LocalSettings.php still has:

$wgTmpDirectory = '/mnt/home/jenkins-deploy/tmpfs/jenkins-0';

And looking at the mw-debug-www.log I got:

0.1305  11.8M  LocalisationCache::recache: got localisation for en from source
0.1749  15.0M  LCStoreCDB::startWrite: called wfMkdirParents(/mnt/home/jenkins-deploy/tmpfs/jenkins-0)
0.2786  17.2M  IP: 127.0.0.1

So it is definitely the LocalisationCache creating the directory via www-data. What I do not get, is why /mnt/home/jenkins-deploy/tmpfs/jenkins-0 is apparently not created previously :(

Change 258450 had a related patch set uploaded (by Hashar):
Point l10n cache to a subdirectory

https://gerrit.wikimedia.org/r/258450

Been running mwext-mw-selenium while watching for files belonging to www-data with:

while true; do date; salt --show-timeout '*slave-trusty-1013*' cmd.run 'find /mnt/home/jenkins-deploy/tmpfs -user www-data -not -name "*lesscache" '; sleep 1; done;

Only yields:

/mnt/home/jenkins-deploy/tmpfs/jenkins-0/l10n_cache-en.cdb

The .lesscache do belong to www-data as well.

So I have been digging into it more and I am out of idea. I can't even think of a good way to detect a job is actually doing the change :-\

Random notes from evening digging, probably not worth reading

Bunch of console logs having rm: cannot remove

$ find mediawiki* mwext-mw-selenium* -type f -name log -exec grep -l 'rm: cannot remove' {} \;
mediawiki-core-jsduck-publish/builds/5190/log
mediawiki-core-npm/builds/8187/log
mediawiki-core-qunit/builds/55051/log
mediawiki-core-qunit/builds/54941/log
mediawiki-extensions-hhvm/builds/42242/log
mediawiki-extensions-hhvm/builds/42285/log
mediawiki-extensions-hhvm/builds/42477/log
mediawiki-extensions-hhvm/builds/42564/log
mediawiki-extensions-hhvm/builds/42276/log
mediawiki-extensions-qunit/builds/22837/log
mediawiki-extensions-qunit/builds/22838/log
mediawiki-extensions-qunit/builds/22844/log
mediawiki-extensions-qunit/builds/22565/log
mediawiki-extensions-qunit/builds/22567/log
mediawiki-extensions-qunit/builds/22849/log
mediawiki-extensions-qunit/builds/22440/log
mediawiki-extensions-qunit/builds/22834/log
mediawiki-extensions-qunit/builds/22835/log
mediawiki-extensions-qunit/builds/22839/log
mediawiki-phpunit-hhvm/builds/20613/log
mediawiki-phpunit-hhvm/builds/20611/log
mediawiki-phpunit-hhvm/builds/20614/log
mediawiki-phpunit-hhvm-composer/builds/1565/log
mwext-mw-selenium-composer/builds/211/log
mwext-mw-selenium-composer/builds/278/log
mwext-mw-selenium-composer/builds/212/log
mwext-mw-selenium-composer/builds/279/log
mwext-mw-selenium-composer/builds/275/log
mwext-mw-selenium-composer/builds/221/log
mwext-mw-selenium-composer/builds/193/log
mwext-mw-selenium-composer/builds/215/log
mwext-mw-selenium-composer/builds/289/log
mwext-mw-selenium-composer/builds/276/log

The earliest record is https://integration.wikimedia.org/ci/job/mediawiki-extensions-qunit/22440/ which triggered the creation of this task.

14:15:32 chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-2’: Operation not permitted

Then looking at Wikibase builds with find mwext-Wikibase-* -type f -name log -exec grep -l 'rm: cannot remove' {} \;

mwext-Wikibase-client-tests-mysql-hhvm/builds/6963/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/7067/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/6960/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/6992/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/6989/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/7004/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/7061/log
mwext-Wikibase-client-tests-mysql-hhvm/builds/7062/log
mwext-Wikibase-client-tests-sqlite-hhvm/builds/6997/log
mwext-Wikibase-client-tests-sqlite-hhvm/builds/6449/log
mwext-Wikibase-client-tests-sqlite-hhvm/builds/7069/log
mwext-Wikibase-client-tests-sqlite-hhvm/builds/6993/log
mwext-Wikibase-client-tests-sqlite-hhvm/builds/7054/log
mwext-Wikibase-qunit/builds/15848/log
mwext-Wikibase-qunit/builds/15777/log
mwext-Wikibase-qunit/builds/15775/log
mwext-Wikibase-qunit/builds/15778/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7067/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7011/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7069/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7080/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7000/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/6982/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7063/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7064/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/7077/log
mwext-Wikibase-repo-tests-mysql-hhvm/builds/6968/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6997/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/7067/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6984/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6988/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6959/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/7063/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6986/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6972/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6996/log
mwext-Wikibase-repo-tests-sqlite-hhvm/builds/7062/log

The earliest from Dec 8 ~14:00 UTC are:

rw-rw-r-- 1 jenkins jenkins 226916 Dec  8 14:12 mwext-Wikibase-client-tests-mysql-hhvm/builds/6963/log
-rw-rw-r-- 1 jenkins jenkins 236782 Dec  8 14:11 mwext-Wikibase-repo-tests-mysql-hhvm/builds/6968/log
-rw-rw-r-- 1 jenkins jenkins 236722 Dec  8 14:09 mwext-Wikibase-repo-tests-sqlite-hhvm/builds/6959/log
-rw-rw-r-- 1 jenkins jenkins 226981 Dec  8 14:04 mwext-Wikibase-client-tests-mysql-hhvm/builds/6960/log

The last four Wikibase builds ran on integration-slave-trusty-1012 on Dec 8 around 14:00 UTC and all fail during mw-install-mysql.sh with:

chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-2’: Operation not permitted

Gotta find a build that ran before that on that slave and executor 2 :(

Found the sequence of three jobs running on slave-trusty-1012 executor #2 by grepping jenkins.log

The npm job did global-teardown.sh in PostBuild step properly which suggest there are no tmpfs files belonging to www-data.

The 3rd job (mwext-Wikibase-repo-tests-sqlite-hhvm) dies during build at mw-install-sqlite.sh

14:09:13 chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-2’: Operation not permitted

That is an entire mystery to me.

Change 258450 abandoned by Hashar:
Point l10n cache to a subdirectory

Reason:
That is probably NOT going to fix it.

https://gerrit.wikimedia.org/r/258450

In T120824#1873097, @hashar wrote:

So far all good. Then we invoke the selenium test runner which has export SKIP_TMPFS=1 and thus export TMPDIR=/tmp/jenkins-0 and export MW_TMPDIR=/tmp/jenkins-0.

The browser tests are then run. The trick is that LocalSettings.php still has:

$wgTmpDirectory = '/mnt/home/jenkins-deploy/tmpfs/jenkins-0';

And looking at the mw-debug-www.log I got:

0.1305  11.8M  LocalisationCache::recache: got localisation for en from source
0.1749  15.0M  LCStoreCDB::startWrite: called wfMkdirParents(/mnt/home/jenkins-deploy/tmpfs/jenkins-0)
0.2786  17.2M  IP: 127.0.0.1

So it is definitely the LocalisationCache creating the directory via www-data. What I do not get, is why /mnt/home/jenkins-deploy/tmpfs/jenkins-0 is apparently not created previously :(

No idea either, but that means there is a bug that one of the directories does not get deleted.

Change 258634 had a related patch set uploaded (by JanZerebecki):
Don't leave one of the TMPDIRs around when it is switched inbetween

https://gerrit.wikimedia.org/r/258634

FWIW, just happened again on integration-slave-trusty-1016, removing the tmpfs/*.lesscache files.

https://integration.wikimedia.org/ci/job/npm/42014/console

Still happening, https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/42958/console for https://gerrit.wikimedia.org/r/#/c/258729/

+ /srv/deployment/integration/slave-scripts/bin/mw-install-mysql.sh
chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-3’: Operation not permitted
Build step 'Execute shell' marked build as failure

Change 258634 merged by jenkins-bot:
Create both possible TMPDIR so they belong to jenkins-deploy

https://gerrit.wikimedia.org/r/258634

I just marked integration-slave-trusty-1012 and integration-slave-trusty-1014 as offline for now due to this.

This issue is still happening despite https://gerrit.wikimedia.org/r/#/c/258634/ :(

Change 260007 had a related patch set uploaded (by Hashar):
Dump stat() for tmp directory

https://gerrit.wikimedia.org/r/260007

Change 260007 merged by jenkins-bot:
Dump stat() for tmp directory

https://gerrit.wikimedia.org/r/260007

Change 260008 had a related patch set uploaded (by Hashar):
Tie mwext-mw-selenium* jobs to specific slaves

https://gerrit.wikimedia.org/r/260008

Change 260008 merged by jenkins-bot:
Tie mwext-mw-selenium* jobs to specific slaves

https://gerrit.wikimedia.org/r/260008

ArticlePlaceholder has mwext-mw-selenium-composer in the experimental pipeline. I crafted dummy change https://gerrit.wikimedia.org/r/#/c/260009/ to be able to trigger via Zuul easily.

Looks like this or something similar is happening again:

[13:17]	RoanKattouw	Hey folks, looks like there are CI issues?
[13:17]	RoanKattouw	Lost of things are getting V-1ed because one of the jobs hits a permissions error
[13:17]	RoanKattouw	e.g. https://integration.wikimedia.org/ci/job/npm/42776/console
[13:17]	RoanKattouw	21:12:56 chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’: Operation not permitted
[13:17]	RoanKattouw	21:12:56 rm: cannot remove ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0/lessphp_805a13p17e8skww04swww4s0w48w00w.lesscache’: Permission denied
[13:17]	RoanKattouw	21:12:56 rm: cannot remove ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0/lessphp_h8b1csvw54gs4gwk0o4kgkww044040w.lesscache’: Permission denied
[13:18]	RoanKattouw	or https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/43610/console
[13:18]	RoanKattouw	What's weird is it's not every job all the time, but at least one job for most commits
[13:18]	RoanKattouw	So maybe some servers are broken and others are OK?

I just executed what is explained in the description, so it should be work again for a while.

Roan mentioned https://integration.wikimedia.org/ci/job/npm/42776/ which ran on executor 0 of integration-slave-trusty-1014. Since I earlier tied the mwext-mw-selenium jobs to different slaves, that means they are innocent.

The stat calls on each tmp directory I added show on https://integration.wikimedia.org/ci/job/npm/42776/

21:12:56 +++ stat /mnt/home/jenkins-deploy/tmpfs/jenkins-0
21:12:56   File: ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’
21:12:56   Size: 80        	Blocks: 0          IO Block: 4096   directory
21:12:56 Device: 18h/24d	Inode: 313437908   Links: 2
21:12:56 Access: (0755/drwxr-xr-x)  Uid: (   33/www-data)   Gid: (   33/www-data)
21:12:56 Access: 2015-12-18 20:51:37.791584293 +0000
21:12:56 Modify: 2015-12-18 20:51:37.899584276 +0000
21:12:56 Change: 2015-12-18 20:51:37.899584276 +0000
21:12:56  Birth: -
21:12:56 +++ stat /tmp/jenkins-0
21:12:56   File: ‘/tmp/jenkins-0’
21:12:56   Size: 4096      	Blocks: 8          IO Block: 4096   directory
21:12:56 Device: fd01h/64769d	Inode: 5370        Links: 2
21:12:56 Access: (0755/drwxr-xr-x)  Uid: ( 2947/jenkins-deploy)   Gid: (  500/ wikidev)
21:12:56 Access: 2015-12-18 20:52:46.967573517 +0000
21:12:56 Modify: 2015-12-18 20:52:46.967573517 +0000
21:12:56 Change: 2015-12-18 20:52:46.967573517 +0000
21:12:56  Birth: -
21:12:56 +++ mkdir -p /mnt/home/jenkins-deploy/tmpfs/jenkins-0
21:12:56 +++ mkdir -p /tmp/jenkins-0
21:12:56 +++ chmod 777 /mnt/home/jenkins-deploy/tmpfs/jenkins-0
21:12:56 chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’: Operation not permitted

Gotta hunt the job that ran at 20:51:37 UTC.

From gallium /var/log/jenkins/jenkins.log and some manual filtering, here are the job starts on slave-trusty-1014

Note the exec-# does not seem to correspond to the EXECUTOR_NUMBER Jenkins env variable but is assigned by the Gearman plugin.

So the build order show:

https://integration.wikimedia.org/ci/job/mediawiki-extensions-qunit/23883 which got cancelled by Zuul and shows a karma error at 20:51:37 !!

The next build is https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/43608 , at 20:52:46 the stat calls show:

File: ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’
Access: (0755/drwxr-xr-x)  Uid: (   33/www-data)   Gid: (   33/www-data)
Access: 2015-12-18 20:51:37.791584293 +0000

stat: cannot stat ‘/tmp/jenkins-0’: No such file or directory

chmod: changing permissions of ‘/mnt/home/jenkins-deploy/tmpfs/jenkins-0’: Operation not permitted

What I don't get is the qunit build before executes mw-teardown-mysql.sh as a post build script and it should delete both temp dir via global-teardown.sh which does:

. global-set-env.sh
rm -rf "${TMPDIR_FS}"
rm -rf "${TMPDIR_REGULAR}"

Change 260098 had a related patch set uploaded (by Hashar):
global-teardown: be more verbose

https://gerrit.wikimedia.org/r/260098

Change 260098 merged by jenkins-bot:
global-teardown: be more verbose

https://gerrit.wikimedia.org/r/260098

From IRC with @hashar, timestamps in PST (TL;DR: parallelism killed Kenny):

14:43 marxarelli: hashar: is it possible that some request to an hhvm process wouldn't be entirely complete before a job is finished?
14:43 marxarelli: and result in something being written to a temporary file
14:43 hashar: ohhhhhh
14:44 marxarelli: after the teardown script has run, etc.
14:44 hashar: yup that would explain it
14:44 marxarelli: it seems we should probably set MW's tmpdir to somewhere different
14:44 hashar: the qunit jobs often fails because of an ajax timeout
14:45 hashar: so the karma runner does hit hhvm
14:45 hashar: timeout for some reason or the job get canceled
14:46 hashar: post build run
14:46 marxarelli: it's the only way to explain the www-data ownership
14:46 hashar: and hhvm continue running the system
14:46 marxarelli: right
14:46 hashar: yeah
14:46 hashar: given Zuul cancel jobs
14:46 hashar: and Jenkins probably kill -9 every sub process
14:47 hashar: I am not sure how we can have post build watch / wait till hhvm finished
14:47 marxarelli: right, but not hhvm (for good reason)
14:47 marxarelli: i'm not sure we need to, really
14:47 marxarelli: we just need to make sure that hhvm/MW processes write to their own tmpdir
14:47 hashar: or instead of deleting the directory we can delete the files underneath? This way the dir still belong to jenkins-deploy
14:48 marxarelli: one that's cleaned up perdiocally, but outside the scope of each job
14:48 hashar: oh
14:48 hashar: but that needs to be scoped per job :(
14:48 marxarelli: if we leave the tmpdir as owned by jenkins-deploy, and hhvm tries to write to it, it will bork
14:48 marxarelli: right? what's the mode?
14:49 hashar: it is 777
14:49 marxarelli: ah, ok
14:49 marxarelli: so that might work
14:49 hashar: we did that because MediaWiki under hhvm does write to the cache dir
14:49 marxarelli: i kind of think the cleanup schedule should mirror the process(es) lifespan though
14:49 hashar: and the process has no idea of the job context
14:49 marxarelli: hhvm processes are long running and separate from job processes themselves
14:50 hashar: or we can namespace tmpdirs based on jenkins context again
14:51 hashar: i.e. using the job/build number or some hash of it
14:51 marxarelli: yeah, but apache/hhvm isnt' being run by jenkins
14:51 marxarelli: i don't think it necessarily needs it's tmpdir scoped to the executors that run against it
14:52 hashar: we can inject it via the mediawiki.d which would set  $wgTmpDirectory = getenv('TMPDIR') / getenv('BUILD_TAG')
14:52 marxarelli: we just need to ensure that something is triggered or run periodically to clean up hhvm temp files
14:54 marxarelli: hashar: we _could_ have some hhvm maintenance endpoint that's requested when jobs complete
14:54 marxarelli: and let it clean up its own shite, as www-data
14:55 marxarelli: hashar: it would have to be a sync operation to avoid race conditions
14:56 hashar: marxarelli: so embedded in hhvm ?
14:57 marxarelli: hashar: i.e. assign MW's tmpdir to /whatever/jenkins-0/hhvm, and at the end of the job, request http://127.0.0.1/jenkins/cleanup.php?dir=/whatever/jenkins-0/hhvm
14:57 marxarelli: or some other wacky shit like that :)
14:58 hashar: but you can still have a long running process standing bye
14:58 hashar: by
14:58 marxarelli: hashar: grr...
14:58 marxarelli: you're right :)
14:58 hashar: maybe we could use the hhvm console to list threads  based on some info they might have
14:59 hashar: maybe apache pass the virtual host to it
14:59 marxarelli: `while lsof +D /tmp/jenkins-0; sleep` :)
14:59 hashar: and the vhost has the job name + build #
14:59 hashar: ahaha
15:00 hashar: marxarelli: would you mind summarizing your suggestion at https://phabricator.wikimedia.org/T120824 ?  I don't want to steal your finding :-}
15:00 marxarelli: hashar: sure. mind if i just copy/paste?
15:00 hashar: yeah
15:00 hashar: will be fine

Change 260174 had a related patch set uploaded (by JanZerebecki):
Workaround for tmpdir being created with a different user

https://gerrit.wikimedia.org/r/260174

I have adjusted the task description for magic command to delete www-data files:

salt -v '*slave*' cmd.run 'find /mnt/home/jenkins-deploy/tmpfs -user www-data -mmin +10 -delete'

Change 260174 merged by jenkins-bot:
Workaround for tmpdir being created with a different user

https://gerrit.wikimedia.org/r/260174

Change 260335 had a related patch set uploaded (by Hashar):
Revert "Tie mwext-mw-selenium* jobs to specific slaves"

https://gerrit.wikimedia.org/r/260335

Change 260335 merged by jenkins-bot:
Revert "Tie mwext-mw-selenium* jobs to specific slaves"

https://gerrit.wikimedia.org/r/260335

Following the discussion on Friday evening with Dan, the workaround would be to only delete files under the directories and leave the dir behind. This way it is still owned by jenkins-deploy user. That is what Jan patch https://gerrit.wikimedia.org/r/260174 does and its deployed.

Leaving the task open though until we are sure the issue is probably solved.

Change 260407 had a related patch set uploaded (by Dduvall):
Fix globs in global and mw-selenium teardown scripts

https://gerrit.wikimedia.org/r/260407

Change 260407 merged by jenkins-bot:
Fix globs in global and mw-selenium teardown scripts

https://gerrit.wikimedia.org/r/260407

@dduvall Thank you! I noticed some left over before our weekly meeting and checked again a minute or so ago there was nothing left. Looks like it did it. Been verifying with:

salt -v '*slave*' cmd.run 'find /mnt/home/jenkins-deploy/tmpfs -user www-data -mmin +10'

Change 260545 had a related patch set uploaded (by Hashar):
Remove debugging statements related to TMPDIR

https://gerrit.wikimedia.org/r/260545

Change 260545 merged by jenkins-bot:
Remove debugging statements related to TMPDIR

https://gerrit.wikimedia.org/r/260545