What could it be wait4ing for?

In T191921#4121932, @mmodell wrote:

What could it be wait4ing for?

Probably a red herring in this instance. There are 7 wait4 calls and there are 3 errors. There are 4 subprocesses that get start started as a result of the mwscript command. So 4 wait4 calls where there were actual child processes waiting on the 4 subprocesses. One of those wait4 calls was waiting on:

execve("/usr/bin/php", ["php", "/srv/mediawiki-staging/multiversion/MWScript.php", "rebuildLocalisationCache.php", "--wiki=enwiki", "--outdir=/tmp/thcipriani-l10nupdate", "--threads=1", "--lang=en"], [/* 18 vars */]) = 0

Which would take some time.

I'm interested in getrusage seems like a profiling thing. Maybe a profiling thing we could turn off?

fwrite is definitely different in hhvm -- accounts for all the lseek in the hhvm output: https://gist.github.com/thcipriani/6c8c7b13fe31df644bd8b7f8ee52b383

What are the blockers for the use of PHP7?

All I see on the ticket mentioned is the memcached issue, which ops are working on right now. It should be fixed in 1-2 weeks.

Is the localisation cache currently generated incompletey as a consequence of that bug? I reimaged an app server with stretch and it logs this exception at a high rate (so I depooled it again):

mw1265 hhvm: #012Warning: Destructor threw an object exception: exception 'MWException' with message 'No localisation cache found for English. Please run
​maintenance/rebuildLocalisationCache.php.' in /srv/mediawiki/php-1.31.0-wmf.29/includes/cache/localisation/LocalisationCache.php:477#012Stack trace:#012#0 /srv/mediawiki/php-1.31.0-wmf.29/includes/cache/localisation/LocalisationCache.php(334): LocalisationCache->initLanguage()#012#1 /srv/mediawiki/php-1.31.0-wmf.29/includes/cache/localisation/LocalisationCache.php(271): LocalisationCache->loadItem()#012#2 /srv/mediawiki/php-1.31.0-wmf.29/languages/Language.php(600): LocalisationCache->getItem()#012#3 /srv/mediawiki/php-1.31.0-wmf.29/includes/title/MediaWikiTitleCodec.php(85): Language->needsGenderDistinction()#012#4 /srv/mediawiki/php-1.31.0-wmf.29/includes/Title.php(1041): MediaWikiTitleCodec->getNamespaceName()#012#5 /srv/mediawiki/php-1.31.0-wmf.29/includes/Title.php(1596): Title->getNsText()#012#6 /srv/mediawiki/php-1.31.0-wmf.29/includes/Title.php(1615): Title->prefix()#012#7 /srv/mediawiki/php-1.31.0-wmf.29/includes/Title.php(1928): Title->getPrefixedDBkey()#012#8 /srv/mediawiki/php-1.31.0-wmf.29/includes/Title.php(2061): Title->getLocalURL()#012#9 /srv/mediawiki/php-1.31.0-wmf.29/extensions/CentralAuth/includes/CentralAuthUtils.php(93): Title->getCanonicalURL()#012#10 /srv/mediawiki/php-1.31.0-wmf.29/extensions/CentralAuth/includes/session/CentralAuthSessionProvider.php(378): CentralAuthUtils::setP3P()#012#11 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionBackend.php(695): CentralAuthSessionProvider->unpersistSession()#012#12 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionBackend.php(596): MediaWiki\Session\SessionBackend->save()#012#13 (): Closure$MediaWiki\Session\SessionBackend::delaySave()#012#14 /srv/mediawiki/php-1.31.0-wmf.29/vendor/wikimedia/scoped-callback/src/ScopedCallback.php(76): call_user_func_array()#012#15 /srv/mediawiki/php-1.31.0-wmf.29/vendor/wikimedia/scoped-callback/src/ScopedCallback.php(56): Wikimedia\ScopedCallback->__destruct()#012#16 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionManager.php(886): Wikimedia\ScopedCallback::consume()#012#17 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionManager.php(310): MediaWiki\Session\SessionManager->getSessionFromInfo()#012#18 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionManager.php(244): MediaWiki\Session\SessionManager->getEmptySessionInternal()#012#19 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionManager.php(194): MediaWiki\Session\SessionManager->getEmptySession()#012#20 /srv/mediawiki/php-1.31.0-wmf.29/includes/WebRequest.php(736): MediaWiki\Session\SessionManager->getSessionForRequest()#012#21 /srv/mediawiki/php-1.31.0-wmf.29/includes/session/SessionManager.php(130): WebRequest->getSession()#012#22 /srv/mediawiki/php-1.31.0-wmf.29/includes/Setup.php(848): MediaWiki\Session\SessionManager::getGlobalSession()#012#23 /srv/mediawiki/php-1.31.0-wmf.29/includes/WebStart.php(90): include()#012#24 /srv/mediawiki/php-1.31.0-wmf.29/index.php(39): include()#012#25 /srv/mediawiki/w/index.php(3): include()#012#26 {main} in /srv/mediawiki/php-1.31.0-wmf.29/vendor/wikimedia/scoped-callback/src/ScopedCallback.php on line 56

