[14:06:03] Is there a way to view mw-cron output in the original order? It seems the k8s version, takes each line of standard out as its own Logstash event with a timestamp but that's not precise enough to order the lines, making it difficult hard to find what's going on. cc/ swfrench-wmf [14:06:51] Looking at eg "startupregistrystats" per https://phabricator.wikimedia.org/T388540 [14:07:14] Krinkle: https://wikitech.wikimedia.org/wiki/Periodic_jobs#Logs_from_kubernetes [14:07:38] But probably at some point they should log in a standard well defined format [14:07:41] That would be best [14:18:18] Krinkle: does that help? [14:20:12] Yep! Trying it now. [14:22:33] Maintenance scripts do have access to structured logging same as any part of MW. I guess over time we'll treat this more like we treat php-fpm/street today. Like, it's there but rarely looked at and not where most stuff should be. The main thing stopping adoption today is that for the use case of running these anywhere else, they should still work as normal CLI scripts, so we'd want to do the inverse and have core output some channels to [14:22:33] stdout by default. [14:22:48] street* stderr [14:23:40] As is, adopting PSR-3 equates to the information becoming hidden for all other use cases so there's a negative incentive to do so [14:24:07] But yeah makes sense. Basically why we do with the jobqueue already [14:28:03] why*what [14:28:13] Surely that's configurable ? [14:28:55] (I'm being very naive) [14:29:35] Not exactly. Monolog goes to Logstash. Php print goes to stdout. [14:29:46] The cli output is pretty much directly calling php print() [14:30:19] We could override that but what wouldn't make it better. That's basically what mw-k8s-cron does now. [14:42:15] So I may be missing a lot of subtleties there, but wouldn't a cli-logging lib wrapping monolog and print and getting a flag from MWScript.php or mediawiki-config be something that could work? [14:42:41] (as a general solution-shape) [14:44:06] We have logger->channel(..)->debug/info/warning(..) and print(..). Changing or wiring print() to the former by itself would yield the same result for WMF prod as what we see today. Out of order and mostly unstructured. [14:44:50] Unless there's something about how we ingest mw-cron today that makes timestamps or order less precise than other messages from MW? [14:45:06] I was assuming not. [14:46:38] We need to rewrite all these messages to basically never log multiple things that relate together as separate lines, and structure them with key value pairs and such. That's not something we can automate afaik [14:47:44] And then to remove the negative incentive we need a change in core maintenance runner to indeed tee one agreed-upon channel name as what we send to stdout like we do today for usability [14:47:45] It's sending everything to stdout/stderr [14:48:02] afaik [14:48:57] Right okay I see what you mean. In the move from hardware to kubernetes, the transport mechanism from mw more generally was changed from rsyslog to stdout or stderr via docker and kubernetes. [14:49:05] yeah [14:49:30] That's a WMF config choice. Mw doesn't send those to stdout. If it did they'd end up in browser viewports etc [14:50:34] Most of what ends up in logstash, at least for blameStartupRegistry.php runs, is because it does a bunch of echos [14:51:10] Yep. That's how all maintenance scripts convey their progress and results to their operators. [14:51:48] Yeah they're litteraly meant to run on a tty, and for human log consumption [14:51:57] We're kinda breaking that assumption with mwcron-k8s [14:52:52] I mean we potentially could just add monolog logging to them, and send stdout/stderr to /dev/null in mwcron [14:52:59] (again being very naive) [14:54:12] https://codesearch.wmcloud.org/deployed/?q=%3Eoutput%5C%28&files=maint.%2Bphp&excludeFiles=test [14:56:04] My straw man proposal would be to start by rewiring output() to logger channel maintenance debug(), and have that channel go to stdout by default. Then slowly go through these with a PHPCS lint rule disallow calls to print/echo/output() and make these more structured so that generally given a given millisecond you either don't have more than one message or the two are separate enough that order doesn't matter much. [14:57:18] by stdout here I mean in terms of how it's used by default locally and third parties. For WMF you'd likely want to dev null that since itd go to monolog/stderr already as well [14:58:22] That could be quite nice actually. We could even make it possible to have a --debug mode locally that shows all channels. Right now devs have to cross reference with a debug.log file somewhere by process ID after the fact. [14:58:50] For indirect code that use structured logging already [14:59:33] It'll take some getting used to but it's not very different from how we use deferred updates and jobqueue today which also don't have echo access [15:00:55] Yeah, that'd be great, both for mw-cron and mw-script-k8s [15:11:06] who is the best person to talk to about IDP? and how i might be able to use it to authenticate my app? :D [15:12:23] slyngs: ^ [15:12:31] Or a phab task to I/F [15:14:33] Oh interesting, I now alos see that there is a idp.wmcloud.org