run Gratipay 274

[gratipay-bot]

← Payday 273

---

Runbook

http://inside.gratipay.com/howto/run-payday

Checklist

• [ ] Review accounts
  • [ ] New givers
  • [ ] 1.0 Payout applications
• [ ] Trigger backup
• [ ] Run payday script
• [ ] Commit payday logs
• [ ] Run masspay
  • [ ] DB query to update broken paypal fees
  • [ ] Generate paypal inputs
  • [ ] Verify there is no fee mismatch
  • [ ] Submit masspay on paypal
  • [ ] Post back masspay
• [ ] Commit masspay logs
• [ ] Shuffle escrow
• [ ] Review decline rate

Rotation

Month	Pilot	Copilot
September	@whit537 :airplane:	@clone1018
October	rohitpaulk	whit537
November	clone1018	rohitpaulk
December	whit537	clone1018
January	rohitpaulk	whit537
February	clone1018	rohitpaulk
March	whit537	clone1018
April	rohitpaulk	whit537
May	clone1018	rohitpaulk
June	whit537	clone1018
July	rohitpaulk	whit537
August	clone1018	rohitpaulk

[chadwhitacre]

Accounts reviewed.

[chadwhitacre]

/me sets his clock to Honolulu time ... 😁

[chadwhitacre]

Problem taking backup:

pg_dump: error reading large object 21839: SSL SYSCALL error: Operation timed out

It was pretty much done, too. :-/

And now my comment won't post.

whit537.org won't load.

Wireless on my laptop is dead?

It's off but it shows as on in the status bar?

Restarting computer.

Now getting "Wi-Fi: No hardware installed". I saw this for the first time a week ago. Re-restart cleared it up, iirc?

[chadwhitacre]

😓

[chadwhitacre]

Backup restarted ...

[chadwhitacre]

Backup finished and verified.

[chadwhitacre]

Started script, saw Sept 1 and killed it. UTC! Restarted ...

[gratipay] $ ./payday.sh 274 for_real_please
Run payday #274? (y/N) y
Run payday #274 FOR REAL?!?!?!??!?!? (y/N) y
Logging to ../logs/payday/gratipay-274.log.

Fri Sep  1 08:39:21 UTC 2017
^C
[gratipay] $ ./payday.sh 274 for_real_please
Rerun payday #274? (y/N) y
Rerun payday #274 FOR REAL?!?!?!??!?!? (y/N) y

[chadwhitacre]

Saw a TypeError, realized I might not be on master, killed it right after "Greetings, program! It's Payday!"

[chadwhitacre]

But now it looks like the script kept running? 😞

[gratipay] $ tail -n19 ../logs/payday/gratipay-274.log
pid-1658 thread-140737185432512 (MainThread) Captured 39 card holds.
pid-1658 thread-140737185432512 (MainThread) Canceling card holds.
pid-1658 thread-140737185432512 (MainThread) Canceled 0 card holds.
pid-1658 thread-140737185432512 (MainThread) Updating balances.
pid-1658 thread-140737185432512 (MainThread) Updated the balances of 270 participants.
pid-1658 thread-140737185432512 (MainThread) Taking over balances.
pid-1658 thread-140737185432512 (MainThread) Updating stats.
pid-1658 thread-140737185432512 (MainThread) Updated payday stats.
pid-1658 thread-140737185432512 (MainThread) Notifying participants.
pid-1658 thread-140737185432512 (MainThread) Traceback (most recent call last):
pid-1658 thread-140737185432512 (MainThread)   File "/Users/whit537/personal/gratipay/gratipay.com/gratipay/cli/payday.py", line 11, in main
pid-1658 thread-140737185432512 (MainThread)     Application().payday_runner.run_payday()
pid-1658 thread-140737185432512 (MainThread)   File "/Users/whit537/personal/gratipay/gratipay.com/gratipay/payday_runner.py", line 27, in run_payday
pid-1658 thread-140737185432512 (MainThread)     self._start_payday().run()
pid-1658 thread-140737185432512 (MainThread)   File "/Users/whit537/personal/gratipay/gratipay.com/gratipay/billing/payday.py", line 90, in run
pid-1658 thread-140737185432512 (MainThread)     self.notify_participants()
pid-1658 thread-140737185432512 (MainThread)   File "/Users/whit537/personal/gratipay/gratipay.com/gratipay/billing/payday.py", line 480, in notify_participants
pid-1658 thread-140737185432512 (MainThread)     _user_initiated=False
pid-1658 thread-140737185432512 (MainThread) TypeError: put() takes exactly 5 arguments (3 given)

[chadwhitacre]

I've shelved my work on gratipay/gratipay.com#4548 and am back on master.

[chadwhitacre]

I am reading payday.py to determine if I should re-run w/o any code changes (commenting out).

[chadwhitacre]