Pretty sure that's unrelated....but I've definitely seen it before. Mostly when running maintenance scripts from tin instead of terbium. It kinda makes sense, considering tin wouldn't have the l10n cache locally (and I think mwscript tries to run it out of mediawiki-staging when on the deploy hosts).

The newly imaged host would be fixed by a full scap or by forcing l10n rebuild on that individual machine. Ideally, provisioning a new Apache should do this automatically?

For deploy masters/cli operations, we can probably add something to core that basically kicks off an l10n rebuild automatically at that point?

In T191921#4126493, @demon wrote:

Pretty sure that's unrelated....but I've definitely seen it before. Mostly when running maintenance scripts from tin instead of terbium. It kinda makes sense, considering tin wouldn't have the l10n cache locally (and I think mwscript tries to run it out of mediawiki-staging when on the deploy hosts).

The newly imaged host would be fixed by a full scap or by forcing l10n rebuild on that individual machine. Ideally, provisioning a new Apache should do this automatically?

Would that be a different command than "scap pull"? I ran that before (and usually /srv/mediawiki is fully provisioned after a fresh install)

No, that should've done it :(

Comparing the freshly installed app server (mw1265) with an existing one (mw1264) also shows that /srv/mediawiki/php-1.31.0-wmf.29/cache/l10n contains identical l10n_cache-en.cdb files

In T191921#4126575, @MoritzMuehlenhoff wrote:

Comparing the freshly installed app server (mw1265) with an existing one (mw1264) also shows that /srv/mediawiki/php-1.31.0-wmf.29/cache/l10n contains identical l10n_cache-en.cdb files

This seems to have been temporary, although I don't have a good explanation why: I've pooled mw1265 for another ~15 mins of production traffic and that all worked fine, the error I quoted above didn't reoccur. I'll keep an eye on it as we proceed reimaging.

As suggested in IRC, I ran perf record for rebuilding only the English language cdb in beta (since perf requires root).

Not sure how to interpret results, I did see a lot of symbols referred to here in https://github.com/facebook/hhvm/blob/master/hphp/doc/hackers-guide/bytecode-interpreter.md#interpreter-dispatch-loop:

