[00:00:58] * Niharika isn't donating hers
[00:07:52] <Krinkle>	 legoktm: Hm.. we don't use wgExtensionInfoMTime in prod?
[00:08:03] <Krinkle>	 I see 0 uses (also no tests)
[00:11:50] <legoktm>	 no, introducing it was a pre-optimization that turned out to not be needed
[05:24:22] <Krinkle>	 legoktm: You mean the N x mtime checking at run-time on all reqs isn't significant it seems?
[05:24:30] <Krinkle>	 Or do we cache it somewhere.
[05:24:35] <legoktm>	 stat cache
[05:24:43] <Krinkle>	 Ah, you mean at the OS level?
[05:24:49] * Krinkle digs up flame graphs
[05:24:52] <legoktm>	 er, HHVM has one
[05:25:00] <Krinkle>	 Ah, okay
[05:25:05] <legoktm>	 and PHP does too
[05:25:56] <legoktm>	 around the 1.25 release I did some basic profiling on a MW install with 20 extensions and found it to be negligible (<1% IIRC)
[05:28:10] <Krinkle>	 legoktm: production hhvm profiling for yesterday (Feb 11) for all web requests (all entry  points combiined) says ~1.22% of php execution is spent in ExtensionRegistry::queue()
[05:29:00] <legoktm>	 well that's not great
[05:30:28] <legoktm>	 the concept behind $wgExtensionInfoMTime was that you'd set it to filemtime( "$IP/LocalSettings.php" ); and every time you modify an extension, you'd also touch that file, before syncing
[05:30:40] <Krinkle>	 For index.php, it's 0.75% for queue(), all within the parent node wfLoadExtension (0.79%), all within parent node LocalSettings.php (5.5%)
[05:31:16] <Krinkle>	 legoktm: Hm.. what if we set to to a directory, like $IP/extensions
[05:42:35] <legoktm>	 Krinkle: if that works, that would be great. (probably max($IP/extensions, $IP/skins))
[05:43:47] <Krinkle>	 legoktm: I assume mtimes propagate through the filesystem in prod just like they normally would, regardless of scap etc.
[05:43:54] <Krinkle>	 I think we use it in one spot already for wmf-config
[05:43:57] <Krinkle>	 or we used to at least
[05:44:10] <Krinkle>	 legoktm: Tracking at https://phabricator.wikimedia.org/T187154
[05:45:02] <legoktm>	 thanks
[05:46:53] <legoktm>	 https://performance.wikimedia.org/xenon/svgs/daily/2018-02-10.index.svgz shows Wikibase.php at 0.77% ...
[05:50:35] <Krinkle>	 Yeah...
[05:54:02] <legoktm>	 oh my
[05:54:05] <legoktm>	 I wish I didn't look
[08:35:05] <tgr>	 Krinkle: do mtimes propagate? don't they just show the last modification of that inode (ie. file/subdir added or removed)?
[18:36:59] <anomie>	 legoktm: Does mediawiki-phpunit-coverage-patch generate actual coverage files for the patch, like the ones on https://doc.wikimedia.org/cover/ ?
[19:05:27] <addshore>	 legoktm: Krinkle evil Wikibase.php? :D
[19:23:17] <Krinkle>	 tgr: Hm.. seems you're right.
[19:23:46] <Krinkle>	 tgr: neither 'nano' nor 'touch' on a file in foo/bar/ results in the mtime of either foo/bar/ nor foo/   to be changed.
[19:24:26] <Krinkle>	 Checked via stat both access/change/modify
[19:24:29] <Krinkle>	 none of them changed
[19:24:39] <Krinkle>	 Not sure where I got that iea
[19:24:40] <Krinkle>	 idea*
[20:09:09] <RoanKattouw>	 addshore: So stephanebisson and I are trying to figure out T184670 and I'm getting super lost in all the layers of abstraction and dependency injection in the MCR code
[20:09:09] <stashbot>	 T184670: [wmf.16-regression]  Fatal exception of type "Flow\Exception\InvalidDataException"  for opting out from "Structured Discussions on user talk" - https://phabricator.wikimedia.org/T184670
[20:09:25] <RoanKattouw>	 It's very hard to figure out what ends up happening when ->getContent() is called on something
[20:09:43] <RoanKattouw>	 The backtrace we have is https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-2018.01.17/mediawiki?id=AWEFuGJFr7jliB7mVr0o&_g=()
[20:10:08] <RoanKattouw>	 Which is basically MovePage creating a newNullRevision, inserting it into $dbw, and other code then calling ->getContent() on it, which returns null
[20:10:17] * addshore ill give it a read in 5 mins!
[20:10:46] <RoanKattouw>	 We don't know why it returns null (https://gerrit.wikimedia.org/r/#/c/405054/ will help figure that out) but one possibility is DB lag
[20:11:06] <RoanKattouw>	 I tried to prove/disprove that by seeing if getContent() reads from a DB_REPLICA somewhere, but instead I got lost in the DI/abstraction maze
[20:12:41] <addshore>	 It not doing something crazy like the AbuseFilter bug i looked at earlier is it? where Abusefilter serializes a Revision object and stores it in the text table? ;)
[20:14:01] <RoanKattouw>	 No we're not doing anything weird
[20:14:16] <RoanKattouw>	 MovePage.php:531 does $nullRevision = Revision::newNullRevision( $dbw, $oldid, $comment, true, $user );
[20:14:28] <RoanKattouw>	 Then $nullRevId = $nullRevision->insertOn( $dbw );
[20:14:51] <addshore>	 Right, just sat down to look!
[20:15:02] <RoanKattouw>	 Then Wikipage::doEditUpdates() gets invoked on $nullRevision
[20:15:22] <addshore>	 This is on master of Flow right?
[20:15:47] <RoanKattouw>	 Yes
[20:16:16] <RoanKattouw>	 Unfortunately there's a PHP bug where "catchable fatal errors" like type hint violations are not actually catchable until PHP7
[20:17:39] <addshore>	 Is there a more up to date stacktrace with newer line numbers anywhere?
[20:18:04] <RoanKattouw>	 lol whoops
[20:18:06] <RoanKattouw>	 Lemme grab one
[20:18:08] <addshore>	 :D
[20:19:10] <RoanKattouw>	 addshore: https://logstash.wikimedia.org/app/kibana#/doc/logstash-*/logstash-2018.02.12/mediawiki?id=AWGLuAp3WMYqG9UiBN0-&_g=(refreshInterval:(display:Off,pause:!f,value:0),time:(from:now-7d,mode:quick,to:now))
[20:19:19] <RoanKattouw>	 Might not be Flow-related but looks like the same cause
[20:20:30] <addshore>	 hmm, I kind of remember seeing a patch for putting some logging in? did that not get merged?
[20:20:48] <RoanKattouw>	 Yes
[20:20:49] <stephanebisson>	 addshore: not merged: https://gerrit.wikimedia.org/r/#/c/405054/
[20:20:50] <addshore>	 In Revision::getContent when RevisionAccessExceptions are caught
[20:20:54] <RoanKattouw>	 It didn't get merged because of concerns about logging volume
[20:21:17] <RoanKattouw>	 But if you want to merge that we would be quite happy
[20:21:27] <RoanKattouw>	 And would SWAT it (even if briefly) so we can see what's happening
[20:21:56] <RoanKattouw>	 Or... we could apply that logging patch locally on mwdebug1002 and use XWD
[20:23:09] <addshore>	 RoanKattouw: yeh we can do that, let me finish working through the stack first! :) see if I spot something
[20:23:18] <RoanKattouw>	 OK cool
[20:29:21] <addshore>	 heh, i actually get an exception when running update.php and flow :/
[20:29:44] <addshore>	 [f650d2efd7aad82fe9810ed0] [no req]   UnexpectedValueException from line 168 of /var/www/mediawiki/includes/user/UserGroupMembership.php: UserGroupMembership::insert() needs a positive user ID. Did you forget to add your User object to the database before calling addGroup()?
[20:31:01] <legoktm>	 anomie: yes, but it throws it away so no. I have an idea of how to implement it though: https://gitlab.com/legoktm/clover-diff/issues/3
[20:36:09] <RoanKattouw>	 addshore: Yeah that only happens once, if you rerun it it shouldn't happen again
[20:38:16] <addshore>	 RoanKattouw: I tried enabling the betafeature to convert the page locally and got another exception :(
[20:38:25] <addshore>	 [7af4ec6c13c863b6ac7aaa4c] /mediawiki/index.php?title=Special:Preferences TypeError from line 111 of /var/www/mediawiki/includes/deferred/DeferredUpdates.php: Argument 3 passed to DeferredUpdates::addCallableUpdate() must implement interface Wikimedia\Rdbms\IDatabase or be null, array given, called in /var/www/mediawiki/extensions/Flow/includes/Import/OptInController.php on line 141
[20:38:48] <RoanKattouw>	 You may need to update core
[20:38:58] <RoanKattouw>	 We recently added array functionality to addCallableUpdate
[20:40:39] <addshore>	 RoanKattouw: im on laster master of core and flow
[20:40:40] <addshore>	 :/
[20:41:28] <RoanKattouw>	 Hmm lemme find the core patch
[20:41:59] <addshore>	 I still see a typehint for IDatabase in addCallableUpdate
[20:42:23] <RoanKattouw>	 Ugh looks like we broke this in core :(
[20:42:25] <RoanKattouw>	 stephanebisson:  ---^^
[20:44:58] <RoanKattouw>	 addshore: Try reverting the mots recent commit in Flow, e.g. git checkout f58664a62a58e3f4f96e122260cfcffd4e4fdf11
[20:45:09] <addshore>	 yeh, Ill revert https://gerrit.wikimedia.org/r/#/c/410193/ locally
[20:46:54] <addshore>	 Conversion from 'html' to 'wikitext' was requested, but core's Parser only supports 'wikitext' to 'html' conversion /// I guess I would need parsoid to test it out locally
[20:50:24] <addshore>	 RoanKattouw: should that block the train? not sure if it is in the branch?
[20:50:42] <RoanKattouw>	 Hmm maybe, nothing uses the array feature yet
[20:50:46] <RoanKattouw>	 We could just revert it
[20:50:53] <RoanKattouw>	 I only merged it today
[20:51:14] <addshore>	 I'm pro reverting it, as I was just about to reproduce this issue on beta :) and ran into this patch again! :P
[20:51:37] <RoanKattouw>	 https://gerrit.wikimedia.org/r/#/c/410262/
[20:53:16] <RoanKattouw>	 addshore: Actually, merging https://gerrit.wikimedia.org/r/#/c/410263/ first to see if that works
[20:59:39] <addshore>	 aaah yes RoanKattouw it looks like MWCallableUpdate is okay but not DeferredUpdates
[21:05:32] <addshore>	 AaronSchulz: when you get a second can I get your eyes on the NameTableStore patch again, it is nearly there, just got 1 more WANCache question / issue :)
[23:18:41] <addshore>	 AaronSchulz: I sent you an email about the above :)