Closed dirkkelly closed 9 years ago
dirkkelly
commented
9 years ago I've turned on the testing password so I can review through mandrill and papertrail.
I've recently pulled the latest codeforamerica, it's likely I'll be testing this through a production deploy today.
dirkkelly
commented
9 years ago dirkkelly
commented
9 years ago How many database connections will I need? How do I figure out connection pool size? Consider a Heroku setup like this:
1 * 4 * 10 = 40 connectionsIf you are using Postgres Hobby Basic plan, we're not
(Sidekiq workers can use databse too, so don't forget to subtract it.)
2 dynos * 2 workers * 5 thread = 20 connections (pool is 5) 1 dyno * 2 workers * 10 threads = 20 connections (pool is 10) 1 dyno * 1 worker * 20 threads = 20 connections (pool is 20)
1 dyno * 1 worker * 10 threads = 10 connectionsRealized I had never deployed the gem ruby update to staging, reverting production
dirkkelly
commented
9 years ago revertin' :warning:
master (dk) [$]
$ heroku releases -a citygram-nyc
=== citygram-nyc Releases
v88 Deploy 19a05d5 heroku@dirkkelly.com 2015/07/19 12:31:52 (~ 3m ago)
v87 Deploy a0233c9 heroku@dirkkelly.com 2015/07/19 12:13:28 (~ 22m ago)
v86 Set SMTP_PASSWORD config vars dkelly@interexchange.org 2015/07/19 11:08:04 (~ 1h ago)
v85 Attach PAPERTRAIL resource dkelly@interexchange.org 2015/07/08 08:09:55
v84 Set DIGEST_DAY config vars dkelly@interexchange.org 2015/06/28 09:46:43
v83 Remove pgbackups:plus add-on billing-2014-heroku@codeforamerica.org 2015/05/23 01:59:43
v82 Detach PGBACKUPS (@ref:thinking-slyly-.. billing-2014-heroku@codeforamerica.org 2015/05/23 01:59:43
v81 Attach DATABASE resource heroku@dirkkelly.com 2015/05/20 22:56:22
v80 Attach HEROKU_POSTGRESQL_GRAY resource billing-2014-heroku@codeforamerica.org 2015/05/04 17:29:56
v79 Deploy a3041a3 heroku@dirkkelly.com 2015/02/21 22:47:46
v78 Deploy b5f90f1 heroku@dirkkelly.com 2015/02/21 14:04:46
v77 Deploy 3090477 heroku@dirkkelly.com 2015/02/21 13:08:38
v76 Set APPLICATION_URL config vars heroku@dirkkelly.com 2015/02/19 03:57:39
v75 Set SMTP_ADDRESS, SMTP_FROM_ADDRES, SM.. heroku@dirkkelly.com 2015/02/19 01:35:39
v74 Deploy 23d3914 heroku@dirkkelly.com 2015/02/19 01:30:52
dirkkelly@spring:~/src/betanyc/citygram-nyc
master (dk) [$]
$ git push cit
citygram-nyc citygram-nyc-311 citygram-nyc-codeforamerica citygram-nyc-staging
dirkkelly@spring:~/src/betanyc/citygram-nyc
master (dk) [$]
$ git push citygram-nyc a3041a3:master -fPushing staging to production, migrations have been running for 5 minutes so far :\
dirkkelly
commented
9 years ago It's doing something
citygram-nyc::DATABASE=> SELECT * FROM pg_stat_activity limit 100;datid | datname | pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | waiting | state | backend_xid | backend_xmin | query -------+----------------+-------+----------+----------------+-------------------------------------------+---------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+---------+--------+-------------+--------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 16385 | d38nsltkku6750 | 20498 | 16387 | collectd | | | | | | | | | | | | | <insufficient privilege> 16385 | d38nsltkku6750 | 2185 | 16384 | uamvstggeftna8 | /app/vendor/bundle/ruby/2.1.0/bin/sidekiq | 10.5.151.72 | | 35241 | 2015-07-19 19:07:25.853759+00 | | 2015-07-19 19:07:25.899757+00 | 2015-07-19 19:07:25.900946+00 | f | idle | | | SELECT "pg_attribute"."attname" AS "name", CAST("pg_attribute"."atttypid" AS integer) AS "oid", CAST("basetype"."oid" AS integer) AS "base_oid", format_type("basetype"."oid", "pg_type"."typtypmod") AS "db_base_type", format_type("pg_type"."oid", "pg_attribute"."atttypmod") AS "db_type", pg_get_expr("pg_attrdef"."adbin", "pg_class"."oid") AS "default", NOT "pg_attribute"."attnotnull" AS "allow_null", COALESCE(("pg_attribute"."attnum" = ANY("pg_index"."indkey")), false) AS "primary_key" FROM "pg_class" INNER JOIN "pg_attribute" ON ("pg_attribute"."attrelid" = "pg_class"."oid") INNER JOIN "pg_type" ON ("pg_type"."oid" = "pg_attribute"."atttypid") LEFT OUTER JOIN "pg_type" AS "basetype" ON ("basetype"."oid" = "pg_type"."typbasetype") LEFT OUTER JOIN "pg_attrdef" ON (("pg_attrdef"."adrelid" = "pg_class"."oid") AND ("pg_attrdef"."adnum" = "pg_attribute"."attnum")) LEFT OUTER JOIN "pg_index" ON (("pg_index"."indrelid" = "pg_class"."oid") AND ("pg_index"."indisprimary" IS TRUE)) WHERE (("pg_attribute"."attisdropped" 16385 | d38nsltkku6750 | 2214 | 16384 | uamvstggeftna8 | unicorn worker[0] -c ./config/unicorn.rb | 10.170.52.173 | | 51577 | 2015-07-19 19:08:16.46055+00 | | 2015-07-19 19:25:46.529049+00 | 2015-07-19 19:25:46.529388+00 | f | idle | | | SELECT * FROM "publishers" WHERE (("active" IS TRUE) AND ("visible" IS TRUE) AND ('seattle' = ANY (tags))) 16385 | d38nsltkku6750 | 3065 | 16384 | uamvstggeftna8 | /app/vendor/bundle/ruby/2.1.0/bin/rake | 10.11.11.35 | | 49116 | 2015-07-19 19:17:06.516805+00 | 2015-07-19 19:17:06.542595+00 | 2015-07-19 19:18:54.564379+00 | 2015-07-19 19:18:54.564381+00 | f | active | 303599 | 303599 | UPDATE events SET tmp_properties = properties::json 16385 | d38nsltkku6750 | 5314 | 16384 | uamvstggeftna8 | psql dirkkelly interactive | 74.73.228.137 | | 44318 | 2015-07-19 19:24:27.908741+00 | 2015-07-19 19:25:52.105257+00 | 2015-07-19 19:25:52.105257+00 | 2015-07-19 19:25:52.10526+00 | f | active | | 303599 | SELECT * FROM pg_stat_activity limit 100;
dirkkelly
commented
9 years ago citygram-nyc::DATABASE=> select * from schema_info; version --------- 24 (1 row)
Long running migration I believe
dirkkelly
commented
9 years ago Just finished!
dirkkelly
commented
9 years ago Running a lot better
Jul 19 12:27:57 citygram-nyc heroku/run.5696: Starting process with command `bundle exec rake digests:send` Jul 19 12:27:57 citygram-nyc heroku/router: at=info method=GET path="/" host=www.citygram.nyc request_id=e6b912c4-3cb9-4f44-80ae-86af4ed2a8b2 fwd="54.247.188.179" dyno=web.1 connect=0ms service=21ms status=200 bytes=10394 Jul 19 12:27:57 citygram-nyc heroku/run.5696: State changed from starting to up Jul 19 12:28:00 citygram-nyc heroku/router: at=info method=GET path="/" host=www.citygram.nyc request_id=a0534736-b871-4b73-8bdc-50089ec876b9 fwd="54.251.34.67" dyno=web.1 connect=4ms service=14ms status=200 bytes=10394 Jul 19 12:28:00 citygram-nyc app/worker.1: 2015-07-19T19:28:00.230Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-12bd7acd07d0a2d62d8394b1 INFO: start Jul 19 12:28:00 citygram-nyc app/worker.1: 2015-07-19T19:28:00.434Z 3 TID-oxqm67kso Citygram::Workers::Notifier JID-292ee832de946c3df2d54258 INFO: start Jul 19 12:28:00 citygram-nyc app/worker.1: 2015-07-19T19:28:00.639Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-3736fc8007f9adcd55cd3cd6 INFO: start Jul 19 12:28:01 citygram-nyc app/worker.1: 2015-07-19T19:28:00.721Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-12bd7acd07d0a2d62d8394b1 INFO: done: 0.49 sec Jul 19 12:28:01 citygram-nyc app/worker.1: 2015-07-19T19:28:00.742Z 3 TID-oxqm67kso Citygram::Workers::Notifier JID-292ee832de946c3df2d54258 INFO: done: 0.307 sec Jul 19 12:28:01 citygram-nyc app/worker.1: 2015-07-19T19:28:00.759Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-3736fc8007f9adcd55cd3cd6 INFO: done: 0.12 sec Jul 19 12:28:01 citygram-nyc app/worker.1: 2015-07-19T19:28:01.008Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-c4b69c661b7b02b691d0a986 INFO: start Jul 19 12:28:01 citygram-nyc app/worker.1: 2015-07-19T19:28:01.473Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-c4b69c661b7b02b691d0a986 INFO: done: 0.466 sec Jul 19 12:28:02 citygram-nyc app/worker.1: 2015-07-19T19:28:01.750Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-2f2359c3854ad43ea19bdc7d INFO: start Jul 19 12:28:02 citygram-nyc app/worker.1: 2015-07-19T19:28:02.106Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-2f2359c3854ad43ea19bdc7d INFO: done: 0.356 sec Jul 19 12:28:02 citygram-nyc app/worker.1: 2015-07-19T19:28:02.586Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-ff41c1ef1cea61c678ac54f7 INFO: start Jul 19 12:28:02 citygram-nyc app/worker.1: 2015-07-19T19:28:02.626Z 3 TID-oxqm67kso Citygram::Workers::Notifier JID-72e3fa799f1d86ccb9e9abc3 INFO: start Jul 19 12:28:03 citygram-nyc app/worker.1: 2015-07-19T19:28:02.850Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-81ea08ef835a34d3d8eba27e INFO: start Jul 19 12:28:03 citygram-nyc app/worker.1: 2015-07-19T19:28:02.934Z 3 TID-oxqm67kso Citygram::Workers::Notifier JID-72e3fa799f1d86ccb9e9abc3 INFO: done: 0.308 sec Jul 19 12:28:03 citygram-nyc app/worker.1: 2015-07-19T19:28:02.946Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-ff41c1ef1cea61c678ac54f7 INFO: done: 0.361 sec Jul 19 12:28:03 citygram-nyc app/worker.1: 2015-07-19T19:28:02.967Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-81ea08ef835a34d3d8eba27e INFO: done: 0.116 sec Jul 19 12:28:05 citygram-nyc app/postgres.5826: [DATABASE] duration: 2702.521 ms statement: SELECT count(*) AS "count" FROM ( SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:02.808054+0000' AND events.created_at <= '2015-07-19 19:28:02.808140+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-73.92303737475662 40.68675242883365,-73.90394862524344 40.68675242883365,-73.90394862524344 40.70122557116633,-73.92303737475662 40.70122557116633,-73.92303737475662 40.68675242883365))'::geometry) ORDER BY events.created_at DESC ) AS "t1" LIMIT 1 Jul 19 12:28:05 citygram-nyc app/worker.1: 2015-07-19T19:28:05.528Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-7cec6bfc815f2cd8311e0f3c INFO: start Jul 19 12:28:06 citygram-nyc app/postgres.11: [DATABASE] checkpoint starting: xlog Jul 19 12:28:06 citygram-nyc app/worker.1: 2015-07-19T19:28:06.301Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-7cec6bfc815f2cd8311e0f3c INFO: done: 0.774 sec Jul 19 12:28:14 citygram-nyc app/postgres.5826: [DATABASE] duration: 9224.582 ms statement: SELECT count(*) AS "count" FROM ( SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:05.516482+0000' AND events.created_at <= '2015-07-19 19:28:05.516569+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-73.96961642902257 40.75782375766732,-73.93139397097735 40.75782375766732,-73.93139397097735 40.78677004233269,-73.96961642902257 40.78677004233269,-73.96961642902257 40.75782375766732))'::geometry) ORDER BY events.created_at DESC ) AS "t1" LIMIT 1 Jul 19 12:28:15 citygram-nyc app/worker.1: 2015-07-19T19:28:14.753Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-ffec6f63187f78a5fa53153a INFO: start Jul 19 12:28:18 citygram-nyc app/worker.1: 2015-07-19T19:28:17.871Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-ffec6f63187f78a5fa53153a INFO: done: 3.118 sec Jul 19 12:28:40 citygram-nyc app/heroku-postgres: source=DATABASE sample#current_transaction=303604 sample#db_size=5154213652bytes sample#tables=6 sample#active-connections=6 sample#waiting-connections=0 sample#index-cache-hit-rate=0.94228 sample#table-cache-hit-rate=0.30555 sample#load-avg-1m=0.215 sample#load-avg-5m=0.875 sample#load-avg-15m=0.665 sample#read-iops=0.5 sample#write-iops=619.5 sample#memory-total=15405664kB sample#memory-free=1914912kB sample#memory-cached=12507724kB sample#memory-postgres=417212kB Jul 19 12:28:43 citygram-nyc app/heroku-postgres: source=HEROKU_POSTGRESQL_YELLOW sample#current_transaction=957064 sample#db_size=1686907064bytes sample#tables=6 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.83347 sample#table-cache-hit-rate=0.16187 sample#load-avg-1m=0.06 sample#load-avg-5m=0.135 sample#load-avg-15m=0.15 sample#read-iops=0 sample#write-iops=3.6738 sample#memory-total=7629440kB sample#memory-free=567408kB sample#memory-cached=6537984kB sample#memory-postgres=180820kB Jul 19 12:28:46 citygram-nyc heroku/router: at=info method=GET path="/" host=www.citygram.nyc request_id=909f3af3-5541-40ea-9cb2-0ffb76432883 fwd="54.248.250.232" dyno=web.1 connect=2ms service=38ms status=200 bytes=10394 Jul 19 12:28:50 citygram-nyc app/postgres.5826: [DATABASE] duration: 35141.506 ms statement: SELECT count(*) AS "count" FROM ( SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:14.748369+0000' AND events.created_at <= '2015-07-19 19:28:14.748466+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-74.04428317879403 40.5945557153346,-73.96800882120597 40.5945557153346,-73.96800882120597 40.65244828466537,-74.04428317879403 40.65244828466537,-74.04428317879403 40.5945557153346))'::geometry) ORDER BY events.created_at DESC ) AS "t1" LIMIT 1 Jul 19 12:28:50 citygram-nyc app/worker.1: 2015-07-19T19:28:49.903Z 3 TID-oxqm4q0f0 Citygram::Workers::Notifier JID-89dd8132e99acd926ae58a8c INFO: start Jul 19 12:28:50 citygram-nyc app/worker.1: 2015-07-19T19:28:50.146Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-741d6433c590f834507b34c3 INFO: start Jul 19 12:28:50 citygram-nyc app/worker.1: 2015-07-19T19:28:50.265Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-741d6433c590f834507b34c3 INFO: done: 0.119 sec Jul 19 12:28:51 citygram-nyc app/worker.1: 2015-07-19T19:28:51.639Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-d96ed9a8113234731ed5fae7 INFO: start Jul 19 12:28:52 citygram-nyc app/worker.1: 2015-07-19T19:28:52.282Z 3 TID-oxqm64f3c Citygram::Workers::Notifier JID-d96ed9a8113234731ed5fae7 INFO: done: 0.643 sec Jul 19 12:28:53 citygram-nyc app/postgres.6303: [DATABASE] duration: 3052.887 ms statement: SELECT count(*) AS "count" FROM ( SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:49.956417+0000' AND events.created_at <= '2015-07-19 19:28:49.956508+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-74.04428317879403 40.5945557153346,-73.96800882120597 40.5945557153346,-73.96800882120597 40.65244828466537,-74.04428317879403 40.65244828466537,-74.04428317879403 40.5945557153346))'::geometry) ORDER BY events.created_at DESC ) AS "t1" LIMIT 1 Jul 19 12:28:55 citygram-nyc heroku/router: at=info method=GET path="/" host=www.citygram.nyc request_id=d7219285-ff92-44d2-8f07-a1dc34a8407a fwd="184.73.237.85" dyno=web.1 connect=4ms service=18ms status=200 bytes=10394 Jul 19 12:28:56 citygram-nyc app/postgres.6303: [DATABASE] duration: 2916.322 ms statement: SELECT count(*) AS "count" FROM ( SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:49.956417+0000' AND events.created_at <= '2015-07-19 19:28:49.956508+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-74.04428317879403 40.5945557153346,-73.96800882120597 40.5945557153346,-73.96800882120597 40.65244828466537,-74.04428317879403 40.65244828466537,-74.04428317879403 40.5945557153346))'::geometry) ORDER BY events.created_at DESC ) AS "t1" LIMIT 1 Jul 19 12:28:59 citygram-nyc app/postgres.6303: [DATABASE] duration: 3344.325 ms statement: SELECT events.* FROM events WHERE events.publisher_id = 1 AND events.created_at > '2015-07-12 19:28:49.956417+0000' AND events.created_at <= '2015-07-19 19:28:49.956508+0000' AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-74.04428317879403 40.5945557153346,-73.96800882120597 40.5945557153346,-73.96800882120597 40.65244828466537,-74.04428317879403 40.65244828466537,-74.04428317879403 40.5945557153346))'::geometry) ORDER BY events.created_at DESC
dirkkelly
commented
9 years ago On staging
UPDATE publishers SET tags='{new-york}';On Production
UPDATE publishers SET tags='{new-york}';production branch pushed to github, having issues on anything but this.
dirkkelly
commented
9 years ago Still got a timeout
dirkkelly
commented
9 years ago irb(main):010:0> ds = Sidekiq::DeadSet.new
=> #<Sidekiq::DeadSet:0x007fdc26d111e0 @name="dead", @_size=2118>
irb(main):011:0> ds.size
=> 2118
irb(main):013:0> ds.first
=> #<Sidekiq::SortedEntry:0x007fdc26ceae28 @value="{\"retry\":5,\"queue\":\"default\",\"class\":\"Citygram::Workers::Notifier\",\"args\":[\"f9f064fb-d2c0-4291-abfd-f8511a6246b2\",null],\"jid\":\"e90c26d94012949eaa459e0c\",\"enqueued_at\":1437318933.6024508,\"error_message\":\"Sequel::PoolTimeout\",\"error_class\":\"Sequel::PoolTimeout\",\"failed_at\":1437319049.655398,\"retry_count\":5,\"retried_at\":1437319948.245418}", @item={"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["f9f064fb-d2c0-4291-abfd-f8511a6246b2", nil], "jid"=>"e90c26d94012949eaa459e0c", "enqueued_at"=>1437318933.6024508, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1437319049.655398, "retry_count"=>5, "retried_at"=>1437319948.245418}, @queue="default", @score=1437319948.245718, @parent=#<Sidekiq::DeadSet:0x007fdc26d111e0 @name="dead", @_size=2118>>Sequel::PoolTimeout is really all I have to go by here.
Okay, so we (@excepttheweasel) are working on the assumption that the issue arose from the change from Heroku Postgres Crane to Standard-0.
This may have changed the way default pools were allocated to the connector, our solution is to up the max connections.
Testing has occurred using a test key from Mandrillapp.com.
We want to test with actual delivery, in order to do this we're going to update all subscriber emails in staging to be one which I own. And then run the digest send.
Let's see how we go.
dirkkelly
commented
9 years ago Here's how we figured out staging didn't have workers turned on, which is why we couldn't test efficiently.
stats = Sidekiq::Stats.new; puts stats.enqueued; puts stats.processed
In good news, successfully sent a digest email on the scheduler. Configuring it now for production.
Jul 22 19:30:10 citygram-nyc-staging heroku/api: Starting process with command `bundle exec rake digests:send_if_digest_day` by scheduler@addons.heroku.com Jul 22 19:30:25 citygram-nyc-staging heroku/scheduler.8148: Starting process with command `bundle exec rake digests:send_if_digest_day`
https://talk.beta.nyc/t/citygram-sending-failing/1218