[thcipriani@deployment-tin ~]$ sudo -E perf record sudo -E -u www-data -- mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/thcipriani-
l10nupdate --threads=1 --lang=en
Rebuilding en...
1 languages rebuilt out of 1
[ perf record: Woken up 3 times to write data ]
[ perf record: Captured and wrote 0.816 MB perf.data (18425 samples) ]
[thcipriani@deployment-tin ~]$ sudo perf report --stdio
Failed to open /tmp/perf-1109.map, continuing without symbols
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 18K of event 'cpu-clock'
# Event count (approx.): 4606250000
#
# Overhead  Command   Shared Object                  Symbol
# ........  ........  .............................  ..................................................................................................
#
    16.34%  php       hhvm                           [.] HPHP::dispatchImpl<false>
     4.14%  php       hhvm                           [.] HPHP::instrCanHalt
     4.09%  php       hhvm                           [.] HPHP::decode_op
     3.90%  php       [kernel.kallsyms]              [k] __lock_text_start
     3.64%  php       [kernel.kallsyms]              [k] system_call_fast_compare
     2.01%  php       libc-2.19.so                   [.] __GI___getrusage
     1.59%  php       hhvm                           [.] HPHP::handle_request_surprise
     1.59%  php       libc-2.19.so                   [.] vfprintf
     1.38%  php       hhvm                           [.] .l26394
     1.11%  php       libjemalloc.so.1               [.] malloc
     1.09%  php       hhvm                           [.] HPHP::HierarchicalProfiler::endFrameEx
     1.08%  php       hhvm                           [.] HPHP::vmfp
     1.06%  php       hhvm                           [.] HPHP::Func::findFPI
     0.89%  php       [kernel.kallsyms]              [k] copy_user_enhanced_fast_string
     0.89%  php       hhvm                           [.] HPHP::Stack::pushVal<(HPHP::DataType)17, long>
     0.74%  php       hhvm                           [.] HPHP::MixedArray::Release
     0.74%  php       hhvm                           [.] HPHP::MD5Transform
     0.72%  php       libjemalloc.so.1               [.] free
     0.72%  php       [kernel.kallsyms]              [k] kmem_cache_alloc
     0.68%  php       hhvm                           [.] HPHP::decode<long>
     0.65%  php       hhvm                           [.] HPHP::cellBitAnd
     0.62%  php       hhvm                           [.] HPHP::NamedEntity::getCachedFunc
     0.60%  php       hhvm                           [.] HPHP::(anonymous namespace)::cellArithO<HPHP::(anonymous namespace)::Add, bool (*)(long, long)
     0.60%  php       hhvm                           [.] HPHP::Native::callFunc<false>
     0.53%  php       libpthread-2.19.so             [.] 0x000000000000f08d
     0.52%  php       hhvm                           [.] HPHP::arFromInstr
     0.51%  php       hhvm                           [.] folly::AtomicHashArray<unsigned long, HPHP::rds::Link<HPHP::TypedValue, false>, HPHP::(anonymo
     0.50%  php       hhvm                           [.] HPHP::prepareFuncEntry

I managed to grab a better perf report by using PHP='hhvm -vEval.PerfPidMap=true'. Then I waited for beta-scap-eqiad to start rebuildLocalisationCache and I recorded the event via: sudo perf record -g --call-graph dwarf -p $PID

P7014 is the report I got from: sudo perf report -g --stdio

@thcipriani Is this with or without translation cache (TC) and JIT?

This uses the value from /etc/hhvm/php.ini: hhvm.jit = false.

Played with -vEval.Jit=1 yesterday and it was quite a bit slower:

@thcipriani Hm.. these are seconds though, as opposed to minutes. Is there something different about these commands? I'm asking because on a short-lived process, JIT indeed adds more overhead than is worth. But if we're talking about a 40min process, JIT has got to speed things up. I'd be confused if it doesn't.

In T191921#4147196, @Krinkle wrote:

@thcipriani Hm.. these are seconds though, as opposed to minutes. Is there something different about these commands?

The --lang=en flag. Rebuilding a single language rather than 408 languages. I'll try the full rebuild with jit enabled.

In T191921#4147196, @Krinkle wrote:

@thcipriani Hm.. these are seconds though, as opposed to minutes. Is there something different about these commands? I'm asking because on a short-lived process, JIT indeed adds more overhead than is worth. But if we're talking about a 40min process, JIT has got to speed things up. I'd be confused if it doesn't.

Given the way the JIT (used to) work in HHVM, I'd be surprise if it does speed things up - but we should surely test and confirm it.

using Eval.Jit=1 does actually seem faster on deployment-tin, anyway

[thcipriani@deployment-tin ~]$ export PHP='hhvm -vEval.Jit=1'
[thcipriani@deployment-tin ~]$ time sudo -E -u www-data -- mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/thcipriani-l10nupdate --threads=6
[...]
real    16m27.911s
user    11m36.524s
sys     4m44.920s
[thcipriani@deployment-tin ~]$ export PHP='hhvm -vEval.Jit=0'
[thcipriani@deployment-tin ~]$ time sudo -E -u www-data -- mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/thcipriani-l10nupdate --threads=6
[...]
real    28m56.778s
user    23m21.984s
sys     5m18.964s

In T191921#4122327, @Joe wrote:

What are the blockers for the use of PHP7?

All I see on the ticket mentioned is the memcached issue, which ops are working on right now. It should be fixed in 1-2 weeks.

T184854 is now closed as resolved so I'll reiterate @Joe's question: are there any other blockers from just using PHP 7?

I've put a straw-man up at T176370#4161855.

Change 430602 had a related patch set uploaded (by Greg Grossmeier; owner: Thcipriani):
[integration/config@master] Change beta-scap-eqiad timeout to 60 minutes

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

Change 430602 merged by jenkins-bot:
[integration/config@master] Change beta-scap-eqiad timeout to 60 minutes

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

coulden't a new flag be added that switches between php7.0 and hhvm?

In T191921#4161858, @Krinkle wrote:

I've put a straw-man up at T176370#4161855.

Seems reasonable, but I'm not sure all of that is necessary if we're just talking about flipping one script over to PHP 7 right now.

In T191921#4194970, @Legoktm wrote:

(..) I'm not sure all of that is necessary if we're just talking about flipping one script over to PHP 7 right now.

Yeah, let's not over-engineer this. I've written a proposal at T175288 , I'd like to hear RelEngs input in particular.

Interestingly for 1 branch of rebuildLocalisationCache.php

tin hhvm

real    40m32.809s

tin php5

real	24m13.240s

mwmaint1001 hhvm

real	16m59.381s

mwmaint1001 php7

real	4m35.088s

cf T195393#4228562

In T191921#4228654, @Reedy wrote:

tin php5

real	24m13.240s

This result seems confusing to me. Doesn't match what I've been seeing on deployment-tin or in-practice. Looking back through scap logs:

From February when we were still using php5, rebuilding l10n-cache took 6 minutes as part of a release of a new version (https://tools.wmflabs.org/sal/log/AWHYvoP_kkJ8OkTwiIMQ)

thcipriani@mwlog1001:/srv/mw-log$ zgrep -i 'finished l10n-' /srv/mw-log/archive/scap.log-20180228.gz | jq '.'                                         
{                                                                                                                                                     
  "script": "/usr/bin/scap",
  "process": 47887,
  "@version": 1,
  "@timestamp": "2018-02-27T19:37:48Z",
  "module": "log",
  "funcName": "_record_elapsed",
  "host": "tin",
  "pathname": "/usr/lib/python2.7/dist-packages/scap/log.py",
  "user": "thcipriani",
  "message": "Finished l10n-update (duration: 06m 00s)",
  "filename": "log.py",
  "type": "scap",
  "levelname": "INFO",
  "channel": "timer",
  "lineno": 748
}

vs fairly recently with HHVM, rebuilding l10n-cache took 76 minutes as part of a release of a new version (https://tools.wmflabs.org/sal/log/AWL4yhlJCdtJF089I_kV):

thcipriani@mwlog1001:/srv/mw-log$ zgrep -i 'finished l10n-' /srv/mw-log/archive/scap.log-20180425.gz | jq '.'                                         
{                                                                                                                                                     
  "script": "/usr/bin/scap",
  "process": 38819,
  "@version": 1,
  "@timestamp": "2018-04-24T19:10:50Z",
  "module": "log",
  "funcName": "_record_elapsed",
  "host": "tin",
  "pathname": "/usr/lib/python2.7/dist-packages/scap/log.py",
  "user": "demon",
  "message": "Finished l10n-update (duration: 76m 04s)",
  "filename": "log.py",
  "type": "scap",
  "levelname": "INFO",
  "channel": "timer",
  "lineno": 748
}

rebuildLocalisationCache is the bulk of what is being timed inside Finished l10n-update: https://github.com/wikimedia/scap/blob/5c3646ad20df9c872ba6c62cc9ceae3f1e7ee219/scap/tasks.py#L532-L544

reedy@tin:~$ time PHP=php5 mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff3
408 languages rebuilt out of 408

real    24m37.609s
user    21m2.040s
sys     1m29.780s

Result looks fairly replicable to me

In T191921#4229114, @Reedy wrote:

reedy@tin:~$ time PHP=php5 mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff3
408 languages rebuilt out of 408

real    24m37.609s
user    21m2.040s
sys     1m29.780s

Result looks fairly replicable to me

Probably to do with the --threads option, I suppose. Or something else specific to the way scap invokes it. The php7 result looks heartening.

The previous was with an unclean outdir...

This one is clean, dunno if it actually makes much/any difference (it was definitely out of date, so would've needed a rebuild)

reedy@mwmaint1001:~$ sudo -u www-data rm -rf /tmp/l10nstuff/*
reedy@mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff
real    11m7.750s
reedy@mwmaint1001:~$ sudo -u www-data rm -rf /tmp/l10nstuff/*
reedy@mwmaint1001:~$ time PHP='hhvm -vEval.Jit=0' mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff
real    17m0.403s

I wonder why are we testing rebuildLocalisationCache.php with --threads option, as I don't know anyone running the script without it.

In T191921#4247698, @Reedy wrote:

reedy@mwmaint1001:~$ sudo -u www-data rm -rf /tmp/l10nstuff/*
reedy@mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff
real    11m7.750s

In T191921#4248100, @Nikerabbit wrote:

I wonder why are we testing rebuildLocalisationCache.php with --threads option, as I don't know anyone running the script without it.

(I assume you mean "without" instead of "with"). There is no particular reason why we tested with or without that option. Looking through this task, I see various results with and various results without. In fact, as mentioned at T176370#4247721, several quick tests indicate the script runs slower when using multiple threads.

In any event, a few one-off tests below

# 6 threads: Matching what @thcipriani used and seems to correlate to the default used by Scap on Beta Cluster (8 cores - 2)
mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --threads=6 --outdir=/tmp/l10nstuff-krinkle1
real	10m35.274s

# 30 threads: Based on what I think Scap's default is in production (32 cores - 2)
mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --threads=30 --outdir=/tmp/l10nstuff-krinkle2
real	12m10.013s

# 1 thread (MW default): Baseline
mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --threads=1 --outdir=/tmp/l10nstuff-krinkle3
real	10m29.323s

# 15 threads: Random comparison
mwmaint1001:~$ time PHP='hhvm -vEval.Jit=1' mwscript rebuildLocalisationCache.php --wiki=enwiki --threads=15 --outdir=/tmp/l10nstuff-krinkle4
real	10m42.160s

It seems to be fairly constant, and while it might be a coincidence, it appears to run consistently slower with more threads:

• 1 thread (32 cores): 10m 29s
• 6 threads (32 cores): 10m 35s
• 15 threads (32 cores): 10m 42s
• 30 threads (32 cores): 12m 10s

More threads means more I/O contention... Not really unexpected. It's finding that balance :)

on deployment-deploy01:

mwscript rebuildLocalisationCache.php --wiki="testwiki" --outdir="/tmp/scap_l10n_3999488278" --threads=30 --force

Then in another term:

while true; do echo "_____"; ps -A -o pid,cpuid,cmd|grep -i rebuild; sleep 1; done;

And eventually they are all on the same CPU.

Then I am using taskset to find the CPU affinity mask.

The maintenance script is tied to CPU 1:

16735 php /srv/mediawiki-staging/multiversion/MWScript.php rebuildLocalisationCache.php --wiki=testwiki --outdir=/tmp/scap_l10n_3999488278 --threads=30 --force
$ taskset -p 16735
pid 16735's current affinity mask: 1

The parent process is not:

16730 sudo -u www-data php /srv/mediawiki-staging/multiversion/MWScript.php rebuildLocalisationCache.php --wiki=testwiki --outdir=/tmp/scap_l10n_3999488278 --threads=30 --force
$ taskset -p 16730
pid 16730's current affinity mask: ff

And from strace of the php process:

getpid()                                = 17963
sched_getaffinity(0, 128, [0, 1, 2, 3, 4, 5, 6, 7]) = 64
sched_setaffinity(0, 128, [6])          = 0

It is magically set to CPU 6 :]

/proc/self/status has informations about the process notably:

• Cpus_allowed: Mask of CPUs on which this process may run (since Linux 2.6.24, see cpuset(7)).
• Cpus_allowed_list: Same as previous, but in "list format" (since Linux 2.6.26, see cpuset(7)).

So here I go locally on Debian Stretch with HHVM from Wikimedia

$ php maintenance/shell.php
>>> preg_grep( "/Cpus_allowed/", split( '\n', file_get_contents('/proc/self/status') ) );

=> [
     47 => "Cpus_allowed:\tf",
     48 => "Cpus_allowed_list:\t0-3",
   ]
>>> 

And on deployment-deploy01:

$ mwscript shell.php --wiki=testwiki
>>> preg_grep( "/Cpus_allowed/", split( '\n', file_get_contents('/proc/self/status') ) );
=> [
     46 => "Cpus_allowed:\t08",
     47 => "Cpus_allowed_list:\t3",
   ]

So something on Wikimedia hosts ends up limiting the number of CPUs allowed. That might be related to includes/shell/limit.sh / the use of cgroups?

Using PHP=php7.0 mwscript it is not affected. So I guess HHVM ends up invoking sched_setaffinity whenever it runs under a Linux CGroup.

Looking at the Debian package sources, there is only a few places having that system call:

hphp/util/alloc.cpp:  numa_sched_setaffinity(0, (*node_to_cpu_mask)[node]);
hphp/runtime/ext/hotprofiler/ext_hotprofiler.h:#define SET_AFFINITY(pid, size, mask) sched_setaffinity(0, size, mask)
...

The hot profiler can be disabled via hhvm.stats.enable_hot_profiler = 0. I did so by manually editing /etc/hhvm/php.ini and magic there is no more cpu limitation.

repro

Broken:

deployment-deploy01:~$ echo "preg_grep( '/Cpus_allowed/', split( '\n', file_get_contents('/proc/self/status') ) );"|mwscript shell.php --wiki=testwiki
=> [
     46 => "Cpus_allowed:\t20",
     47 => "Cpus_allowed_list:\t5",
   ]

Disabling hotprofiler fix the cpu limitation:

deployment-deploy01:~$ echo "preg_grep( '/Cpus_allowed/', split( '\n', file_get_contents('/proc/self/status') ) );"|PHP='hhvm -d hhvm.stats.enable_hot_profiler=0' mwscript shell.php --wiki=testwiki
=> [
     46 => "Cpus_allowed:\tff",
     47 => "Cpus_allowed_list:\t0-7",
   ]

@hashar Nice research!

For web servers, HHVM has 1 worker process per CPU (this happens before affinity is modified). And each worker process has numerous threads, one thread for one web request handling. Those worker process should ideally not affect each other or steal/saturate other worker process' CPUs. As such, it makes sense to limit the affinity. It makes even more sense for Xenon ("ext.hotprofiler") to limit the affinity because Xenon code within each worker process needs to interrupt all threads from the same worker in a cheap way. I am not sure, but I suspect that it makes Xenon easy/efficient to limit the affinity there, to prevent the threads from being "randomly" assigned to a different CPU.

In terms of efficiency/performance, I suspect that this does not cause any problem. In theory, it could mean that if a worker has all its request threads stalled, it means that its CPU time is not re-usable by another worker. On the other hand, if it would allow another worker to take over, it would lose that slot and experience stagnation once its own thread wants to resume.

If I understand this correctly (and I'm not sure that I do), this means HHVM optimises for predictable performance, good resource utilisation, and optimises for lower latency per-request. This means, it does not want to optimise for completing all tasks together with perfect resource utilisation, which incompatible with the other two goals.

This makes it great for web servers, but not great for offline processing and command-line usage. This reason, and other reasons, is why the jobrunner servers were changed from a maintenance script to a VirtualHost that accepts POST requests.

About rebuildLocalisationCache.php, note that --threads is not actually an option for threads (surprise!). It is actually an option to control the number of child processes. And yeah.. with how HHVM works there are two problems:

• Trying to auto-detect the number of cores will yield 1 instead of N.
• If you spawn more sub processes anyway, they get tied to the same CPU because of the affinity of the parent process.

Perhaps there is a way to override that, but probably not. Workarounds:

• Add an option for rebuildLocalisationCache.php to tell it what portion to process, e.g. --threads-total=10 thread-self=1, --self=2, --self=3, ...). Then you can make the process separately from Scap, and it will not need to create further sub processes.
• Use PHP 7.
• Disable hotprofiler (we don't collect Xenon from CLI anyway).

Also remember that enabling JIT will speed things up as previously discovered. I believe this was not yet applied, is that right?

In T191921#4558120, @Krinkle wrote:

[...]
Also remember that enabling JIT will speed things up as previously discovered. I believe this was not yet applied, is that right?

That is correct, there's nothing in scap for this. I was hoping this task would be resolved when the maintenance scripts moved to using php7 so I moved scap-specific fixes down my priority list.

I'll start working on a way to pass flags when scap is using hhvm.

Change 459828 had a related patch set uploaded (by Thcipriani; owner: Thcipriani):
[operations/puppet@production] Scap: Update config to use PHP=hhvm -vEval.Jit=1

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

Seems scap learned to set the PHP environment variable for mwscript. I guess we can now try hhvm -d hhvm.stats.enable_hot_profiler=0 (per comment above T191921#4557854 ).

If I am not mistaken, Eval.Jit would not grant improvement since the HHVM bytecode cache is already filled with compiled code.

It's unclear to me why we're continuing to invest so much time in getting HHVM to work when we're going to switch to PHP 7 anyways. Is there a specific reason for that? Like I said in May, we should switch *this script* over to PHP 7 and re-evaluate its performance.

legoktm@deploy1001:~$ time PHP=php7.0 mwscript rebuildLocalisationCache.php --wiki=enwiki --outdir=/tmp/l10nstuff4
...
414 languages rebuilt out of 414

real	4m28.432s
user	3m31.656s
sys	0m56.376s

Does this need a patch like https://gerrit.wikimedia.org/r/459828 but pointing it at php7.0?

@Legoktm: There was some concern about incompatibilities between the mbstring in php7 vs hhvm and an assertion that php7 would not build the localization cache correctly. I was never convinced that is actually the case. Unfortunately I can't seem to find where that discussion is logged, most of it was in IRC as far as I remember.

I share the same concern as what @mmodell remembers. Having said that, I believe at this point in time that we've dealt with any/all issues of the type that would cause cascading failure or hard-to-reverse corruption. That was mostly in the area of the php-memcached driver and those type of issues have been fixed.

The XML-generation infrastructure ("dump") has been running on PHP 7 for a while now from the command-line, doing "read" -type queries. And while many parts of MediaWiki do "writes" on "read" queries (mostly relating to caching), as mentioned, any bugs relating to cache corruption have been found and fixed, and I suspect that if there were more, we would have discovered them by now through the XML-generation scripts.

I think we should continue to refrain use of PHP 7 for HTTP requests, jobs and most cron jobs, but we can start considering individual maintenance scripts. rebuildLocalisationCache.php seems like a good one to try next.

As long as we switch it in a way that we can quickly reverse if/when we find issues, you have my support to switch it whenever you feel like.

I ran a script to diff the CDBs I just generated with PHP 7.0, and there's no functional diff (just some sorting issues).

legoktm@deploy1001:~$ php dump-cdb.php /tmp/l10nstuff4/l10n_cache-en.cdb > php7-en.json && php dump-cdb.php /srv/mediawiki/php-1.32.0-wmf.20/cache/l10n/l10n_cache-en.cdb > hhvm-en.json && diff php7-en.json hhvm-en.json

Looking at other languages there's a small diff, it looks like my build of l10n cache didn't pick up LU changes.

Change 460021 had a related patch set uploaded (by Thcipriani; owner: Thcipriani):
[operations/puppet@production] Scap: Update config to use PHP=php7.0

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

Change 460021 merged by Alexandros Kosiaris:
[operations/puppet@production] Scap: Update config to use PHP=php7.0

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

Yay! :-)

Great! \o/