[01:22:12] grrr... rezabot is back to spamming the session log channel [03:01:41] bd808: ori: tgr: Thoughts on https://gerrit.wikimedia.org/r/#/c/274331/ [03:01:52] May've taken it too far, but just looking at how much we can simplify this [03:02:02] Mostly followed what AaronSchulz did elsewhere [04:52:32] Krinkle: I have like 3 other patches like https://gerrit.wikimedia.org/r/#/c/265617/ btw, but force merging causes problems I thought? [05:13:19] the tests should be nonvoting [14:48:43] bd808: Not the same rezabot jobs from last week at least, just two more that showed up. I'll ping andrewbogott on #wikimedia-labs about it. [15:03:19] bd808: Another one: https://en.wiktionary.org/wiki/User_talk:JAn_Dud%C3%ADk#Please_attend_to_your_bot [17:03:12] AaronSchulz: Yeah, it does. Better not. I did it once yesterday for removing a caller to a func I'm removing in core. [17:03:37] But for migration like this, I usually just let it sit until someone starts maintaining the repo again [17:03:40] you've done all you need to do :) [17:03:44] (and more) [19:05:49] MaxSem, Krinkle: It seems Ieb3bc27e4f33e170b2217ab8eab58f5309083e80 and I66937f32095a4e4ecde94ca20a935a3c3efc9cee broke generateLocalAutoload.php, it's getting confused by the "class" in "static::class". [19:07:26] * anomie files T128625 [19:07:45] stashbot: I guess you didn't see T128625 in the /me? [19:07:46] T128625: generateLocalAutoload.php breaks on `static::class` - https://phabricator.wikimedia.org/T128625 [19:10:19] pfft, an ol' good regexp would have worked much better:P [20:15:41] bd808: How do you get mw core to log to log files with the json packet at the end like your comment shows? [20:15:53] (and should we make that the default, and/or easy to configure?) [20:16:12] Anything that doesn't involve pasting 200 lines from wmfconfig in my LocalSettings is fine. [20:16:29] heh, welll [20:16:59] I use Monolog with a custom config in my mw-vagrant VM [20:17:06] so it is a lot of stuff [20:18:10] the bit that does what you are interested in is '"%datetime% %extra.host% %extra.wiki% %channel% %level_name%: %message% %context% %exception%\n"' as the format string for LineFormatter [20:19:02] %context% adds a json stringification of the context data [20:22:23] Krinkle: this config file from mw-vagrant might work for you -- https://github.com/wikimedia/mediawiki-vagrant/blob/master/puppet/modules/role/templates/psr3/settings.php.erb [20:22:53] it's only 102 lines so under your limit ;) [20:23:52] Hm.. well, next time I'll bargain better. I wasn't prepared [20:24:00] I meant to say 20 :P [20:26:13] It should be no more than 3 lines of code to: 1) enable logging (by setting a default file, overridden per-channel wgDebugLogGroups), 2) change the format %% format. [20:26:32] I've been thinking about an RfC for work to start in 1.28 that rips out the legacy logger and its config and make it all Monolog by default [20:26:46] Yeah [20:26:59] wgDebugLogGroups can be enhanced with ability to change the log level cut off [20:27:08] which is indeed missing and something that makes it incompatibel with Monolog [20:27:30] and if is_string (for existing config) some kind of default [20:29:23] Krinkle: your scenario assumes a strongly static default logging setup [20:29:49] bd808: Our current reality and planet are also strongly static. [20:29:54] :) [20:30:11] I change, but there's only one of me at any given moment. [20:30:25] 50% of the reason for PSR3 support was to provide actual logging flexibiltiy [20:30:42] wgDebugLogGroups is not really flexible [20:30:47] I don't think the vast majority of mw installs need that. [20:31:15] adding the ability to set up advanced log destinations (e.g. logstash) is useful, and being able to specify which channels go where, and with what level, too. [20:31:30] most installs need all channels in a single file [20:31:39] But I think the current Monolog config as exposed to wmf config is overly complex. It's not impressive, just hard to use. [20:32:04] a file, or udp destination, or another single destination (e.g. logstash or redis) [20:32:20] using udp can't really be normal [20:32:29] I'd be nice if we can keep wgDebugLogGroups in non-deprecated form but as proxy for Monolog [20:33:11] I think its time to rip off the bandaid honestly and fix the legacy idea of arbitrary channel naming at the same time [20:33:22] channels should be named after classes [20:33:40] I'd also like us to remove many of the other debugging variables such as wgDebugDumpSql (might be bad example, but others like it) and have them be channels instead. [20:33:51] +1 for that [20:33:55] bd808: Hm.. objectcache seems sensible as a single channel though? [20:34:14] objectcache. [20:34:16] Granted, things like Redis connection errors would ideally go in a dedicated redis channel for easy operationally useful dashboarding and such [20:34:43] that could be done with tags in the context much more flexibly [20:35:02] but non-critical errors tend to be shared with objectcache and make it easier for mw developers (who shouldn't even know at any given point what backend a cache object is using) - to still be able to find statistics about their cache behaviour [20:35:36] logging is this funny thing that people think they have strong opinions about, but never work on [20:35:45] So end use case: Have a dashboard for memcached and redis, but also a dashboard for objectcache that reports duplicate key access [20:36:07] Either by using 1 channel with a field for backend, or a channel per backend with a field for type, I don't mind [20:36:12] though the former seems cleaner imho [20:36:54] so the parent class gives the log channel its name and children just have to live with it? [20:36:59] is namespacing the channel a thing in logstash or monolog? [20:37:10] all db in one channel, all cache in another, etc? [20:37:25] bd808: no, I agree logging should be injected as an object and the class no control over the channel [20:37:26] channel names are a thing in PSR3 [20:37:42] (and most logger implementations) [20:37:49] [12:32:20] using udp can't really be normal <-- it took about 2 minutes for me to grab a UDP -> IRC script to all our debug logs go to IRC [20:37:59] yes, but is channel namespacing a thing? [20:38:09] e.g. would 'objectcache.redis' be reasonable in your opinion? [20:38:33] ah. that's more of a Java'ism but in my opinion reasonable [20:38:36] [12:35:36] logging is this funny thing that people think they have strong opinions about, but never work on <-- no, that's everything ;-) [20:38:38] * bd808 used to be a java dev [20:38:44] I think giving all bags a log channel of 'objectcache' and having base class BagOStuff tack on a class:name field could be something to consider. [20:38:53] (via the ObjectCache factory) [20:39:25] "tacking on" per whatever isn't easy with PSR3 or Monolog [20:39:33] Right. [20:39:38] so if we stick with standards then things get harder [20:39:42] Channel is the only injected meta data [20:39:54] unless we override each of the logger methods [20:39:55] yeah [20:39:59] that adda property to the $context array [20:40:10] but that isn't because logger is an instance member [20:40:16] we don't inherit the methods [20:40:17] hm. [20:40:20] Yeah, so namespacing it is? [20:40:21] I really hate that PSR3 didn't adopt diagnostic contexts [20:40:50] Log4J's MDC is the nicest thing for structured logging ever [20:41:12] its a thread local dict of things to add to all log messages [20:41:38] PSR3 doesn't standardise the concepts of channels either [20:41:40] so you just grab it when you have something interesting to add (like username or session id) [20:41:43] that's presumed via the logger interface [20:42:08] yeah, although named logger ~= channel [20:42:22] Yeah, but that's Monolog thing, it's not mentioned in PSR-3 [20:43:17] you're right. psr3 stays away from any description of where LoggerInterface instances come from doesn't it [20:44:08] TimStarling: Could you sanity check https://gerrit.wikimedia.org/r/#/c/267024/ ? [20:45:00] So if we went with a more native Monolog integration in core we could get fancier with some things [20:45:26] and still have the benefit of loose coupling for things that we want to pull out into libs [20:45:52] ok [20:45:56] Keeping core highly flexible for PSR3 implementation makes providing sane default configuration harder [20:47:03] bd808: btw, I also drafted https://gerrit.wikimedia.org/r/#/c/258163/ a while back which might excite you, or make you cry. [20:48:08] that is isset() on a string offset? I don't think I've seen that before [20:49:53] Yeah, it's a weird one, even for PHP. [20:51:04] php > $foo = 'bar'; [20:51:04] php > echo $foo['quux']; [20:51:04] PHP Warning: Illegal string offset 'quux' in php shell code on line 1 [20:51:04] b [20:51:11] It yields a warning, but nonetheless returns offset 0 [20:51:16] (PHP 5.6) [20:52:09] bd808: also https://phabricator.wikimedia.org/T115890 - thoughts welcome [20:52:28] the isset( $m[1][0] ) has the benefit of ensuring both that $m[1] exists and that it is non-null I guess [20:56:06] Krinkle: if only the PSR for a cache interface hadn't gotten so horribly weird... [20:56:21] http://www.php-fig.org/psr/psr-6/ [20:57:18] wrapping all cached content in value objects *shudder* [20:58:48] looks like strlen() has an implementation in the VM even in Zend now, so there won't be much performance advantage [20:59:01] in HHVM I think it is inlined [20:59:07] but it's a nice shortcut syntax [21:11:26] bd808: why is that so bad? [21:11:48] (having a wrapper around values that were retrieved from the cache) [21:12:42] ori: you have to wrap them to put them in [21:13:30] and use separate setters to specify things like ttl [21:13:42] with a builder like pattern [21:14:06] just really really verbose for something as simple as "hang on to this for a while" [21:24:53] just checking: it's legit to use $this in closures now, right? [21:25:01] yes [21:25:28] that got fixed in 5.4 [21:25:37] sweet [21:53:29] bd808: https://gerrit.wikimedia.org/r/274500 - fails in read-only mode [21:55:06] Krinkle: ugh. +2d [21:55:13] we should backport yes? [21:55:26] Yeah [21:55:34] to wmf15 [21:56:14] picked to https://gerrit.wikimedia.org/r/#/c/274501/ [21:56:27] do you have time to get that out? [22:00:28] bd808: yeah, i'll wait for the train to finish and then push it out [22:00:43] thanks [22:17:00] * Krinkle is about to give up on his local dev environment. [22:17:21] I don't know what it is but it seems about every 1-2 days, my local install randomly freezes up and decides all mw http requests just time out [22:17:29] restarting apache fixes it every time [22:19:45] Krinkle: Vagrant or bare-metal? [22:19:50] metal [22:20:26] Hmm. [22:21:25] I've tried 5 times to use Vagrant on my machine, plus about a dozen times on other people's machine. It always ends up shitting itself when I start checking out patches and stuff. Usually puppet fails or isn't well maintained. I want to believe, but reality disagrees. [22:21:39] So I've been back on metal for the past 6 months. Simple Mac/Homebrew apache+php+mariadb [22:22:05] MW-Vagrant works great for me, but every now and then RB goes nuts and I have to (virtually) power-cycle it. [22:22:09] I can't work with an environment where I have to file unbreak tasks just to do my work. :) [22:22:31] depending on what you're doing, Vagrant might be overkill indeed. however for something non-trivial like Elasticsearch Vagrant is absolutely inavoidable [22:22:38] Anyhow, at times it goes crazy (my metal set up) non-mw requests still work fine [22:22:44] so Apache or PHP itself isn't broken. [22:22:49] Something must be locking badly in MW itself [22:25:54] apache, php and mw logs never mention anything. [22:26:12] It's happening right now actually. Havent' restarted it yet. [22:32:14] Krinkle, is it making external requests (e.g. InstantCommons)? [22:33:42] Hm.. good point. Disabled that, no effect yet. The page I'm requesting doesn't contain images though. [22:33:55] It does reach LocalSettings if I put a hard die() there. [22:35:28] Krinkle: Have you tried setting $wgSessionsInObjectCache = true; ? [22:35:52] There's a deadlock in the default PHP session handler that's pretty easy to hit if you use Parsoid for example [22:36:37] Hm.. wgSessionsInObjectCache isn't in my config, it defaults to true. [22:36:56] I have Parsoid set up, but these are regular page view requests (logged-in) [22:37:20] Interesting [22:37:20] It defaults to true now? It didn't use to [22:37:25] But that may have been in 2012/2013 I guess [22:38:50] There is only 1 entry in error.json channel after all these timed out requests (they don't actually time out, they just linger indefinitely with no response) - possibly unrelated, but one of the requests resulted in "PHP Notice: A session had already been started" in the error log, from session_start, MediaWiki\\quietCall, Setup.php:752, WebStart.php, [22:38:50] index.php [22:39:54] https://gist.github.com/Krinkle/da785c2321e0c6289414 [22:40:32] Yeah, I've narrowed it down to session [22:40:51] OK [22:41:00] Well we did have a bunch of code change in that area [22:41:04] die('x'); in Setup.php before $ps_session works. die('x2'); after scopedProfileOut( $ps_session ); never shows up [22:41:07] anomie: [22:41:19] I think session manager broke my local wiki