gratipay::DATABASE=> select * from paydays order by ts_end desc limit 1;
┌─────┬───────────────────────────────┬───────────────────────────────┬────────┬────────┬───────┬────────┐
│ id  │           ts_start            │            ts_end             │ volume │ nusers │ stage │ nteams │
├─────┼───────────────────────────────┼───────────────────────────────┼────────┼────────┼───────┼────────┤
│ 340 │ 2017-09-01 08:39:53.223145+00 │ 2017-09-01 08:40:37.939528+00 │ 654.94 │    499 │     2 │    231 │
└─────┴───────────────────────────────┴───────────────────────────────┴────────┴────────┴───────┴────────┘
(1 row)

gratipay::DATABASE=>

[chadwhitacre]

Since stage is 2 a re-rerun will skip payin and update_stats. We'll hit end a second time, but that'll be a no-op since there's no payday with ts_end 1970.

[chadwhitacre]

Okay, that sucked.

I re-ran ... and it started a new payday! And so I ctrl-c'd right at "It's payday!" ... and then remembered that that wasn't enough to kill the script last time! So I did a ps and kill 1823 as fast as I could ... and I think it was enough?

gratipay::DATABASE=> select * from paydays order by ts_end desc limit 1;
┌─────┬───────────────────────────────┬───────────────────────────────┬────────┬────────┬───────┬────────┐
│ id  │           ts_start            │            ts_end             │ volume │ nusers │ stage │ nteams │
├─────┼───────────────────────────────┼───────────────────────────────┼────────┼────────┼───────┼────────┤
│ 340 │ 2017-09-01 08:39:53.223145+00 │ 2017-09-01 08:40:37.939528+00 │ 654.94 │    499 │     2 │    231 │
└─────┴───────────────────────────────┴───────────────────────────────┴────────┴────────┴───────┴────────┘
(1 row)

gratipay::DATABASE=>

[chadwhitacre]

There is no log for 275. Why not? 👀

[gratipay] $ less ../logs/payday/gratipay-27
gratipay-270.log  gratipay-274.log  

[chadwhitacre]

Because I ran it as 274, so new messages are appended to 274.

[gratipay] $ ./payday.sh 274 for_real_please

[chadwhitacre]

Thankfully, it appears that I killed the process in the nick of time. I see card holds but no captures. 😓 💦

[chadwhitacre]

Sooooo, we will want to cancel all of those card holds, but we can do that later today.

[chadwhitacre]

For now we need to get back on track with notifications.

[chadwhitacre]

And then finish running payday.

[chadwhitacre]

There it is:

gratipay::DATABASE=> select * from paydays order by ts_start desc limit 2;
┌─────┬───────────────────────────────┬───────────────────────────────┬────────┬────────┬───────┬────────┐
│ id  │           ts_start            │            ts_end             │ volume │ nusers │ stage │ nteams │
├─────┼───────────────────────────────┼───────────────────────────────┼────────┼────────┼───────┼────────┤
│ 341 │ 2017-09-01 08:52:48.150756+00 │ 1970-01-01 00:00:00+00        │   0.00 │      0 │     0 │      0 │
│ 340 │ 2017-09-01 08:39:53.223145+00 │ 2017-09-01 08:40:37.939528+00 │ 654.94 │    499 │     2 │    231 │
└─────┴───────────────────────────────┴───────────────────────────────┴────────┴────────┴───────┴────────┘
(2 rows)

[chadwhitacre]

We'll have to clean that up later as well. 😞

[chadwhitacre]

... or now? I believe in order to rerun without picking up the new, wrong payday, what we need to do is delete 341, and reset ts_end on 340 back to 1970-01-01 00:00:00+00.

[chadwhitacre]

gratipay::DATABASE=> update paydays set ts_end='1970-01-01 00:00:00+00' where id=340;
ERROR:  duplicate key value violates unique constraint "paydays_ts_end_key"
DETAIL:  Key (ts_end)=(1970-01-01 00:00:00+00) already exists.
gratipay::DATABASE=> delete from paydays where id=341;
DELETE 1
gratipay::DATABASE=> update paydays set ts_end='1970-01-01 00:00:00+00' where id=340;
UPDATE 1
gratipay::DATABASE=>

[chadwhitacre]

gratipay::DATABASE=> select * from paydays order by ts_start desc limit 2;
┌─────┬───────────────────────────────┬───────────────────────────────┬────────┬────────┬───────┬────────┐
│ id  │           ts_start            │            ts_end             │ volume │ nusers │ stage │ nteams │
├─────┼───────────────────────────────┼───────────────────────────────┼────────┼────────┼───────┼────────┤
│ 340 │ 2017-09-01 08:39:53.223145+00 │ 1970-01-01 00:00:00+00        │ 654.94 │    499 │     2 │    231 │
│ 339 │ 2017-08-24 21:48:50.552623+00 │ 2017-08-24 21:49:28.799672+00 │ 680.26 │    501 │     2 │    230 │
└─────┴───────────────────────────────┴───────────────────────────────┴────────┴────────┴───────┴────────┘
(2 rows)

