[00:26:02] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog: Tag removal triggers unrestricted dedupe query - https://phabricator.wikimedia.org/T216057 (Eileenmcnaughton) I logged this upstream... https://github.com/civicrm/org.civicrm.contactlayout/issues/46 [00:27:47] (PS1) Eileen: Fix extraneous slow dedupe call when no deduping to do [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) [00:31:35] mepps: you are probably gone now but I posted up here about that perf regression https://github.com/civicrm/org.civicrm.contactlayout/issues/46 [01:01:21] (PS2) Ejegg: Front-end logging for Ingenico url too short [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/489700 (https://phabricator.wikimedia.org/T210893) [01:01:45] (CR) Ejegg: "thanks XenoRyet. Fixed in PS2" (1 comment) [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/489700 (https://phabricator.wikimedia.org/T210893) (owner: Ejegg) [01:03:47] eileen: in my local [01:04:07] Setup it looked like the notices were from address history [01:04:24] hmm - I think the notices are tangental [01:04:41] Yeah [01:04:45] my read is that CiviCRM does weird shit here https://gerrit.wikimedia.org/r/#/c/wikimedia/fundraising/crm/civicrm/+/490507/1/CRM/Profile/Form.php [01:05:16] ie it does a query to get dupes & then throws them away if they weren’t really needed anyway [01:05:55] which would ALWAYS be a ‘bit bad’ for performance but in this particular case is a lot bad [01:22:53] Yeah it’d be nice if there was a way to not check for dupes on profile edit [01:23:19] that patch seems to do it [01:43:16] yeah, those enotices are annoying too though. looks like two tabs are malformed in that array [01:43:38] mailing events in addition to address history [01:51:33] (CR) Ejegg: [C: +1] "Looks like this fixes it! But perhaps it could be a mite simpler." (1 comment) [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [05:06:50] Fundraising-Backlog, Analytics, Analytics-Kanban: Clean up old fundraising-related user data on Analytics hosts - https://phabricator.wikimedia.org/T215382 (Nuria) Open→Resolved [05:15:37] (CR) Eileen: "ejegg that kinda scares me because in the 'else' we have" [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [12:06:16] (CR) Ejegg: [C: +1] "Since you're only returning true from isUpdateExistingContactById when _isUpdateDupe is 1, we would never even get to the 'else' part of t" [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [14:18:57] Fundraising Sprint A series of unfortunate event handlers, Fundraising Sprint Bert and Ernie's Excellent Adventure, Fundraising Sprint Casino Royale With Cheese, Fundraising Sprint XML ate my homework, and 3 others: Add 'CentralNotice' tag to all CentralNot... - https://phabricator.wikimedia.org/T209795 [14:19:54] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog, Wikimedia-Fundraising-CiviCRM, Patch-For-Review: Civi: Cancel button for recurring donations missing - https://phabricator.wikimedia.org/T215513 (Ejegg) Open→Resolved [14:21:12] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog, Unplanned-Sprint-Work: Civi Upgrade UI issue: Quick Search doesn't work consistently or well - https://phabricator.wikimedia.org/T215802 (Ejegg) First and Last Name search works for me too. [14:28:59] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog, MediaWiki-extensions-CentralNotice, WikimediaMessages, and 4 others: Missing centralnotice admin protection level messages causing broken edit summaries and strings in Special Pages - https://phabricator.wikimedia.org/T210986 (Ejeg... [14:30:08] cwd and Jeff_Green: thanks for the work on payments2003. I can get an Amazon payment all the way through on payments.frdev now [14:31:10] I looked at all the forms on an iphone and they seem pretty good [14:31:20] = identical to the old ones [14:31:58] want to start upgrading another box or two on the main cluster? [14:34:31] hmm, the logs on bellatrix seem to be a bit sparse though [15:16:58] Fundraising-Backlog, Fr-CentralNotice-Translation-Bugs, MediaWiki-extensions-CentralNotice: New message inclusion syntax strips with more than one class - https://phabricator.wikimedia.org/T216150 (Pcoombe) [15:25:56] hi Jeff_Green, any idea why the logs on bellatrix seem so much sparser than the logs on frlog1001? [15:26:52] for example, trying to make a donation via Astropay / dlocal [15:27:17] I'm getting an error (may be address control related) but nothing appears in the log [15:29:40] by upgrading another box do you mean making it live or pointing them to the frdev domain? [15:30:21] and i can't think of a reason the log servers would be different, maybe it takes longer to get to codfw [15:30:24] cwd I think we're ready for live, at least on the main cluster [15:31:01] cwd wait, takes longer to get to codfw? [15:31:25] doesn't bellatrix just log stuff from codfw and frlog1001 just log stuff from the main cluster? [15:32:00] yes, that's right ^^ [15:32:54] ah i didn't know that [15:34:19] ejegg: can you give me an example of what's not showing up, so I can see if it's in fact logged on payments2003 and just not making it to bellatrix? [15:39:02] let's see... so if I look at attempt 65760585, there's nothing at all in payments-astropay [15:39:28] I just see some stuff in payments-fraud and one line in payments.debug [15:40:08] for a similar attempt on the main cluster I at least see some lines about the session, then some timing lines around the API request [15:40:19] hmm, is the error happening on the client side? that might explain it [15:41:39] no, it's doing a post back to the page and loading a whole new page, just with the error message showing [15:42:02] and nothing at all logged [15:43:58] similarly with attempt 65760830 for old-style paypal [15:44:53] does a full post to the page, re-renders with error message, but nothing at all in the logs except for 1 line in debug and 4 lines in -fraud [15:47:18] is it possible this has to do with new php defaults? [15:49:17] what php defaults could do that? [15:49:54] can you grep for those numbers in payments2003's syslog? [15:49:56] I don't know, specifically, but my first thought would be something related to filtering by syslog loglevel [15:50:13] yes, there are 5 lines with those numbers, total [15:50:56] oh huh [15:50:57] four are from paypal_gateway_fraud, one from smashpig re. "entering logging context" [15:51:12] right, so all of those get to the remote logger [15:51:59] looking at the logging config [15:55:58] ejegg: can you PM me the full URL for the post-back that barfs an error? [17:23:08] (CR) XenoRyet: [C: +2] Front-end logging for Ingenico url too short [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/489700 (https://phabricator.wikimedia.org/T210893) (owner: Ejegg) [17:24:06] (Merged) jenkins-bot: Front-end logging for Ingenico url too short [extensions/DonationInterface] - https://gerrit.wikimedia.org/r/489700 (https://phabricator.wikimedia.org/T210893) (owner: Ejegg) [17:59:28] (CR) Mepps: "Hmm there are a lot of if/elses here so I don't love introducing one more. However, I'd go with Eileen that we don't want it to go into th" [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [18:08:46] (CR) Mepps: "Wait, just ran through the code locally. If we set ids to null, there is no else statement, it just moves forward and saves no prolem. The" [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [18:09:16] ejegg i actually agreed with you--should i make that change or wait for eileen since it's her patch? ^^ [18:28:26] (PS1) Cstone: Add in check to set no_thank_you field for recurring payments after the first recurring payment. [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/490666 (https://phabricator.wikimedia.org/T213209) [18:48:20] mepps you want to make that change and I'll review? feels importanyt enough not to wait for weileen [19:11:16] (PS2) Mepps: Fix extraneous slow dedupe call when no deduping to do [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [19:17:21] (CR) Ejegg: "Thanks eileen & mepps. This looks good and works locally." [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [19:22:30] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog, Recurring-Donations: research recurring upsell - https://phabricator.wikimedia.org/T215340 (Ejegg) ping @CCogdill_WMF, @MeganHernandez_WMF, @spatton, @Pcoombe: any thoughts on sending the user back to PayPal to get a second authorizat... [19:36:36] (CR) Ejegg: [C: +2] Fix extraneous slow dedupe call when no deduping to do [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [19:40:40] (Merged) jenkins-bot: Fix extraneous slow dedupe call when no deduping to do [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [19:46:05] (PS1) Ejegg: Update CiviCRM submodule [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/490680 [19:46:09] (CR) Ejegg: [C: +2] Update CiviCRM submodule [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/490680 (owner: Ejegg) [19:46:34] (PS1) Ejegg: Merge branch 'master' into deployment [wikimedia/fundraising/crm] (deployment) - https://gerrit.wikimedia.org/r/490681 [19:46:38] (CR) Ejegg: [C: +2] Merge branch 'master' into deployment [wikimedia/fundraising/crm] (deployment) - https://gerrit.wikimedia.org/r/490681 (owner: Ejegg) [19:50:23] (Merged) jenkins-bot: Update CiviCRM submodule [wikimedia/fundraising/crm] - https://gerrit.wikimedia.org/r/490680 (owner: Ejegg) [19:50:25] (Merged) jenkins-bot: Merge branch 'master' into deployment [wikimedia/fundraising/crm] (deployment) - https://gerrit.wikimedia.org/r/490681 (owner: Ejegg) [20:09:00] !log updated fundraising CiviCRM from 02ea871b88 to 165fbf5894 [20:09:01] Logged the message at https://wikitech.wikimedia.org/wiki/Server_Admin_Log [20:10:28] Fundraising Sprint Casino Royale With Cheese, Fundraising-Backlog, Recurring-Donations: research recurring upsell - https://phabricator.wikimedia.org/T215340 (CCogdill_WMF) Do we know what that looks like on the PP side? It's not ideal but it makes sense. We could compare it to the CC conversion rate... [20:29:49] (CR) Eileen: "ejegg & mepps some code is best just not ever seen" [wikimedia/fundraising/crm/civicrm] - https://gerrit.wikimedia.org/r/490507 (https://phabricator.wikimedia.org/T216057) (owner: Eileen) [20:47:31] hmph, I can't replicate that logging failure :( [20:49:29] ejegg: does it happen on payments1004? [20:49:46] Jeff_Green: yeah, so it's definitely something to do with the upgrade [20:49:51] ok [20:49:54] and not just the secondary cluster [20:50:20] are you testing on stretch, or something else? [20:50:29] I'm on debian experimental [20:50:58] buster-ish? interesting [20:51:10] ah, I was assuming it was mediawiki-1.31, but I guess it could be the php version too [20:51:16] I could try testing in vagrant [20:51:43] yeah and also our puppetized php and apache configs [20:52:36] what's on these payments servers should be very close to the payments-listeners [20:55:43] ejegg: another possibility would be that we're missing a package? [20:56:13] Jeff_Green: hmm, I guess maybe, but it would be really weird to have some logs working and not others [20:56:41] yeah that sounds more like a loglevel filtering thing [21:01:03] ejegg: is there a common thread re. the log mechanism used for the missing logs vs the ones that are showing up? [21:03:16] Jeff_Green: oho, weird, so I DO see that same log line about 'session_addDonorData on payments2003 in some earlier attempt [21:03:23] so... how's that happening [21:06:15] ah, it does log the line on first page load [21:06:24] but it doesn't on the post [21:06:33] so... maybe some weird crash first? [21:09:05] interesting, that would be sorta similar to what happened re missing GeoIP.dat [21:10:14] Let's see, I'm going to turn debug logging for all the gateways and see if that helps show where we're losing the thread [21:13:27] oh hey, Token match: false [21:13:35] problem with the edit token? [21:15:05] how the heck would that just be happening there? [21:16:45] hmm, paypal legacy is still not logging anything past the constructor [21:17:49] ah, it is logging some stuff, but that's all going to payments.debug [21:51:42] ok, so payments1004 does seem to have more of the logging than I saw at first [21:51:55] what seems to be broken is the edit tokens on payments2003 [21:56:38] where are those stored? [21:57:08] they're stored in session, and then written to a hidden field on the payments form [21:57:22] could it have to do with ip/url? [21:57:30] is that in php's cache? memcache? [21:58:04] cwd that's what I was thinking, but it looks like it's just some random numbers [22:00:05] https://github.com/wikimedia/mediawiki-extensions-DonationInterface/blob/master/gateway_common/gateway.adapter.php#L3190 [22:01:14] what about token_getSaltedSessionToken below? [22:01:28] that does some juggling withthe value [22:05:17] hmm, there's a Salt global, but that's the same on both machines [22:15:41] ok, again this is looking like the upgrade is fine in the primary datacenter [22:16:02] I'd really like to move ahead with the main dc upgrade! [22:18:16] ok, looks like we're just not saving sessions right on payments2003 [22:18:38] we're re-generating contribution tracking IDs too [22:21:51] so what do you think, cwd and Jeff_Green, can we decouple the testing of the backup DC hosts from the testing of the upgrade in the main DC? [22:22:20] I'd really like to get the upgrade done [22:22:35] no, I think if we don't understand why it's breaking at codfw, we can't be confident it won't break on newly imaged hosts in eqiad [22:22:58] and there's not really a good rollback option if it doesn't go reasonably well [22:23:03] so is the existing version working in codfw? [22:23:24] good question, we can test that pretty easily--sec [22:26:53] ejegg: ok we're switched to payments2001 [22:27:12] Jeff_Green: hah, prod traffic is going there now? [22:27:27] just https://payments.frdev.wikimedia.org [22:27:32] ah, ok [22:28:27] I'm gonna have to run in a minute, dinner plans [22:28:49] Jeff_Green: getting the same error on 2001 [22:29:34] interesting! [22:29:42] or.. looks the same from client side, but it's a different error in the back [22:30:33] ok, that's an IP address issue [22:31:44] ok I gotta run, ejegg sorry-but I can work with you on this tomorrow [22:31:55] ok, have a good night [22:31:59] you too [22:32:58] looking at session cookies [22:33:16] cwd can you switch payments.frdev back to payments2003? [22:33:59] ok, one minute [22:34:02] does that version work? [22:39:44] so the version on 2001 (based on mw 1.27) doesn't seem to have the session problem [22:40:27] ejegg: ok should be back [22:40:45] the session problem = the token mismatch? [22:40:59] right, the token mismatch was the first thing I noticed [22:41:20] but then I noticed we're also getting a new contribution tracking ID [22:41:37] so I'm guessing the whole session is not persisting on 2003 [22:41:40] on each pageload? [22:41:45] yeah [22:41:49] hrm [22:42:06] well, at least between the first pageload and the post back, on astropay and old paypal [22:43:54] hmm, it's definitely posting back the same session cookie that's sent in set_cookie on the initial request [22:43:56] ejegg: could the processors be using the normal urls? [22:44:08] w/o frdev [22:44:15] cwd this is before we're even redirecting to a processor [22:44:50] ah ok [22:45:05] we're getting another set-cookie header with a different session cookie as the response to the post [22:45:18] so.. is nginx passing the cookies to apache? [22:45:40] can you tell in the apache logs on 2003 if the cookies are coming through? [22:45:58] specifically on a recent post to Special:AstroPayGateway? [22:46:00] i'll check [22:46:43] XenoRyet|food: want to help figure this out? [22:47:00] I've got to head to the airport soon, but I really want to get this upgrade done this sprint [22:47:42] i don't see cookies in the logs [22:47:44] just urls [22:47:49] cwd oho [22:47:56] are they there on e.g. 1004? [22:48:17] Yea, let me catch up on backscroll and what not [22:48:24] oh, forgot the nick again. [22:49:10] nah i don't think cookies are logged anywhere [22:49:41] nor are POSTs [22:49:44] just get strings [22:50:02] right, the cookie would just be a header [22:51:30] cwd so how can we determine if apache is getting the cookies? [22:52:56] nginx is doing the same proxy as ever [22:53:05] http://nginx.org/en/docs/http/ngx_http_proxy_module.html#proxy_pass [22:53:36] it seems unlikely it would mess with headers [22:54:26] can we turn on more logging? [22:54:46] it sure looks like headers are being discarded someplace [22:55:14] though i guess it could have to do with the changed url [23:00:20] it looks like apache can be extended tolog headers https://stackoverflow.com/questions/9948064/is-it-possible-to-log-all-http-request-headers-with-apache [23:00:30] well, no, the URL didn't break things for 2001 [23:00:51] cwd we could test the URL theory if you let me log into 2003 to tunnel [23:02:10] shoot, I gotta head out. [23:02:18] how would tunneling help? [23:02:31] it's serving a cert for frdev [23:02:34] cwd I could try out payments2003 with the normal URL [23:02:47] you'd get a cert mismatch tho [23:03:43] could we replicate 1004 completely on 2003? [23:04:01] I think we've verified the visual stuff we needed to do on different devices [23:04:35] how do you mean replicate? [23:04:41] XenoRyet: I'll be on mobile for the next couple hrs if you want [23:04:43] they should be the same [23:04:53] 10-4 [23:05:04] cwd I mean make it answer to the normal payments URL with all the same nginx config etc [23:05:43] XenoRyet: so the current issue is that on payments.frdev, we keep getting new sessions every time we post [23:05:51] but not on the upgraded payments1004 [23:06:02] (or every page load, I think) [23:06:08] that could be explored [23:06:48] Ok, I'll see what kind of digging I can do on that.