[01:20:18] <wikibugs>	 (03PS5) 10Awight: Hooks to maintain judgment link tables [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466806 (https://phabricator.wikimedia.org/T202596)
[01:20:20] <wikibugs>	 (03PS3) 10Awight: Maintenance scripts for judgment indexes [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466808 (https://phabricator.wikimedia.org/T202596)
[04:40:45] <wikibugs>	 (03CR) 10Legoktm: [C: 032] build: Updating npm dependencies for security issues [extensions/ORES] - 10https://gerrit.wikimedia.org/r/466262 (owner: 10Libraryupgrader)
[04:42:13] <wikibugs>	 (03CR) 10jenkins-bot: build: Updating npm dependencies for security issues [extensions/ORES] - 10https://gerrit.wikimedia.org/r/466262 (owner: 10Libraryupgrader)
[07:30:19] <wikibugs>	 (03PS1) 10Awight: Spaces to tabs in JSON files [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466829
[09:21:39] <Amir1>	 o/
[10:06:36] <Amir1>	 akosiaris: hey, do you think we can merge this? https://gerrit.wikimedia.org/r/#/c/466716/
[10:06:52] <akosiaris>	 sure
[10:08:28] <akosiaris>	 99-main.yaml just got 
[10:08:30] <akosiaris>	 +logging:
[10:08:30] <akosiaris>	 +  handlers:
[10:08:30] <akosiaris>	 +    logstash:
[10:08:30] <akosiaris>	 +      host: logstash.svc.eqiad.wmnet
[10:08:30] <akosiaris>	 +      port: 12201
[10:08:52] <akosiaris>	 should be in all of the cluster in the next 30 mins
[10:11:06] <akosiaris>	 btw, I 've tested all last 500 revision of https://es.wikipedia.org/wiki/Usuario:Danielalfredo/Taller with mwparserfromhell 0.5.1 and none cause the issue
[10:11:26] <akosiaris>	 s/last/latest/
[10:12:54] <akosiaris>	 but this is weird. cause clearly this is stuck in mwparserfromhell.parse and https://phabricator.wikimedia.org/P7669 does indeed point to that page
[10:15:55] <Amir1>	 Oh thanks!
[10:15:59] <Amir1>	 let me dig
[10:18:19] <akosiaris>	 it's a rabbithole mind you. I am trying to figure it out for years
[10:18:22] <akosiaris>	 hours*
[10:19:58] <Amir1>	 :)) the best typo ever
[10:20:32] <akosiaris>	 yeah, that subconscious thing is funny
[10:20:55] <akosiaris>	 it probably does look that long to me already
[10:21:37] <akosiaris>	 that's something about those tables
[10:21:52] <akosiaris>	 half the stack trace is Tokenizer_parse_table and Tokenizer_handle_table_row
[10:25:37] <Amir1>	 akosiaris: let's just delete the page :D
[10:25:44] <akosiaris>	 lol
[11:37:11] <wikibugs>	 (03PS1) 10Ladsgroup: Start using logstash [services/ores/deploy] - 10https://gerrit.wikimedia.org/r/466857 (https://phabricator.wikimedia.org/T181546)
[11:42:48] <wikibugs>	 (03CR) 10Ladsgroup: [V: 032 C: 032] Start using logstash [services/ores/deploy] - 10https://gerrit.wikimedia.org/r/466857 (https://phabricator.wikimedia.org/T181546) (owner: 10Ladsgroup)
[11:54:59] <Amir1>	 akosiaris: https://logstash-beta.wmflabs.org/goto/80b35b5099d8d95f993a2e7ec18754ff
[11:56:53] <wikibugs>	 10Scoring-platform-team (Current), 10Operations, 10Wikimedia-Logstash, 10monitoring, and 3 others: Send celery and wsgi service logs to logstash - https://phabricator.wikimedia.org/T181630 (10Ladsgroup) It works: https://logstash-beta.wmflabs.org/goto/f9a3fea8c95c02724813fb7cbebb6471 Shall we go prod? let'...
[12:57:07] <akosiaris>	 YES!!! I 've finally reproduce it!
[12:57:20] * akosiaris adding info to phab
[12:57:57] <akosiaris>	 wanna know the best part ? I think I know why timeouts don't work
[12:58:14] <akosiaris>	 mwparserfromhell does something with signals I guess
[12:58:23] <akosiaris>	 cause I can't even Ctrl-C the process
[12:59:04] <Amir1>	 Coool
[12:59:08] <Amir1>	 akosiaris: https://github.com/glenfant/stopit
[12:59:17] <Amir1>	 "Will not stop the execution of blocking Python atomic instructions that acquire the GIL. In example, if the destination thread is actually executing a time.sleep(20), the asynchronous exception is effective after its execution."
[12:59:23] <Amir1>	 Is it related?
[13:01:50] <akosiaris>	 no, I don't think so
[13:02:36] <akosiaris>	 there must be some malformed character in all of that btw that causes all this pain
[13:03:23] <Amir1>	 oh good (you saved me from going to a rabbit hole)
[13:21:49] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10akosiaris) I think I 've managed to reproduce the problem. After fetching and trying the last 500 revisions from https://es.wikipedia.org/wiki/Usua...
[13:29:38] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10akosiaris) The dumped memory when converted back to utf8 has the exact same MD5 as https://es.wikipedia.org/w/index.php?title=Usuario:Danielalfredo...
[13:41:59] <halfak>	 o/
[13:42:54] <halfak>	 akosiaris, great catch!  No nested signals!  It explains the problem. 
[13:44:25] <halfak>	 oh... wait.  Can't trigger the bug again with that revision?  Hmmm.  
[13:44:30] <akosiaris>	 can't find any evidence of signal handling in mwparserfromhell however
[13:44:42] <halfak>	 How did you get it to spin out of control?
[13:44:49] <wikibugs>	 (03CR) 10Ladsgroup: [C: 032] Always require damaging and goodfaith together [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466781 (owner: 10Awight)
[13:44:50] <akosiaris>	 look at the memory dump file
[13:45:01] <akosiaris>	 download it and parse that with the sample script I provided
[13:45:03] <wikibugs>	 (03CR) 10Ladsgroup: [C: 032] Followup: convert user subschema to use oneOf [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466786 (owner: 10Awight)
[13:46:42] <halfak>	 OK.  So somehow this is in memory but it doesn't match the revid in question exactly?
[13:47:02] <halfak>	 This might be enough to file a bug and get earwig involved. 
[13:47:52] <wikibugs>	 (03CR) 10Ladsgroup: Split user schema into ID or IP; validate (031 comment) [extensions/JADE] - 10https://gerrit.wikimedia.org/r/461502 (https://phabricator.wikimedia.org/T206573) (owner: 10Awight)
[13:49:27] <wikibugs>	 10Scoring-platform-team, 10Wikilabels, 10articlequality-modeling, 10artificial-intelligence: Build article quality model for Galician Wikipedia - https://phabricator.wikimedia.org/T201146 (10Halfak) FWIW, I'll be working on the ArticleQuality.js documentation today so you'll be able to translate and make u...
[13:53:25] <akosiaris>	 this is very very weird. The internal memory representation of this thing reproduces the bug, but only that. Why ?
[13:56:12] <halfak>	 I'm struggling with this memory dump.  The encoding is strange somehow. 
[13:56:36] <halfak>	 Ahh.  UTF-16? 
[13:56:47] <Amir1>	 Emojis?
[13:57:22] <halfak>	 UTF-16 ~ UTF-8
[13:57:37] <halfak>	 Just forces early ascii chars to use more bytes. 
[13:57:39] <halfak>	 I think?
[13:58:22] <akosiaris>	 the memory dump is in UCS2 cause that's what python3 uses internal for this specific string (since pep393 (python3.3) it's variable and entirely depends on the string)
[13:58:48] <akosiaris>	 for converting from ucs2 to a native python string, using UTC16 is fine (the inverse doesn't work)
[13:58:59] <halfak>	 I just converted it to UTF-8 and the signal timeout worked just fine. 
[13:59:08] <akosiaris>	 yup I have that too
[13:59:14] <akosiaris>	 but only if I write the file first
[13:59:27] <akosiaris>	 for example if I add a line under text = data.decode('utf16')
[13:59:28] <halfak>	 So, there's something about loading it as USC2... :|  
[13:59:35] <akosiaris>	 text = data.encode('utf8')
[13:59:46] <akosiaris>	 and feed that variable to mwparserfromhell I still reproduce
[13:59:59] <akosiaris>	 that former being of type str and the later of type bytes
[14:00:12] <akosiaris>	 but if I write that to a file and try to reproduce with that.. no dice
[14:00:23] <halfak>	 Oh interesting.  Let me load this in as bytes. 
[14:00:26] <akosiaris>	 WHAT ON EARTH ?
[14:00:59] <halfak>	 I wonder if pickle is doing something weird.  We use pickle as a transport between uwsgi and celery. 
[14:01:11] <halfak>	 At some point, this text will get pickled and unpickled. 
[14:02:09] <halfak>	 A straight up pickle/unpickle doesn't affect anything
[14:07:54] <halfak>	 akosiaris, so I'm struggling to find a way to reproduce. 
[14:08:01] <halfak>	 I can't even get the process to hang. 
[14:08:09] * halfak pastes code. 
[14:08:37] <halfak>	 https://phabricator.wikimedia.org/P7672
[14:08:42] <halfak>	 Do you see something I am missing? 
[14:08:46] <akosiaris>	 I only reproduced up to now in the virtualenv on ores1001 btw
[14:08:56] <halfak>	 Oh interesting. 
[14:09:05] <halfak>	 I'll try that.  I have been running in my localhost. 
[14:10:40] <akosiaris>	 with a few minor modification (I 've removed the timeout call) it does indeed reproduce on ores1001
[14:11:36] <wikibugs>	 (03Merged) 10jenkins-bot: Always require damaging and goodfaith together [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466781 (owner: 10Awight)
[14:11:38] <wikibugs>	 (03Merged) 10jenkins-bot: Followup: convert user subschema to use oneOf [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466786 (owner: 10Awight)
[14:12:11] <akosiaris>	 ok my brain is fried. I am gonna step away a few hours 
[14:12:18] <halfak>	 totally reasonable. 
[14:12:23] <akosiaris>	 maybe I 'll have some epiphany in the meantime
[14:12:32] <halfak>	 So maybe the timeout *is* working after all but the job just keeps getting resubmitted. 
[14:12:48] <halfak>	 Regardless, mwparserfromhell shouldn't be spinning out of control. 
[14:12:50] <akosiaris>	 no that definitely not it
[14:13:03] <akosiaris>	 it's a busy loop for sure
[14:13:33] <akosiaris>	 I don't know why the timeout does not catch it but the fact Ctrl-c does not work makes me think something weird is going on
[14:13:41] <wikibugs>	 (03CR) 10Ladsgroup: Render Judgment pages as wikitext (034 comments) [extensions/JADE] - 10https://gerrit.wikimedia.org/r/464737 (https://phabricator.wikimedia.org/T206346) (owner: 10Awight)
[14:13:48] <akosiaris>	 normally that would happen if a library/application was catching signals and handling them
[14:14:00] <akosiaris>	 maybe there's something esoteric about binary modules in python 
[14:14:22] <akosiaris>	 Amir had a point a few hours ago about an exception to the stopit module
[14:14:26] <akosiaris>	 something about atomic operations 
[14:14:34] <halfak>	 akosiaris, but you said it spun once you removed the timeout. 
[14:14:42] <akosiaris>	 I fail to see how mwparserfromhell is an atomic operation
[14:14:42] <halfak>	 akosiaris, that is for ThreadedTimeouts. 
[14:14:54] <halfak>	 SignalTimeouts can stop anything supposedly. 
[14:15:02] <halfak>	 Even "atomic operations"
[14:15:13] <akosiaris>	 yeah I removed the the timeout because ores.util was not directly importable
[14:15:32] <akosiaris>	 probably because I am running it from my homedir
[14:15:43] <akosiaris>	 even though the venv is activated
[14:15:49] * halfak SCP's up a cloned git. 
[14:15:49] <akosiaris>	 lemme retry that
[14:16:46] <akosiaris>	 but later, RL calls
[14:16:59] <halfak>	 kk
[14:17:10] <halfak>	 Will give a good ores1001 test in the meantime. 
[14:17:39] <wikibugs>	 (03CR) 10jenkins-bot: Always require damaging and goodfaith together [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466781 (owner: 10Awight)
[14:20:40] <wikibugs>	 (03CR) 10jenkins-bot: Followup: convert user subschema to use oneOf [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466786 (owner: 10Awight)
[14:22:38] <halfak>	 I just ran the darn'ed thing on ores1001 and it didn't even spin.  The timeout didn't even get caught. 
[14:22:43] * halfak sighs
[14:34:05] <halfak>	 Aha!  I wasn't using the right file.  I have also managed to replicate!
[14:34:38] <halfak>	 Indeed the signal does not work to stop it. 
[14:34:55] <halfak>	 Confirmed that ^C does nothing. 
[14:35:40] <halfak>	 OK.  So now, I want to see if I can process this revision in labs without anything going crazy. 
[14:37:53] <halfak>	 Confirmed.  I can reproduce on ores-staging with http://ores-staging.wmflabs.org/v3/scores/eswiki/111186880/damaging
[14:38:54] <halfak>	 OK!  We're getting somewhere. 
[14:39:07] <halfak>	 Now can I reproduce on my localhost in ORES?
[14:39:32] <Amir1>	 This is second time eswiki is bringing ores down :D
[14:39:40] <halfak>	 haha.  
[14:41:28] <wikibugs>	 (03PS6) 10Ladsgroup: Introduce ext.ores.api [extensions/ORES] - 10https://gerrit.wikimedia.org/r/459549 (https://phabricator.wikimedia.org/T201691)
[14:42:53] <halfak>	 ^ nice
[14:43:31] <halfak>	 Amir1, I really want to get that batch processing in place so that I can fix ArticleQuality.js.  I'm seriously considering just implementing it within the user-script.
[14:44:49] <Amir1>	 I recommend doing it but in a way that's easily portable to the extension. 
[14:46:38] <wikibugs>	 (03PS7) 10Ladsgroup: Introduce ext.ores.api [extensions/ORES] - 10https://gerrit.wikimedia.org/r/459549 (https://phabricator.wikimedia.org/T201691)
[14:47:07] <halfak>	 Hmm.  Not sure what might make it easily portable. 
[14:47:19] <wikibugs>	 (03CR) 10Ladsgroup: "Thanks." (033 comments) [extensions/ORES] - 10https://gerrit.wikimedia.org/r/459549 (https://phabricator.wikimedia.org/T201691) (owner: 10Ladsgroup)
[14:47:29] <halfak>	 Other than just wholesale grabbing your code and extending it in the user-script. 
[14:48:12] <Amir1>	 That would work :D
[14:49:01] <halfak>	 Aha!  So, the problem persists on my local machine too (ubuntu 16.04)
[14:49:45] <halfak>	 I need to kill -9 the process to get it to stop
[14:49:53] * halfak copies notes. 
[14:59:57] <Platonides>	 that's interesting
[15:05:53] <Platonides>	 is the text anywhere I could try it?
[15:06:43] <halfak>	 Platonides, there's a file attached to https://phabricator.wikimedia.org/T206654#4661442
[15:07:05] <halfak>	 That contains the strangely encoded text that fails.  akosiaris pulled it out of memory. 
[15:07:29] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10Halfak) OK trying to replicate...  I have found that you absolutely *must* use the file provided by @akosiaris directly.  Even re-saving it UTF-16...
[15:08:56] <Platonides>	 which version of mwparserfromhell and ores.util should I install?
[15:09:20] <halfak>	 ores.util from git clone of https://github.com/wikimedia/ore
[15:09:26] <halfak>	 mwparserfromhell==0.5.1
[15:10:35] * halfak attempts running the same thing with mwparserfromhell==0.5.0
[15:11:43] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10Halfak) OK trying to replicate...  I have found that you absolutely *must* use the file provided by @akosiaris directly.  Even re-saving it UTF-16...
[15:12:58] <halfak>	 I've confirmed that mwparserfromhell==0.5.0 still spins out of control but that the signal timeout works. 
[15:13:21] <Platonides>	 sigh No module named 'stopit'
[15:13:57] <Platonides>	 ok, it certainly runs
[15:14:02] <halfak>	 install ores requirement :P 
[15:14:28] <halfak>	 pip install -r requirements.txt in the ores base dir. 
[15:16:02] <halfak>	 This is so weird. 
[15:16:49] <Platonides>	 the revision doesn't seem to stop, either
[15:17:29] <halfak>	 Interesting.  Are you parsing the revision directly or using the file that akosiaris produced?
[15:17:32] <Platonides>	 it has been running for more than 5 seconds with the version downloaded from wikipedia
[15:17:47] <halfak>	 I should re-try that. 
[15:17:48] <Platonides>	 probably because I downloaded it directly
[15:17:59] <Platonides>	 wget "https://es.wikipedia.org/w/index.php?title=Usuario:Danielalfredo/Taller&oldid=111186880&action=raw" -O 111186880.txt
[15:18:21] <Platonides>	 maybe you copied and pasted it instead?
[15:18:54] <halfak>	 Maybe.  I'll use mwapi. 
[15:23:28] <halfak>	 Ha!  Confirmed.  Nice work Platonides!
[15:23:34] <halfak>	 So it's not celery!
[15:23:40] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10Platonides) I can reproduce it with the version downloaded from wikipedia:    $ wget "https://es.wikipedia.org/w/index.php?title=Usuario:Danielalfr...
[15:23:42] <halfak>	 That makes life way better. 
[15:23:56] <Platonides>	 :)
[15:24:09] <halfak>	 We can now file a bug against mwparserfromhell. 
[15:24:23] <halfak>	 I need to make a nice minimal version that also shows that signal timeouts don't work. 
[15:29:37] <Platonides>	 hmm
[15:29:44] <Platonides>	 signaltimeouts seem to use alarm
[15:29:52] <halfak>	 Right. 
[15:30:04] <Platonides>	 I don't see why it would faild :S
[15:30:12] <Amir1>	 I don't have much left to do for today (and this helps to reduce some overtime) I might work later though if there are some stuff to do :D
[15:30:25] <Amir1>	 Have a nice weekend people 
[15:30:40] <Platonides>	 you too, Amir1 
[15:30:44] <halfak>	 o/ Amir1 
[15:30:47] <halfak>	 Thanks for your work on this. 
[15:31:14] <halfak>	 Amir1, if you have a minute (no worries if you don't), I don't understand why you removed the try-catch around stopit. 
[15:31:20] <Platonides>	 the alarm is generated
[15:31:51] <Platonides>	 the problem may be that mwparserfromhell is allocating and deallocating a lot of memory
[15:32:01] <Amir1>	 halfak: sure, basically because it already raises 
[15:32:04] <Platonides>	 (brk,munmap,mmap)
[15:32:32] <Platonides>	 and thus, the alarm interrupts one of those internal syscalls
[15:32:51] <Amir1>	 https://github.com/wikimedia/ores/pull/273/files#diff-3d43799c54cb415864fb94bd365dcb60R32
[15:33:13] <Amir1>	 halfak: ^
[15:33:25] <Platonides>	 17:32:22.320229 mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x723fe97b0000
[15:33:29] <Platonides>	 17:32:22.329990 munmap(0x723fe97b0000, 262144) = 0
[15:33:31] <Platonides>	 17:32:22.330182 mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x723fe97b0000
[15:33:34] <Platonides>	 17:32:22.344833 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
[15:33:36] <Platonides>	 17:32:22.344974 rt_sigreturn()          = 125618827244528
[15:33:39] <Platonides>	 17:32:22.355381 brk(0x3591000)          = 0x3591000
[15:33:42] <Platonides>	 17:32:22.358384 munmap(0x723fe97b0000, 262144) = 0
[15:33:56] <Platonides>	 I wonder if it reaches python code even
[15:34:04] <Platonides>	 or if the loop is in the C part
[15:34:38] <awight>	 Amir1: Hey, thanks for the CR!
[15:35:15] <halfak>	 Platonides, should be that we can still alarm during the C execution. 
[15:35:19] <halfak>	 *should* 
[15:35:20] <halfak>	 :) 
[15:35:34] <halfak>	 OK I have a simple script that works great. 
[15:35:47] <halfak>	 Filing bug report
[15:36:05] <halfak>	 In the meantime, we can downgrade to 0.5.0 and expect this specific degenerate condition to go away. 
[15:40:18] <Platonides>	 halfak: I was thinking that perhaps it <blocked signals>, <do X which is supposed to be fast>, <unblock signals>
[15:40:21] <halfak>	 https://github.com/earwig/mwparserfromhell/issues/206
[15:41:01] <Platonides>	 if you run kill -15 <pid> it ignores you, too
[15:41:11] <Platonides>	 but kill -TERM works
[15:41:24] <halfak>	 Platonides, there's also the problem of nested signals.  Basically, they are not allowed.  So if mwparserfromhell is doing anything with signals, then it would overwrite what we're trying to do. 
[15:43:37] <halfak>	 Platonides, yes.  Same experience. 
[15:45:30] * halfak looks through difference between 0.5.0 and 0.5.1
[15:45:41] <Platonides>	 I don't see them using any signal code 
[15:45:55] <Platonides>	 and in fact, there was no signal syscall
[15:45:56] <halfak>	 Me either. 
[15:46:07] <Platonides>	 (in the strace output), and it was delivered...
[15:49:16] <halfak>	 Yeah... I really don't understand how the signal is getting fudged. 
[15:51:34] <Platonides>	 I wonder if that revision may contain a malformed utf-8 character
[15:51:54] <halfak>	 I'm guessing something like that is the case. 
[15:52:18] <halfak>	 Maybe the code that reads in the bytes does something weird with signal.  But then why would 0.5.1 behave any differently from 0.5.0. 
[15:52:48] <Platonides>	 $ LANG=C iconv -f utf-8 -t iso-8859-15 < 111186880.txt > 111186880.iso
[15:52:48] <Platonides>	 iconv: illegal input sequence at position 196065
[15:53:49] <Platonides>	 I don't see anything odd there
[15:54:01] <Platonides>	 although I wonder how does iconv count positions...
[15:57:03] <wikibugs>	 10ORES, 10Scoring-platform-team (Current), 10Growth-Team, 10MediaWiki-extensions-PageCuration, and 2 others: Merge articlequality and itemquality - https://phabricator.wikimedia.org/T206037 (10Halfak) articlequality and itemquality have very much in common.  They are all based on similar scales and refer t...
[15:58:18] <Platonides>	 that iconv was just a special -
[15:58:33] <Platonides>	 U+2013 EN DASH
[15:59:14] <Platonides>	 I note that this article has many unclosed tables
[15:59:47] <Platonides>	 maybe it's not a loop
[16:00:03] <Platonides>	 but just makes it go a way that takes too long
[16:02:03] <Platonides>	 170 {| but only 120 |}
[16:03:59] <Platonides>	 the problem was likely introduced in 86c805d59b835146e792504550da860f95b11c9a
[16:06:58] <Platonides>	 hmmm, nope
[16:08:05] <halfak>	 Why "nope"?
[16:08:30] <Platonides>	 I'm testing with several versions from mwpfh git
[16:08:54] <wikibugs>	 10Scoring-platform-team, 10editquality-modeling, 10artificial-intelligence: Simplify and modularize the Makefile template - https://phabricator.wikimedia.org/T190968 (10Halfak) a:05Halfak>03None Yeah.  Was looking into it and it'll take some work to revive it.  It doesn't seem pressing now.
[16:09:25] <halfak>	 Gotcha. 
[16:10:04] <halfak>	 awight, have you been following this stuff ^ ?
[16:10:10] <notconfusing>	 Hi Channel. halfak, awight or Amir1, does anyone have 30 minutes today to talk over hangouts and give me a walkthrough of the anatomy of a [campaign]quality repo? I've been stepping through without documentation, but it would be a bit easier just to do it synchronously with an expert.  Also we can setup a time for next week.
[16:10:28] <awight>	 halfak: yes, looks like great fun so far.
[16:11:09] <awight>	 I do enjoy a mystery, if you want to hand off your baton at any point
[16:11:21] <halfak>	 awight, I propose we downgrade to mwparserfromhell==0.5.0 in the short term. 
[16:11:39] <halfak>	 Because then our timeouts will continue to work. 
[16:12:00] <halfak>	 And prevent this degenerative behavior. 
[16:12:04] <awight>	 halfak: I couldn't quite parse what you had discovered--ah okay, so it still gets stuck in something like an infinite loop, but we can break out?
[16:12:27] <awight>	 & you confirmed 0.5.0 behavior on ores1001?
[16:12:57] <Platonides>	 I am still seeing it on mwparserfromhell version: 0.5
[16:13:01] <awight>	 fwiw we've been using 0.5.1 since mid-April
[16:13:19] <halfak>	 awight, Platonides you are not able to get a signal timeout to work in 0.5?
[16:13:25] <Platonides>	 no
[16:13:31] <Platonides>	 0.5 compiled from git
[16:13:40] <halfak>	 Oh.  It works for me.  I'm able to demo
[16:14:10] * halfak double-checks on ores1001
[16:14:56] <wikibugs>	 (03CR) 10Awight: "Note to self: AbstractContentHandler::getSecondaryDataUpdates might be an alternative to some of these hooks." [extensions/JADE] - 10https://gerrit.wikimedia.org/r/466806 (https://phabricator.wikimedia.org/T202596) (owner: 10Awight)
[16:16:22] <Platonides>	 fails with mwparserfromhell==0.5.0 from pip, too
[16:17:23] <halfak>	 Platonides, define "fails"
[16:17:46] <Platonides>	 I need to send a kill externally
[16:17:53] <Platonides>	 and time spent > 5s
[16:17:55] <Platonides>	 eg. 16s
[16:18:07] <halfak>	 Weird.  Not my experience. 
[16:18:16] <Platonides>	 $ time python3 test3.py 111186880.txt 
[16:18:16] <Platonides>	 mwparserfromhell version: 0.5
[16:18:16] <Platonides>	 PID:  3423
[16:18:16] <Platonides>	 Terminado
[16:18:16] <Platonides>	 real	0m16.761s
[16:18:30] <Platonides>	 different environments, probably
[16:19:12] <Platonides>	 I can try from scratch on a new VM
[16:22:45] * halfak tries from Jessie 9.3
[16:23:03] <halfak>	 Well..  
[16:23:15] <halfak>	 Indeed this doesn't work.  Let me try again from my Ubuntu 16.04
[16:23:44] <Platonides>	 yes, it is failing on a clean VM too
[16:24:40] <halfak>	 Confirmed.  0.5.0 is interruptable in Ubuntu 16.04 but not Debian Jessie 9.3
[16:24:49] <Platonides>	 funny
[16:25:47] <Platonides>	 which parameters are used on 16.04 when compiling the tokenizer?
[16:27:01] <halfak>	 Platonides, I'm running "pip install mwparserfromhell==0.5.0"
[16:27:36] <Platonides>	 yes, but when I do that I see that it is doing eg.
[16:27:40] <Platonides>	 x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -g -fstack-protector-strong -Wformat -Werror=format-security -D_FORTIFY_SOURCE=2 -fPIC -I/usr/include/python3.4m -c mwparserfromhell/parser/ctokenizer/tok_support.c -o build/temp.linux-x86_64-3.4/mwparserfromhell/parser/ctokenizer/tok_support.o
[16:29:18] * halfak tries a verbose install
[16:29:49] <halfak>	 For debian 9.3: x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -g -fdebug-prefix-map=/build/python3.5-3.5.3=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2 -fPIC -I/usr/include/python3.5m -I/home/halfak/venv/include/python3.5m -c mwparserfromhell/parser/ctokenizer/tokenizer.c -o build/temp.linux-x86_64-3.5/mwparserfromhell/parser/ctokenizer/tokenizer.o
[16:29:57] <Platonides>	 I didn't need anything special :/
[16:30:27] <Platonides>	 btw, 9.3 is not Jessie but stretch
[16:31:08] <halfak>	 Yes.  Thank you. 
[16:31:13] <halfak>	 Ooh  maybe a breakthrough.  
[16:31:23] <halfak>	 "compilation terminated.    error: command 'x86_64-linux-gnu-gcc' failed with exit status 1"    Falling back to pure Python mode."
[16:31:33] * halfak runs to meeting
[16:31:36] <halfak>	 back in 30
[16:31:53] <Platonides>	 :)
[16:32:01] <halfak>	 I wonder if pure-python mode is the ticket. 
[16:32:02] <Platonides>	 could be the defference
[16:32:12] <Platonides>	 *difference
[16:32:26] <Platonides>	 I noticed that if I add a signal handler for SIGTERM it doesn't work either
[16:33:13] <awight>	 Interesting note in the CHANGELOG:
[16:33:14] <awight>	 +- Fixed the parser getting stuck in deeply nested HTML tags with unclosed,
[16:33:17] <awight>	 +  quoted attributes. (#190)
[16:33:49] <Platonides>	 isn't that the one I mentioned earlier?
[16:34:47] <Platonides>	 hmmm 0.4.4 is working :)
[16:35:04] * Platonides bisects
[16:35:22] <awight>	 Platonides: Ah, good!  I did see your note about the unclosed HTML tables but missed the issue #
[16:36:09] <Platonides>	 I mean when I said:
[16:36:09] <Platonides>	 16:02:45 < Platonides> the problem was likely introduced in 86c805d59b835146e792504550da860f95b11c9a
[16:36:40] <awight>	 oops yeah and I recognize the problem report as already linked from our Phab task
[16:37:01] <awight>	 Of course, the *fix* is supposedly in 0.5.1
[16:38:45] <Platonides>	 bisection lead me to 6ee61789da11a23720e743e14d856f7d5ed1c234 is the first bad commit
[16:39:00] <Platonides>	 but that's just a commit making the compilation work
[16:42:06] <awight>	 O_O
[16:44:44] <Platonides>	 if compilation of C code fails, it falls back to python, which works :P
[16:45:46] <Platonides>	 forcing compilation with -std=c99, the problem seems to be this other:
[16:45:51] <Platonides>	 $ git bisect good
[16:45:51] <Platonides>	 8a9c9224be6cb2020ed4ad67a401081096dd21d1 is the first bad commit
[16:45:51] <Platonides>	 commit 8a9c9224be6cb2020ed4ad67a401081096dd21d1
[16:45:52] <Platonides>	 Author: Ben Kurtovic <ben.kurtovic@gmail.com>
[16:45:52] <Platonides>	 Date:   Fri Jun 23 01:08:19 2017 -0400
[16:45:54] <Platonides>	     Speed up parsing deeply nested syntax by caching bad routes (fixes #42)
[16:45:57] <Platonides>	     
[16:45:59] <Platonides>	     Also removed the max cycles stop-gap, allowing much more complex pages
[16:46:02] <Platonides>	     to be parsed quickly without losing nodes at the end
[16:46:05] <Platonides>	     
[16:46:07] <Platonides>	     Also fixes #65, fixes #102, fixes #165, fixes #183
[16:46:09] <Platonides>	     Also fixes #81 (Rafael Nadal parsing bug)
[16:46:12] <Platonides>	     Also fixes #53, fixes #58, fixes #88, fixes #152 (duplicate issues)
[16:46:14] <Platonides>	 :100644 100644 7d34015e6617e8fe64bd9e7b944aed16d0bfd197 bebacbf7f150ba65808db796170305d440c5e007 M	CHANGELOG
[16:46:17] <Platonides>	 :100644 100644 230bc5c0ddb9faf37c2a443fe21de7ca95f23f6f 588e73714318b294c252a556089ef56be4aedf4f M	LICENSE
[16:46:20] <Platonides>	 :040000 040000 0948488c8bdf20dad56f5fc9319027b82eec7c86 42357d1ea27a29f466b7055952ae44b398c4eeea M	docs
[16:46:23] <Platonides>	 :040000 040000 5f76a541f8c350d3dc8b87ebe2039f07463fcddb d6ebf96d1e3f99bd563a1ea187f69fee519448dd M	mwparserfromhell
[16:46:26] <Platonides>	 :040000 040000 83761869237f086c06b82cc3677dddd3c4825b34 5b27b8f4fde83ae6ab21fb7c1bfc06e7c176d67a M	tests
[16:46:54] <Platonides>	 seems logical to be that
[16:48:39] <awight>	 Looks exciting!  I'm confused about which tokenizer we're using, though-- halfak seems to be saying that our production boxes are using the Python tokenizer?
[16:48:43] <Platonides>	 and the article indeed has many nested tables (as they aren't closed)
[16:50:16] <awight>	 oh good, commit 8a9c9224be6 includes the same "fixes" to the Python parser
[16:52:05] <awight>	 Production is showing _tokenizer.cpython-35m-x86_64-linux-gnu.so, I assume that means the wheel includes correctly compiled C.
[16:54:08] <awight>	 The relevant point is probably that the fallback python tokenizer behaves differently when receiving a signal, so that invalidates some of our sandbox tests.
[16:58:39] <halfak>	 Back!
[16:59:10] <halfak>	 awight, I think my local Ubuntu install was using the python tokenizer. 
[16:59:44] <awight>	 halfak: +1 so that would account for why signals behaved correctly
[16:59:48] <halfak>	 Right.  
[17:00:31] <halfak>	 Though, I'm really confused about why we can't interrupt the C-code with signals.  They should be independent of the process itself. Maybe the C-code needs to handle signals in order to *be* interruptable. 
[17:00:41] <awight>	 rats.  Platonides found a pretty compelling trail of breadcrumbs, luckily.
[17:01:15] <awight>	 Yeah arcane stuff happens around signals.  I'm happy to investigate that aspect of the mystery, if it's helpful.
[17:02:15] <Platonides>	 maybe it's malloc() the one that scrubs it :/
[17:02:32] <Platonides>	 happy to have been helpful
[17:02:39] <halfak>	 Very helpful ^_^
[17:09:17] <halfak>	 "A long-running calculation implemented purely in C (such as regular expression matching on a large body of text) may run uninterrupted for an arbitrary amount of time, regardless of any signals received. The Python signal handlers will be called when the calculation finishes."
[17:09:20] <halfak>	 https://docs.python.org/3/library/signal.html
[17:09:22] <halfak>	 Well shit. 
[17:09:32] <halfak>	 Why ever use signals then?
[17:10:33] <wikibugs>	 10ORES, 10Scoring-platform-team (Current), 10Documentation: Draft of ORES threshold optimization documentation - https://phabricator.wikimedia.org/T198232 (10Halfak) 05Open>03Resolved
[17:10:52] <awight>	 https://stackoverflow.com/questions/14271697/ctrlc-doesnt-interrupt-call-to-shared-library-using-ctypes-in-python
[17:11:11] <awight>	 We just need to implement signal handling in the C module, it seems.
[17:11:36] <awight>	 I like this barbaric approach, too: https://stackoverflow.com/a/45570686
[17:11:51] <awight>	 can you get the timeout library to send SIGTERM?
[17:12:04] <halfak>	 I think that's exactly what we're doing. 
[17:12:24] <awight>	 not SIGINT? hmm
[17:12:36] <halfak>	 Oh.  Not sure. 
[17:13:16] <halfak>	 SIGALRM
[17:13:22] <halfak>	 https://github.com/glenfant/stopit/blob/master/src/stopit/signalstop.py#L33
[17:15:24] <awight>	 We could subclass and override which signal is used...
[17:16:53] <halfak>	 Would SIGTERM just kill the whole process? 
[17:17:54] <awight>	 no, apparently it's handleable as well
[17:18:11] <awight>	 Donno yet why it's rumored to have more of an effect on the non-GIL call
[17:18:21] <awight>	 reading cpython source...
[17:19:23] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10Halfak) OK we have a good working demo script and an issue filed against mwparserfromhell.   See https://github.com/earwig/mwparserfromhell/issues/...
[17:19:29] <halfak>	 OK need a break.  Getting lunch
[17:29:07] <awight>	 It's really too bad that Guido thought the world needed a new, "modern" language which wasn't thread-safe.
[17:29:22] <awight>	 threading too hard?  Just don't support it :-/
[17:45:05] <awight>	 I wonder what would happen to malloc'd memory if we signal out of a C function.
[18:23:37] <halfak>	 awight, new proposal.  Let's use the pure-python implementation of mwparserfromhell
[18:23:47] * halfak checks out performance. 
[18:24:59] <awight>	 devious
[18:26:26] <halfak>	 "--without-extension" seems like what we want
[18:29:33] <halfak>	 Confirmed that timeouts work still. 
[19:48:18] <wikibugs>	 (03PS6) 10Awight: Split user schema into ID or IP; validate [extensions/JADE] - 10https://gerrit.wikimedia.org/r/461502 (https://phabricator.wikimedia.org/T206573)
[19:48:20] <wikibugs>	 (03PS8) 10Awight: Render Judgment pages as wikitext [extensions/JADE] - 10https://gerrit.wikimedia.org/r/464737 (https://phabricator.wikimedia.org/T206346)
[19:48:22] <wikibugs>	 (03PS8) 10Awight: Tests to demonstrate SpamBlacklist integration [extensions/JADE] - 10https://gerrit.wikimedia.org/r/464727 (https://phabricator.wikimedia.org/T206255)
[20:01:04] <wikibugs>	 (03CR) 10Awight: Render Judgment pages as wikitext (034 comments) [extensions/JADE] - 10https://gerrit.wikimedia.org/r/464737 (https://phabricator.wikimedia.org/T206346) (owner: 10Awight)
[20:12:55] <wikibugs>	 10ORES, 10Scoring-platform-team (Current): ORES workers using dramatically higher CPU, increasing linearly with time - https://phabricator.wikimedia.org/T206654 (10Halfak) OK so my proposal is that we deploy the python-only build of mwparserfromhell so that we can timeout effectively.  I've run a basic perform...
[20:13:07] <halfak>	 And with ^, I'm changing locations.  Back online in about 30 minutes.