gratipay::DATABASE=>

[chadwhitacre]

Okay! So now a rerun will pick up 340, see stage 2, skip payin and update_stats, and proceed to end and then notify_participants.

[chadwhitacre]

😅

pid-1947 thread-140737185432512 (MainThread) Picking up with an existing payday.
pid-1947 thread-140737185432512 (MainThread) Payday started at 2017-09-01 08:39:53.223145+00:00.
count#npm-sync-lag=1
pid-1947 thread-140737185432512 (MainThread) Greetings, program! It's PAYDAY!!!!
pid-1947 thread-140737185432512 (MainThread) Notifying participants.
pid-1947 thread-140737185432512 (MainThread) Script ran for six seconds (0:00:06.933801).

[chadwhitacre]

I really don't like that we're installing cron jobs during payday (could we be flushing email from local!?), but that's another story as well.

[chadwhitacre]

Gosh! Okay!

[chadwhitacre]

On to MassPay ...

gratipay::DATABASE=> update exchange_routes set fee_cap = 20.00 where fee_cap is null and network = 'paypal';
UPDATE 17
gratipay::DATABASE=>

[chadwhitacre]

P.S. It looks like two failures from the second (bad) payday run ended up in the exchanges table. Looks like we don't record holds in exchanges (sounds familiar).

[chadwhitacre]

Notification received.

[chadwhitacre]

We send notifications based on querying exchanges for the time range of the payday, so I wanted to see who we were sending to. Maybe some duplicates?

[chadwhitacre]

Interestingly, the final hold in the bad payday was declined, but there's no record in exchanges, which means we can see fairly precisely when I finally killed the bad payday.

[chadwhitacre]

Okay! So two people got notifications of card failures that they wouldn't otherwise have gotten until next week, but nobody got a duplicate notification. I think we can live with that.

[chadwhitacre]

One of the declines doesn't have an email address on file anyway.

gratipay::DATABASE=> select spt_name, em.ctime, result from email_messages em join participants p on p.id=em.participant order by em.ctime desc;
┌─────────────────────┬───────────────────────────────┬──────────────────┐
│      spt_name       │             ctime             │      result      │
├─────────────────────┼───────────────────────────────┼──────────────────┤
│ charge_failed       │ 2017-09-01 09:08:22.058763+00 │                  │
│ charge_failed       │ 2017-09-01 09:08:21.907274+00 │ NoEmailAddress() │
│ charge_succeeded    │ 2017-09-01 09:08:21.746209+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:21.58977+00  │                  │
│ charge_succeeded    │ 2017-09-01 09:08:21.446751+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:21.289434+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:21.137785+00 │ NoEmailAddress() │
│ charge_succeeded    │ 2017-09-01 09:08:20.980088+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:20.826071+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:20.672252+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:20.522129+00 │ NoEmailAddress() │
│ charge_succeeded    │ 2017-09-01 09:08:20.363292+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:20.227381+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:20.073215+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:19.9272+00   │                  │
│ charge_succeeded    │ 2017-09-01 09:08:19.778894+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:19.639222+00 │                  │
│ charge_succeeded    │ 2017-09-01 09:08:19.49727+00  │                  │
...

[chadwhitacre]

Alright, MassPay. What surprises do you have in store for us?

[chadwhitacre]

I WASN"T SERIOUS.

The widget for uploading a CSV is unresponsive. The button does not appear to be clickable.

[chadwhitacre]

The sign-in flow was also off a tad ... something with my browser? Or PayPal?

[chadwhitacre]

To the Firefox!

[chadwhitacre]

FF better so far. In Chrome I couldn't see the item in the dropdown where I select the number to use for 2FA (though I could still submit the form and I guess the right number was selected because I got the text). In FF I see the number to begin with.

[chadwhitacre]

Sure enough, the upload works in FF. ¯\_(ツ)_/¯

[chadwhitacre]

MassPay submitted.

Logs in https://github.com/gratipay/logs/commit/f44a207ae359106342b08eded9a7f1f34e6f41c1.

[chadwhitacre]

POSTed MassPay back to Gratipay for 70 users.

[chadwhitacre]

Braintree is showing all of the extra holds, but the decline rate is acceptable (7 / 78 = 10%).

[chadwhitacre]

Escrow Shuffle

	$
MassPay	1,548.20
5x	7,741.00
Balance	7,200.81
Added	0.00

[chadwhitacre]

Alright, that was adventurous. And it's still Thursday in Honolulu! Didn't even have to go to Samoa. :)

[chadwhitacre]

Actually, reopening to post-mortem and reticket ...

[rohitpaulk]

That was eventful..

[chadwhitacre]

I'm working on canceling the card holds.