[00:00:09] i mean you've got to hone your skillz [00:00:18] Otherwise, I don't know what will happen. [00:00:28] (or maybe I do) [00:00:34] K4-713: I think you should work on keeping the static *out* [00:00:46] I'll do what I can. [00:00:48] i.e., I pity the foo [00:03:11] waaaaaait a second. [00:03:27] Actually, just kidding. Carry on. [00:03:29] * awight time freezes [00:03:30] I need to wait a second. [00:03:32] oh good [00:04:24] I think my tests passed because this is a problem with the log function, and we're... hijacking that for tests. [00:04:50] ah [00:04:57] Wait. But amazon isn't doing that. [00:05:00] And that's the problem. [00:05:26] Hargh [00:05:31] atgo should I try AU or GB? [00:05:39] PPena: probably a good idea :) [00:05:43] oki [00:08:34] atgo nope [00:08:37] GB [00:08:46] ok, did you wait for enough time since the last donation? [00:10:46] I guess? [00:10:48] Weee: Sofia has coding class tomorrow: CLASS 37 - TUESDAY, DECEMBER 9, 2014 [00:10:48] Hour of Code @ www.code.org [00:10:48] Students will participate in the HOUR OF CODE. Students will learn the basic concepts of Computer Science with Angry Birds drag and drop programming (similar to NXT programming) [00:10:50] and I used a diff card [00:10:55] PPena: If you can get me the order id, I'll letchu know whether this was caused by not waiting long enough [00:11:01] PPena: it's not the card, it's the velocity [00:11:16] atgo im tryign to get the trnx ID for u [00:11:17] Yeah it's based on your computer's IP address, not the card [00:11:18] WP is slowwww [00:11:23] Oh crap [00:11:24] forgot [00:11:55] awight: while you're running said query... https://wikimedia.mingle.thoughtworks.com/projects/online_fundraiser/cards/2103 [00:12:04] atgo awight order ID 22730965.1 [00:12:19] reponse code :Unidentified error on Auth [00:12:25] so… no fraud fitler [00:12:34] PPTID 5733893471 [00:15:31] atgo: PPena cool, thx [00:15:39] adding another card for this one [00:15:45] PPena: wait a few and try AU please? [00:15:50] K4-713: PPena: btw, those response codes are not supposed to display to the donor [00:15:55] atgo_ yeah will wait till 4:30 [00:15:59] awight: she's going into the console :) [00:16:04] aha ok thx [00:16:09] You have to override those things, though. [00:16:26] yeah all I saw on the flow was our regular "coultn complete your donaiton" page [00:16:35] good, thanks for confirming [00:16:37] "couldnt complete your donation" [00:16:51] ...but, with GC, I think everything goes to the generic error thingy unless it's specifically... yeah, okay, so that's good, then. [00:16:59] We can get more specific. [00:18:22] Here's what CentralAuth's P3P thing points to: http://en.wikipedia.org/wiki/Special:CentralAutoLogin/P3P [00:19:38] I dunno, since this is donation stuff... is something better needed? [00:20:06] P3P is apparently an official W3C recommendation... [00:20:19] How we use this cookie: to try not to bother you for a while after you donate or click close [00:20:31] K4-713: oh god that better be a mashup :p [00:20:41] yep ok [00:20:49] cross-checked [00:20:49] ejegg: heh [00:20:49] Hell yeah. [00:20:58] It's... mashup o'clock. [00:21:09] :) seriously. I'm not getting any traction on the radio over here. [00:21:19] and my ears keep sweating! [00:23:12] The funny thing is, this particular mashup? I'm not sure which half you find to be more objectionable. [00:23:19] Was is skrillix, or oasis? :P [00:23:33] baa [00:23:47] I only caught the lo-fi oasis [00:24:32] wtf: http://msdn.microsoft.com/en-us/library/ie/ms537341%28v=vs.85%29.aspx [00:24:56] awight: I also have Ke$ha and Vanilla Ice. [00:25:06] Would that help you? [00:30:24] I need boombox [00:31:02] K4-713: hey um... what's a normal success ratio of contribution_Tracking -> donations? [00:31:15] We're handing out too many numbers. [00:31:17] This is known. [00:31:30] There's a card for it and everything. [00:31:33] oh. [00:31:39] I think it's partially qc's fault. [00:31:42] Or... something else. [00:31:46] recurring donations. [00:31:52] Somedangthing, anyway. [00:31:52] mm [00:32:05] ok yeah that [00:32:07] no this is something else [00:32:13] hey tech - hot potato: https://wikimedia.mingle.thoughtworks.com/projects/online_fundraiser/cards/2267 [00:32:17] Anyway, iirc, I made a card and everybody said "we don't care AT ALL." [00:32:28] K4-713: I tallied up all the CT ids coming from payments rcc attempts [00:32:36] I'm getting 30% conversion to an actual subscription... [00:32:53] awight: That's better than I thought it was. [00:34:01] atgo: re the fraud thing, I'm inclined to think it's a dash problem. [00:34:11] K4-713: me too... but we should... confirm. [00:34:20] gives me the heebie jeebies if it's not [00:34:22] Nothing looks off in the logs I've been looking at like this forever. [00:34:26] yup. heebie jeebies [00:34:30] ok, that's fine [00:34:32] PPena: ^ [00:34:37] The new thing, we probably just don't know how to look at it right yet. [00:34:42] i'll convert the card into a fix for dash for later [00:34:51] it's weird though because of the way it's been declining [00:35:03] The way what has been declining? [00:35:11] the rate day to day [00:35:21] Er. [00:35:26] coming to you [00:35:39] Unless you're talking percentage, this is... expected. [00:35:40] ccogdill: I'm seeing that normal "click -> donation" conversion is 70%, but for recurring (GlobalCollect) it's around 30%. Do you have any insight into this? [00:36:40] atgo SUCCESS!! [00:36:43] atgo AUD [00:37:20] woo! [00:37:27] PPena: with this fraud thing, what time period are oyu taking? [00:38:07] atgo everyday at 4pm for the last 24hrs [00:40:53] ccogdill: hey, were you ever able to load a CSV file into MySQL? If so, can you come teach me? [00:41:56] hey awight - sorry, not sure what to make of the recurring conversion rate [00:42:06] except maybe people are hitting it when they intend one-time? [00:42:12] that certainly happens [00:42:21] and uhhh I don’t think I ever loaded a csv into sql [00:43:25] ccogdill: hrrmph ok [00:43:48] sorrrrry :D [00:46:14] ccogdill: well that worked quite nicely: mysqlimport --local awight rcc_contrib.csv [00:46:17] ccogdill: http://dev.mysql.com/doc/refman/5.1/en/mysqlimport.html#option_mysqlimport_local [00:46:34] hey! that sounds easy enough [00:47:23] PPena: feeling pretty confident it's a dash issue [00:47:38] atgo that is awesome [00:48:19] atgo as long as we reviewed the US fraud logic and nothing changed… I just wont take the Dash fraud scores for USD until its not fixed [00:49:58] yeah... PPena there's probably some digging to be done in general [00:50:11] i wouldn't take the number there as total truth until more digging happens [00:50:17] for any of them [01:06:25] ccogdill: you might want to email this donor and see if they meant to make a recurring or one-time payment: contact_id=8777183 [01:06:41] ccogdill: other than that, I think I can confirm nothing bad happened to any recurring attempts, this month. [01:06:56] okay, that one definitely looks weird? [01:07:04] we usually just wait for them to complain [01:07:35] ohh sorry awight so you think that was supposed to be recurring? [01:07:49] It's unclear. this donor seems to have used the back button. [01:07:55] silly donor [01:07:59] :) [01:07:59] okay [01:08:01] thanks [01:10:45] I'm ready for bonding over beer. [01:11:37] (PS1) Katie Horn: Prevents us from hurting ourselves when trying to log things during object construction. [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/178387 [01:11:50] awight: This is why I hate myself right now ^^. [01:13:06] * K4-713 writes a card for refactoring logging, throws card out window into the night [01:14:05] aaiaaa [01:14:31] Hand me the stone of shame. [01:14:35] (CR) Awight: [C: 2] Prevents us from hurting ourselves when trying to log things during object construction. [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/178387 (owner: Katie Horn) [01:15:03] (CR) Ejegg: "Just a couple comments and questions" (5 comments) [wikimedia/fundraising/SmashPig] - https://gerrit.wikimedia.org/r/177730 (owner: Awight) [01:15:05] (Merged) jenkins-bot: Prevents us from hurting ourselves when trying to log things during object construction. [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/178387 (owner: Katie Horn) [01:15:33] ejegg: thanks! [01:15:39] Okay, I'm going to try this. [01:17:32] (PS1) Katie Horn: Merge branch 'master' into deploy [extensions/DonationInterface] (deployment) - https://gerrit.wikimedia.org/r/178389 [01:18:02] (CR) Katie Horn: [C: 2] "+2 for deploy" [extensions/DonationInterface] (deployment) - https://gerrit.wikimedia.org/r/178389 (owner: Katie Horn) [01:19:26] (CR) Awight: "Thanks, agreed that the watchdog() call is a blocker." (4 comments) [wikimedia/fundraising/SmashPig] - https://gerrit.wikimedia.org/r/177730 (owner: Awight) [01:19:45] awight: if you're grabbing #2103, could you throw an estimate on there? it's also a-ok to wait on that one until next sprint [01:20:03] just wanted to call it to your attn earlier in case it was a fix at the same time as the other thing [01:20:08] atgo: sure thx, kicking it to the next sprint [01:20:12] rad :) [01:20:15] although... we're losing data. [01:20:17] an estimate would still be cool [01:20:21] did [01:20:24] we're losing data or cc's query isn't working? [01:20:31] the former [01:20:34] the query is fine [01:20:35] oh sad [01:20:57] i'm upgrading the priority for next sprint [01:20:57] danke [01:21:01] ok [01:24:24] !log updated payments to 0e92713c0d6e5 [01:24:28] Logged the message, Master [01:24:43] (PS5) Awight: WorldPay Lynk (WP US) reconciliation [wikimedia/fundraising/SmashPig] - https://gerrit.wikimedia.org/r/177730 [01:24:52] awight: it's really great having you here 5 days [01:24:57] :( [01:25:04] I don't wish this on anybody :) [01:25:08] hahaha [01:25:11] well, thank you [01:25:15] Let's all go on strike 4 a 30-hour week [01:25:20] ? [01:25:25] i mean... [01:25:31] * awight stands in front of the building with a picket sign [01:25:33] alone [01:25:47] awight: you inspired me! i'm on that plan [01:26:06] * K4-713 gets nervous [01:26:12] oh they coopted you by giving you the 30 hours without a battle, then :p [01:26:17] haha [01:28:04] ejegg: don't worry if you have a life or anything, but merging https://gerrit.wikimedia.org/r/#/c/177704 would help my process over here... [01:28:32] meh nvm [01:28:40] Oh, I was putting that off till the Lynk thing was done, but totally don't need to [01:28:41] I just have to remember what evil magick I did [01:28:47] sure, either way [01:29:16] looks solid [01:29:54] (PS3) Awight: SmashPig can process WPUS files now [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177718 [01:30:00] it's fine, this rebase will do what I need ^^ [01:30:29] actually, i like adding the vendor submodule bump to the commit that needs it [01:30:57] true--to 177718. [01:31:44] 177704 needs the updated autoloader, right? [01:32:34] yes [01:34:47] (PS6) Awight: WorldPay Lynk (WP US) reconciliation [wikimedia/fundraising/SmashPig] - https://gerrit.wikimedia.org/r/177730 [01:35:33] Mystery solved. [01:35:49] Ooh, I gotta know! [01:35:54] Well... mystery 1 of... however many cards we have left. [01:36:01] :/ [01:36:14] If it's either of the session-looking things, I'm curious [01:36:19] It is. [01:36:23] (CR) Ejegg: [C: 2] "Looking good!" [wikimedia/fundraising/SmashPig] - https://gerrit.wikimedia.org/r/177730 (owner: Awight) [01:36:24] You ready for this? [01:36:35] * ejegg girds himself [01:36:44] This happens when you fail AVS/CVV... before the iframe content gets popped out. [01:36:55] ohhhhh [01:36:59] snap [01:37:01] RIGHT. [01:38:49] (PS1) Awight: add SmashPig and update stuff [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178393 [01:39:33] (PS4) Awight: include SmashPig through Composer [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177704 [01:40:35] (PS4) Awight: SmashPig can process WPUS files now [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177718 [01:40:44] ejegg: Well, this is great. [01:40:50] Whew. [01:41:09] yep, the validation error code correlates nicely with ffname=null! [01:41:16] yaaaaaaaaaaaaaaaaaay. [01:41:56] Also, now, if we get any lines in the logs that say "Soft reset, order_id only"... probably the same thing. [01:42:27] Those are new. :) [01:42:50] (Abandoned) Awight: add SmashPig and update stuff [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178393 (owner: Awight) [01:43:15] awight: missing .gitmodules? [01:45:18] ejegg: I just noticed your commit "Fix DonationInterface submodule" [01:45:45] I'm trying to figure out whether Composer does the submodule correctly or not [01:45:56] oh right, what was that... [01:46:42] looks like you created the .gitmodules manually [01:47:11] I'm suddenly a little disturbed about how Composer is managing these repos for us [01:47:32] ah, I think so. Yeah, composer doesn't really do submodules, huh? [01:47:44] argh [01:47:46] (PS1) Awight: update twig [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178396 [01:47:47] something... like it [01:48:04] managed in that .lock file... [01:48:10] ok well I'm fine going with the model you set in .gitmodules [01:48:26] so either composer.phar or git submodule update, but not both :p [01:48:27] Cos I noticed Composer was unable to update my repo... [01:48:30] yep [01:48:36] aw, what a pain [01:48:39] well, actually I think both is harmless [01:48:47] *cos* of composer's failure to update the submodule [01:48:57] let's hope they don't fix that bug ;) [01:48:58] ah, right. Guess we /need/ both! [01:50:27] (PS1) Awight: add SmashPig repo and dependencies [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178397 [01:51:28] (PS5) Awight: include SmashPig through Composer [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177704 [01:51:52] (PS5) Awight: SmashPig can process WPUS files now [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177718 [01:52:08] ejegg: ok I'm done with my shell game... [01:52:28] Rockin! Reviewing... [01:54:24] hmm, we don't really want --recursive for the SmashPig dependencies, do we? How is Composer supposed to work again? [01:56:51] ejegg: I. hmm [01:57:25] I would hope that composer ignores the dependency vendor dirs [01:57:31] Checking now... [01:58:10] It seemed correct, cos the vendor/wikimedia/SmashPig autoload info and dependency autoloads were added to the top-level autoloader [01:58:23] Yeah I think the subproject's vendor/ is a harmless wart? [01:59:27] our deploy script checks out recursively, but the composer autoload isn't drilling down, huh? [01:59:38] exactly [02:00:23] it seems to correctly pick up the dependencies, then include all their autoload info in the top-level autoload classes. [02:00:45] See https://gerrit.wikimedia.org/r/#/c/178397/1/composer/autoload_namespaces.php,unified [02:01:43] yep, looks good [02:02:07] I should document the submodule hack... [02:02:26] It actually works nicely if you git submodule add *after* using composer to install the dev repo [02:02:50] ah, goot to know [02:05:48] (CR) Awight: [C: -1] "Seems to work perfectly, but can you WIP this until it uses real data?" [wikimedia/fundraising/dash] (X-by-Y-chart) - https://gerrit.wikimedia.org/r/178246 (owner: Ssmith) [02:06:55] (CR) Awight: "Oh sorry, now I see the branch. This is what you were talking about earlier!" [wikimedia/fundraising/dash] (X-by-Y-chart) - https://gerrit.wikimedia.org/r/178246 (owner: Ssmith) [02:09:48] ejegg: Oooh, I found another thing going on, too. [02:10:23] ye-e-e-e-s? [02:10:26] I should add something to mingle about it. [02:10:37] Ah... you anywhere near the logs? [02:11:12] (CR) Ejegg: "let's kill worldpay_audit_recon_parser_dir in the config form too (can be another patch)" (1 comment) [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177704 (owner: Awight) [02:11:40] yeah, lessing .error now [02:12:02] ejegg: grep the error log for 22751245. [02:13:07] hmm, order id mutated within 2 minutes... [02:13:11] yep [02:13:27] This may also be the other thing... if you grep the -globalcollect log for the same ctid. [02:13:30] let's see what else we can see about these requests [02:14:55] cya! [02:20:37] (CR) Ejegg: [C: 2] update twig [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178396 (owner: Awight) [02:20:49] (CR) Ejegg: [V: 2] update twig [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178396 (owner: Awight) [02:21:36] (CR) Ejegg: [C: 2 V: 2] add SmashPig repo and dependencies [wikimedia/fundraising/crm/vendor] - https://gerrit.wikimedia.org/r/178397 (owner: Awight) [02:22:15] (CR) Ejegg: [C: 2] include SmashPig through Composer [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177704 (owner: Awight) [02:22:40] (CR) Ejegg: [C: 2] SmashPig can process WPUS files now [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/177718 (owner: Awight) [02:24:48] (PS1) Ejegg: Zap unused worldpay_audit_recon_parser_dir setting [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/178410 [03:47:34] (PS1) AndyRussG: Make Special:HideBanners set a P3P header for IE [extensions/CentralNotice] - https://gerrit.wikimedia.org/r/178423 [04:10:11] (PS2) AndyRussG: Make Special:HideBanners set a P3P header for IE [extensions/CentralNotice] - https://gerrit.wikimedia.org/r/178423 [05:41:22] (CR) AndyRussG: "Confirmed locally that with this patch, IE 11 will set a cookie via an tag pointing to Special:HideBanners on a different domain... " [extensions/CentralNotice] - https://gerrit.wikimedia.org/r/178423 (owner: AndyRussG) [17:21:38] Heya! [17:22:20] ejegg: Have you had the chance to do anything with the insights we gained last night with the new logging in DonationInterface? [17:22:36] I'm mostly asking because I don't want to dive in and duplicate stuff you've already done. [17:23:01] K4-713: not especially... [17:23:13] Excellent. I'm claiming this one, then. :D [17:24:07] These are going to be fun tests to write, I think. [17:28:35] so, that order number you sent me yesterday looked a bit interesting. There were two simultaneous INSERT_ORDERWITHPAYMENT requests at the beginning, with different order id suffixes [17:28:51] This isn't that unusual. [17:29:15] What usually causes that? [17:29:15] Particularly if the paymentproductid changes: That means they went: "Oh, wait, I didn't want visa. I wanted MC" or somesuch. [17:29:50] But, short answer: Users being users. [17:30:13] If they do it a lot, we start suspecting it's something more like an attack. [17:30:47] just twice in the one secornd [17:30:51] *second [17:31:28] That... sounds like a double-click. :/ [17:31:57] ah [17:32:07] Or, maybe not, because the timestamp we log isn't when it was sent. It's when the response is received. [17:32:15] Maybe GC got a little blocked up. [17:32:27] Anyway, still not that weird. [17:32:46] But, I don't think we recover super-gracefully from stuff like that right now. [17:32:47] probably doubleclick - i'm going by the timestamps on buildRequestXML [17:32:57] ah, okay. [17:33:04] same paymentproductid? [17:33:16] lesseenow [17:38:18] ah, nope. 1 and 3 [17:38:25] aha! [17:38:34] I believe one of those is visa, and the other is mc. [17:38:54] dude was quick on the trigger then! [17:39:10] Or, latency somewhere else... [17:40:44] ejegg: What else are you doing today? [17:40:55] I don't want to derail you unless that seems appealing. [17:41:28] so far, just reviewing a couple patches. Glad to dive into another project [17:41:53] Well, once I get this bad behavior codified in a test, I will need some review... [17:42:06] oh, definitely [17:42:34] Other than that, I'm not sure. I suspect very strongly that the stuff we're seeing in https://wikimedia.mingle.thoughtworks.com/projects/online_fundraiser/cards/2233 is the same thing. [17:42:54] That's the biggest other thing I know of, to tackle today. [17:43:21] you mean the reloaded iframe on avs/cvn fail, right? [17:43:25] nope [17:43:47] doubleclickage? [17:43:51] Well, hang on. Let me rephrase. [17:44:19] I think https://wikimedia.mingle.thoughtworks.com/projects/online_fundraiser/cards/2233 and https://wikimedia.mingle.thoughtworks.com/projects/online_fundraiser/cards/2232 may be related to the same underlying issue. [17:44:20] Maybe. [17:45:32] So, I'm a little hesitant to enthusiastically point you at 2233 until after I potentially change the entire behavior there, in 2232. :) [17:45:45] However... [17:46:02] ah, right. I'll focus on the dash and cn patches for now [17:46:12] ejegg: You think you can reproduce the bad behavior in 2233, in unit tests? [17:46:29] And then stop there with failing tests? [17:47:19] I'll give it a shot [17:47:23] Rad. [17:47:57] There are some fairly recent ones in the error log. [17:48:35] ejegg: Did you see the trick I worked in to the tests, so you can check the payments logs for statements? [17:49:00] Specific statements at different log levels? [17:49:24] Yeah, good stuff, that [17:49:47] though I was thinking I'd have to just test the curled params [17:50:26] It's pretty useful for checking to make sure your initial conditions are closely simulating the user weirdness you may be seeing in prod... :) [17:50:35] I mean, more unit-y unit tests are good, too... [17:50:47] Both wouldn't hurt. [17:51:48] Sorry, not following, I guess. Which log lines are you thinking of? The order ID collision ones are responses to the processor response, right? [17:52:33] Yeah, but in this case, a large portion of the issue seems to be that we are not regenerating a non-collision order id that does the right thing in the session. [17:52:38] It's more than just the one-off. [17:53:09] grep payments-globalcollect for the contribution tracking id instead of the specific order id, and you should see what I mean. [17:53:21] ok, let me look through code + logs till I grok [17:53:29] An initial collision isn't so much the problem as the inability to pick a good one on try #2. [17:54:34] ejegg: Possible missing bit of context: 3 tries for a good one is the maximum. I haven't seen less than three. [17:54:44] Something is borken. [17:55:07] ohh, that's interesting! [17:55:19] Yeah, something in there should be varying the id... [17:55:40] I have this problem sometimes, in which I believe I have said things I was just thinking very loudly. [17:56:11] a better mindreader than transmitter, i suppose [17:56:16] And actually, in this case, it might not be the order id. The XML seems to indicate that the merchantreference also has to be unique. [17:56:26] right [17:57:24] ...which ,akes zero sense to me. [17:57:30] *makes [17:57:45] Because for regular people, that would be a shopping cart ID. [17:57:59] And, if you fat-finger a cc number on try #1, you need a new cart ID? [17:58:04] Dumb. [17:58:18] Order ID is meant to be theirs. [17:58:20] huh, that /is/ weird [17:58:27] Merchant reference is supposed to be ours. [17:58:33] Annoying. [18:08:13] (CR) Ejegg: [C: -1] "Let's either add the /P3P subpage functionality or do something different when the global is false" [extensions/CentralNotice] - https://gerrit.wikimedia.org/r/178423 (owner: AndyRussG) [18:12:51] (Abandoned) Awight: WIP maybe fix amt-per-second [wikimedia/fundraising/dash] - https://gerrit.wikimedia.org/r/178058 (owner: Awight) [18:14:18] (CR) AndyRussG: "Ooops! K, thanks, doing that... (I was thinking it'd be a normal wiki page, but indeed it won't, since it's in the Special NS...)" [extensions/CentralNotice] - https://gerrit.wikimedia.org/r/178423 (owner: AndyRussG) [18:15:40] (CR) Awight: [C: 2] "Thanks! Weird, I lost that hunk from my earlier patch..." [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/178410 (owner: Ejegg) [18:15:46] (Merged) jenkins-bot: Zap unused worldpay_audit_recon_parser_dir setting [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/178410 (owner: Ejegg) [18:16:10] Hi awight and AndyRussG! [18:16:22] Hey ejegg [18:16:27] Hey awight [18:16:44] bonjour! [18:17:03] Il neige! [18:17:47] Silly IE... [18:42:17] Jeff_Green: It's sounding like I should poke through the slow query log again... Can you copy over the log for the last 72 hours or so? [18:42:48] ya [18:42:55] thanks [18:43:16] i tried looking but nothing leapt out at me, wasn't familiar enough with the queries and tables of interest [18:43:21] I'm still hard pressed to find useful info in that, myself. [18:43:43] could we make civi log slow queries? [18:43:46] I guess I'm just looking for times at which lock contention happens, to potentially correlate it to a job [18:43:51] Jeff_Green: sorta [18:44:04] even having a timestamp would help probably [18:44:21] I thought the log included those? [18:44:35] pretty sure. it's just unix timestampified or something [18:44:55] i mean a timestamp from civi about a query that hurt [18:45:13] there are definitely some multi-minute queries in the log [18:45:48] My theory so far is that the killer queries are coming from outside of Civi [18:45:57] the Silverpop export is a likely candidate [18:46:21] of course, wrapping all our Civi stuff in transactions is not helping, but it doesn't explain multi-minute delays. [18:47:12] what time does the silverpop export happen? [18:47:13] awight: the sp export is in the middle of the night, though [18:47:27] ejegg: ah, eliminated then. [18:47:28] probably not that then :-) [18:47:41] awight: see your homedir on barium [18:47:44] thx [18:47:49] np [18:50:03] Jeff_Green: just found a builtin tool, mysqldumpslow [18:50:18] fancy [18:50:38] aww, it was looking pretty fancy, but gives me 0.00s for all times [18:50:48] possibly a version mismatch [18:56:02] ejegg: Looks like you're right, the only lock contention is over the civicrm_prevnext_cache table, with no joins to other tables. [18:56:42] this clause just makes me mad: WHERE cacheKey LIKE 'S' [19:03:08] ok nvm, that's a summarization. the actual query is worse :) [19:06:51] yeah, the purge by letter function or something [19:07:59] the actual queries look like, WHERE cacheKey LIKE '%civicrm search df418b3dde066fe25a71c2905321e3a2_7168%' [19:08:18] It's horrible... I don't see any inserts, but the expensive updates are rampant. [19:10:15] look like the only inserts are from the Dedupe_Merger [19:12:54] huh, weird. I thought each search dumped a load of rows in there [19:13:21]