Datenbankmigration stockt bei riesigem Wert eines "calendar-details"-Elements in der Tabelle "post_custom_fields"

amotl · 7. Dezember 2020 um 11:54

TLDR;

At post #4 ff., we have been able to confirm that this problem was related to Discourse Calendar (and Event) and the database migration was nudged into success after deactivating this temporarily – thanks @falco.
At post #9 ff., we found that the value of a specific calendar-details item on a single post contained ~80MB worth of data.
After deleting the offending row as outlined in post #13, the database migration has been fully successful even after enabling Discourse Calendar (and Event) again – thanks again, @falco.
The background on this is a database migration being applied since March 2020, see DEV: Migrate from custom fields to tables by nbianca · Pull Request #23 · discourse/discourse-calendar · GitHub. Thanks, @nbianca, @eviltrout and @j.jaffeux.

Dear Discourse developers,

after some time we had not been able to take care about our Discourse instances on https://community.hiveeyes.org/ and https://community.panodata.org/, we went into the process of upgrading them yesterday night.

The upgrade on the Hiveeyes Community Forum went pretty smooth as always. PostgreSQL was upgraded from version 10 to version 12 and it was a pleasure to watch the upgrade process without further ado. Kudos to the whole team for the excellent work you are putting into Discourse!

However, when trying to upgrade the Panodata Community Forum, we are observing some problems now. On the second stage of running ./launcher rebuild community.panodata.org, the system is experiencing extremely high load and currently grinds the whole machine.

I’ve kind of identified where this starts and will share some parts of the logs here. Apparently, it looks like the database migration process is running into a loop of some kind when touching the post_custom_fields table. Let me know if you need more information about that.

Did I manage to get ourselves into serious trouble here? I am very much looking forward on anything which could help us getting out of this situation.

Thank you in advance and with kind regards,
Andreas.

I, [2020-12-07T11:33:28.554810 #1]  INFO -- : > cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate'
2020-12-07 11:33:34.200 UTC [3888] discourse@discourse LOG:  duration: 119.116 ms  parse <unnamed>: SELECT t.oid, t.typname
	FROM pg_type as t
	WHERE t.typname IN ('int2', 'int4', 'int8', 'oid', 'float4', 'float8', 'bool', 'timestamp', 'timestamptz')

2020-12-07 11:33:34.413 UTC [3888] discourse@discourse LOG:  duration: 213.398 ms  bind <unnamed>: SELECT t.oid, t.typname
	FROM pg_type as t
	WHERE t.typname IN ('int2', 'int4', 'int8', 'oid', 'float4', 'float8', 'bool', 'timestamp', 'timestamptz')

2020-12-07 11:33:34.662 UTC [3888] discourse@discourse LOG:  duration: 220.921 ms  parse <unnamed>: SELECT t.oid, t.typname, t.typelem, t.typdelim, t.typinput, r.rngsubtype, t.typtype, t.typbasetype
	FROM pg_type as t
	LEFT JOIN pg_range as r ON oid = rngtypid
	WHERE
	  t.typname IN ('int2', 'int4', 'int8', 'oid', 'float4', 'float8', 'text', 'varchar', 'char', 'name', 'bpchar', 'bool', 'bit', 'varbit', 'timestamptz', 'date', 'money', 'bytea', 'point', 'hstore', 'json', 'jsonb', 'cidr', 'inet', 'uuid', 'xml', 'tsvector', 'macaddr', 'citext', 'ltree', 'line', 'lseg', 'box', 'path', 'polygon', 'circle', 'interval', 'time', 'timestamp', 'numeric')
	  OR t.typtype IN ('r', 'e', 'd')
	  OR t.typinput = 'array_in(cstring,oid,integer)'::regprocedure
	  OR t.typelem != 0

2020-12-07 11:33:34.820 UTC [3888] discourse@discourse LOG:  duration: 157.985 ms  bind <unnamed>: SELECT t.oid, t.typname, t.typelem, t.typdelim, t.typinput, r.rngsubtype, t.typtype, t.typbasetype
	FROM pg_type as t
	LEFT JOIN pg_range as r ON oid = rngtypid
	WHERE
	  t.typname IN ('int2', 'int4', 'int8', 'oid', 'float4', 'float8', 'text', 'varchar', 'char', 'name', 'bpchar', 'bool', 'bit', 'varbit', 'timestamptz', 'date', 'money', 'bytea', 'point', 'hstore', 'json', 'jsonb', 'cidr', 'inet', 'uuid', 'xml', 'tsvector', 'macaddr', 'citext', 'ltree', 'line', 'lseg', 'box', 'path', 'polygon', 'circle', 'interval', 'time', 'timestamp', 'numeric')
	  OR t.typtype IN ('r', 'e', 'd')
	  OR t.typinput = 'array_in(cstring,oid,integer)'::regprocedure
	  OR t.typelem != 0

2020-12-07 11:33:35.197 UTC [3888] discourse@discourse LOG:  duration: 376.904 ms  execute <unnamed>: SELECT t.oid, t.typname, t.typelem, t.typdelim, t.typinput, r.rngsubtype, t.typtype, t.typbasetype
	FROM pg_type as t
	LEFT JOIN pg_range as r ON oid = rngtypid
	WHERE
	  t.typname IN ('int2', 'int4', 'int8', 'oid', 'float4', 'float8', 'text', 'varchar', 'char', 'name', 'bpchar', 'bool', 'bit', 'varbit', 'timestamptz', 'date', 'money', 'bytea', 'point', 'hstore', 'json', 'jsonb', 'cidr', 'inet', 'uuid', 'xml', 'tsvector', 'macaddr', 'citext', 'ltree', 'line', 'lseg', 'box', 'path', 'polygon', 'circle', 'interval', 'time', 'timestamp', 'numeric')
	  OR t.typtype IN ('r', 'e', 'd')
	  OR t.typinput = 'array_in(cstring,oid,integer)'::regprocedure
	  OR t.typelem != 0

2020-12-07 11:33:35.388 UTC [3888] discourse@discourse LOG:  duration: 165.044 ms  statement: SELECT name, data_type, value FROM site_settings
2020-12-07 11:33:37.170 UTC [3888] discourse@discourse LOG:  duration: 166.378 ms  statement: SELECT a.attname, format_type(a.atttypid, a.atttypmod),
	       pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod,
	       c.collname, col_description(a.attrelid, a.attnum) AS comment
	  FROM pg_attribute a
	  LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum
	  LEFT JOIN pg_type t ON a.atttypid = t.oid
	  LEFT JOIN pg_collation c ON a.attcollation = c.oid AND a.attcollation <> t.typcollation
	 WHERE a.attrelid = '"users"'::regclass
	   AND a.attnum > 0 AND NOT a.attisdropped
	 ORDER BY a.attnum

2020-12-07 11:33:40.578 UTC [3888] discourse@discourse ERROR:  relation "user_api_key_scopes" does not exist at character 454
2020-12-07 11:33:40.578 UTC [3888] discourse@discourse STATEMENT:  SELECT a.attname, format_type(a.atttypid, a.atttypmod),
	       pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod,
	       c.collname, col_description(a.attrelid, a.attnum) AS comment
	  FROM pg_attribute a
	  LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum
	  LEFT JOIN pg_type t ON a.atttypid = t.oid
	  LEFT JOIN pg_collation c ON a.attcollation = c.oid AND a.attcollation <> t.typcollation
	 WHERE a.attrelid = '"user_api_key_scopes"'::regclass
	   AND a.attnum > 0 AND NOT a.attisdropped
	 ORDER BY a.attnum

2020-12-07 11:33:41.954 UTC [3898] discourse@discourse LOG:  duration: 232.874 ms  statement: CREATE TABLE "calendar_events" ("id" bigserial primary key, "topic_id" integer NOT NULL, "post_id" integer, "post_number" integer, "user_id" integer, "username" character varying, "description" character varying, "start_date" timestamp NOT NULL, "end_date" timestamp, "recurrence" character varying, "region" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
2020-12-07 11:33:42.693 UTC [3898] discourse@discourse LOG:  duration: 349.048 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:43.190 UTC [3898] discourse@discourse LOG:  duration: 289.433 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:43.692 UTC [3898] discourse@discourse LOG:  duration: 293.116 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:44.189 UTC [3898] discourse@discourse LOG:  duration: 288.891 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:44.622 UTC [3898] discourse@discourse LOG:  duration: 290.721 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:45.051 UTC [3898] discourse@discourse LOG:  duration: 291.924 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:45.544 UTC [3898] discourse@discourse LOG:  duration: 289.327 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:46.039 UTC [3898] discourse@discourse LOG:  duration: 291.734 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:46.471 UTC [3898] discourse@discourse LOG:  duration: 290.173 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:46.900 UTC [3898] discourse@discourse LOG:  duration: 288.805 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:47.392 UTC [3898] discourse@discourse LOG:  duration: 288.812 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:47.884 UTC [3898] discourse@discourse LOG:  duration: 286.272 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:48.326 UTC [3898] discourse@discourse LOG:  duration: 302.706 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:48.755 UTC [3898] discourse@discourse LOG:  duration: 288.766 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:49.260 UTC [3898] discourse@discourse LOG:  duration: 299.901 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:49.762 UTC [3898] discourse@discourse LOG:  duration: 293.430 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:50.192 UTC [3898] discourse@discourse LOG:  duration: 291.202 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:50.625 UTC [3898] discourse@discourse LOG:  duration: 293.805 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:51.138 UTC [3898] discourse@discourse LOG:  duration: 301.952 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:51.643 UTC [3898] discourse@discourse LOG:  duration: 291.137 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:52.075 UTC [3898] discourse@discourse LOG:  duration: 292.726 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:52.517 UTC [3898] discourse@discourse LOG:  duration: 301.480 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:53.027 UTC [3898] discourse@discourse LOG:  duration: 295.174 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:53.583 UTC [3898] discourse@discourse LOG:  duration: 292.007 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:54.025 UTC [3898] discourse@discourse LOG:  duration: 298.499 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:54.461 UTC [3898] discourse@discourse LOG:  duration: 294.801 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:54.957 UTC [3898] discourse@discourse LOG:  duration: 289.026 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:55.463 UTC [3898] discourse@discourse LOG:  duration: 301.325 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:55.905 UTC [3898] discourse@discourse LOG:  duration: 296.361 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:56.348 UTC [3898] discourse@discourse LOG:  duration: 302.991 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:58.843 UTC [3898] discourse@discourse LOG:  duration: 2289.322 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:33:59.376 UTC [3898] discourse@discourse LOG:  duration: 322.300 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:00.445 UTC [3898] discourse@discourse LOG:  duration: 921.013 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:00.749 UTC [3898] discourse@discourse LOG:  duration: 111.277 ms  bind <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 186
2020-12-07 11:34:02.055 UTC [3898] discourse@discourse LOG:  duration: 1302.319 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:02.611 UTC [3898] discourse@discourse LOG:  duration: 299.807 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:03.130 UTC [3898] discourse@discourse LOG:  duration: 310.089 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:03.586 UTC [3898] discourse@discourse LOG:  duration: 310.537 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:04.050 UTC [3898] discourse@discourse LOG:  duration: 316.072 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:04.585 UTC [3898] discourse@discourse LOG:  duration: 315.813 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:05.138 UTC [3898] discourse@discourse LOG:  duration: 332.339 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:05.611 UTC [3898] discourse@discourse LOG:  duration: 320.420 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:06.086 UTC [3898] discourse@discourse LOG:  duration: 313.841 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:06.636 UTC [3898] discourse@discourse LOG:  duration: 330.514 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:07.277 UTC [3898] discourse@discourse LOG:  duration: 423.374 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:08.308 UTC [3898] discourse@discourse LOG:  duration: 881.346 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:09.041 UTC [3898] discourse@discourse LOG:  duration: 581.518 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:09.674 UTC [3898] discourse@discourse LOG:  duration: 413.955 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:10.538 UTC [3898] discourse@discourse LOG:  duration: 642.608 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:11.047 UTC [3898] discourse@discourse LOG:  duration: 358.794 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:17.793 UTC [3898] discourse@discourse LOG:  duration: 6599.545 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:33.146 UTC [3898] discourse@discourse LOG:  duration: 15127.645 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:34:53.075 UTC [3898] discourse@discourse LOG:  duration: 316.940 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:04.574 UTC [57] LOG:  using stale statistics instead of current ones because stats collector is not responding
2020-12-07 11:35:19.396 UTC [3898] discourse@discourse LOG:  duration: 26159.832 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:19.893 UTC [3898] discourse@discourse LOG:  duration: 315.783 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:20.438 UTC [3898] discourse@discourse LOG:  duration: 322.196 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:21.081 UTC [3898] discourse@discourse LOG:  duration: 403.873 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:34.236 UTC [3898] discourse@discourse LOG:  duration: 12995.895 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:35:55.785 UTC [3898] discourse@discourse LOG:  duration: 20970.124 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
167:M 07 Dec 2020 11:36:31.074 * 10 changes in 300 seconds. Saving...
167:M 07 Dec 2020 11:36:31.267 * Background saving started by pid 3911
2020-12-07 11:36:40.770 UTC [3898] discourse@discourse LOG:  duration: 44203.350 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
3911:C 07 Dec 2020 11:36:52.503 * DB saved on disk
3911:C 07 Dec 2020 11:36:52.518 * RDB: 1 MB of memory used by copy-on-write
167:M 07 Dec 2020 11:36:52.618 * Background saving terminated with success
2020-12-07 11:37:00.570 UTC [3898] discourse@discourse LOG:  duration: 19089.557 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:37:09.917 UTC [3898] discourse@discourse LOG:  duration: 9086.196 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:37:50.176 UTC [3898] discourse@discourse LOG:  duration: 39768.704 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:38:06.180 UTC [3898] discourse@discourse LOG:  duration: 15340.958 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:38:16.549 UTC [3898] discourse@discourse LOG:  duration: 9526.000 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:38:45.231 UTC [3898] discourse@discourse LOG:  duration: 28221.839 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:39:26.818 UTC [3898] discourse@discourse LOG:  duration: 41289.489 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:39:56.099 UTC [3898] discourse@discourse LOG:  duration: 28172.307 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:39:58.117 UTC [3898] discourse@discourse LOG:  duration: 1384.587 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:39:59.305 UTC [3898] discourse@discourse LOG:  duration: 758.125 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:41:07.711 UTC [3898] discourse@discourse LOG:  duration: 67823.399 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:41:24.048 UTC [3898] discourse@discourse LOG:  duration: 15546.933 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:41:35.033 UTC [3898] discourse@discourse LOG:  duration: 10181.365 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:42:04.037 UTC [3898] discourse@discourse LOG:  duration: 28545.266 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:43:41.573 UTC [3898] discourse@discourse LOG:  duration: 92603.676 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:43:50.101 UTC [3898] discourse@discourse LOG:  duration: 7813.096 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:44:03.377 UTC [3898] discourse@discourse LOG:  duration: 12590.301 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:44:37.995 UTC [3898] discourse@discourse LOG:  duration: 34268.080 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:44:54.399 UTC [3898] discourse@discourse LOG:  duration: 15760.378 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:45:56.976 UTC [3898] discourse@discourse LOG:  duration: 58722.471 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:46:46.091 UTC [3898] discourse@discourse LOG:  duration: 48556.685 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:47:09.536 UTC [3898] discourse@discourse LOG:  duration: 23130.829 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:47:33.762 UTC [3898] discourse@discourse LOG:  duration: 23694.256 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:48:09.190 UTC [3898] discourse@discourse LOG:  duration: 34922.442 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:48:09.539 UTC [3898] discourse@discourse LOG:  duration: 127.286 ms  parse <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 478
2020-12-07 11:49:05.314 UTC [3898] discourse@discourse LOG:  duration: 55677.361 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:49:07.150 UTC [3898] discourse@discourse LOG:  duration: 1647.675 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:49:19.072 UTC [3898] discourse@discourse LOG:  duration: 11720.259 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:49:31.135 UTC [3898] discourse@discourse LOG:  duration: 11582.021 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:49:44.365 UTC [3898] discourse@discourse LOG:  duration: 12831.278 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:51:41.565 UTC [3898] discourse@discourse LOG:  duration: 116599.870 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:52:22.060 UTC [3898] discourse@discourse LOG:  duration: 39664.789 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:52:56.540 UTC [3898] discourse@discourse LOG:  duration: 33136.236 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:52:57.214 UTC [3898] discourse@discourse LOG:  duration: 139.491 ms  parse <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 487
2020-12-07 11:52:57.472 UTC [3898] discourse@discourse LOG:  duration: 258.338 ms  bind <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 487
2020-12-07 11:53:08.567 UTC [3898] discourse@discourse LOG:  duration: 10615.113 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:53:13.908 UTC [3898] discourse@discourse LOG:  duration: 1035.837 ms  parse <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 488
2020-12-07 11:53:14.443 UTC [3898] discourse@discourse LOG:  duration: 475.898 ms  bind <unnamed>: SELECT "calendar_events".* FROM "calendar_events" WHERE "calendar_events"."post_id" = 488
2020-12-07 11:53:21.659 UTC [3898] discourse@discourse LOG:  could not send data to client: Broken pipe
2020-12-07 11:53:21.659 UTC [3898] discourse@discourse STATEMENT:  SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
2020-12-07 11:53:21.734 UTC [3898] discourse@discourse FATAL:  connection to client lost
2020-12-07 11:53:21.734 UTC [3898] discourse@discourse STATEMENT:  SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc
Killed
I, [2020-12-07T11:53:30.522597 #1]  INFO -- :
I, [2020-12-07T11:53:35.390781 #1]  INFO -- : Terminating async processes
I, [2020-12-07T11:53:35.815966 #1]  INFO -- : Sending INT to HOME=/var/lib/postgresql USER=postgres exec chpst -u postgres:postgres:ssl-cert -U postgres:postgres:ssl-cert /usr/lib/postgresql/12/bin/postmaster -D /etc/postgresql/12/main pid: 50
2020-12-07 11:53:36.108 UTC [50] LOG:  received fast shutdown request
I, [2020-12-07T11:53:36.185340 #1]  INFO -- : Sending TERM to exec chpst -u redis -U redis /usr/bin/redis-server /etc/redis/redis.conf pid: 167
167:signal-handler (1607342016) Received SIGTERM scheduling shutdown...
167:M 07 Dec 2020 11:53:36.211 # User requested shutdown...
167:M 07 Dec 2020 11:53:36.211 * Saving the final RDB snapshot before exiting.
2020-12-07 11:53:36.626 UTC [50] LOG:  aborting any active transactions
2020-12-07 11:53:37.025 UTC [50] LOG:  background worker "logical replication launcher" (PID 59) exited with exit code 1
2020-12-07 11:53:37.616 UTC [54] LOG:  shutting down
167:M 07 Dec 2020 11:53:38.311 * DB saved on disk
167:M 07 Dec 2020 11:53:38.312 # Redis is now ready to exit, bye bye...
2020-12-07 11:53:40.331 UTC [50] LOG:  database system is shut down


FAILED
--------------------
Pups::ExecError: cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate' failed with return #<Process::Status: pid 3870 exit 137>
Location of failure: /pups/lib/pups/exec_command.rb:112:in `spawn'
exec failed with the params {"cd"=>"$home", "hook"=>"db_migrate", "cmd"=>["su discourse -c 'bundle exec rake db:migrate'"]}
a03fe2903df190bacab2f312cb2c8dca7707a9f5d9fcca0821ea5b7ce0e2d742
** FAILED TO BOOTSTRAP ** please scroll up and look for earlier error messages, there may be more than one.
./discourse-doctor may help diagnose the problem.

amotl · 7. Dezember 2020 um 12:26

Nachfolgend Upgrade of postgres failed und PostgreSQL 12 update konnten wir nichts Besonderes identifizieren, das uns hier weiterhelfen könnte.

Diese Installation ist nicht besonders groß:

root@pulp:/srv/www/organizations/panodata/community.panodata.org# du -sch .
661M	total

und der Versuch, die Anwendung erneut in der richtigen Reihenfolge zu starten,

scheitert, da die Rails-Anwendung keine Verbindung zu PostgreSQL herstellen kann:

==> shared/standalone/log/rails/unicorn.stderr.log <==
I, [2020-12-07T12:20:58.960126 #459]  INFO -- : Refreshing Gem list
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `initialize': could not connect to server: No such file or directory (PG::ConnectionBad)
	Is the server running locally and accepting
	connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"?
	from /var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `new'
	from /var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `connect'

amotl · 7. Dezember 2020 um 12:32

tail -n100 -F shared/standalone/log/rails/production.log

zeigt Folgendes an:

Creating scope :pending. Overwriting existing method DiscoursePostEvent::EventDate.pending.
Creating scope :open. Overwriting existing method Poll.open.
Migrating to AddSmtpAndImapToGroups (20181220115844)
Migrating to AddImapFieldsToIncomingEmails (20190111183409)
Migrating to AddSecureToUploads (20190716173854)
Migrating to RsvpMigration (20191016154136)
Migrating to AddLastSeenToCategoryUsers (20191107025041)
Migrating to AddIndexToLastSeenAtOnCategoryUsers (20191107025140)
Migrating to ChangeNotificationLevel (20191107032231)
Migrating to RemoveSuppressFromLatestFromCategory (20191107190330)
Migrating to AddTargetTagIdToTags (20191113193141)
Migrating to AddGraphToPolls (20191114160613)
Migrating to RenameSiteSettingAssignEmailer (20191119174425)
Migrating to AddTimezoneToUserOptions (20191120015344)
Migrating to AddUniqueIndexToDevelopers (20191128222140)
Migrating to DropUnusedGoogleInstagramAuthTables (20191129144706)
Migrating to AddFeaturedTopicIdToUserProfiles (20191202202212)
Migrating to CreateStandaloneBookmarksTable (20191205100434)
Migrating to AddGroupNameToPolls (20191206123012)
Migrating to EnsuresUniqueAcceptedAnswerPostId (20191209095548)
Migrating to AddIndexToInvites (20191211152404)
Migrating to AddHashedApiKey (20191211170000)
Migrating to PopulateTopicIdOnBookmarks (20191217035630)
Migrating to RemoveKeyFromApiKeys (20191219112000)
Migrating to AddDistinctBadgeCountToUserStats (20191220134101)
Migrating to AddAccessControlColumnsToUpload (20191230055237)
Migrating to AddFeaturedRankToUserBadges (20200107161405)
Migrating to UpdateUserProfilesIndexes (20200109130028)
Migrating to AddGroupToCustomEmojis (20200116092259)
Migrating to RenameReplyIdColumn (20200116140132)
Migrating to UpdatePostReplyIndexes (20200117141138)
Migrating to AddTriggerToSyncPostReplies (20200117172135)
Migrating to MakePostReplyIdColumnReadOnly (20200117174646)
Migrating to DropUnusedColumns (20200120131338)
Migrating to RemoveBounceScoreThresholdDeactivateSiteSetting (20200130115859)
Migrating to MarkBookmarksTopicIdNotNull (20200203061927)
Migrating to CreateCalendarEvents (20200226183018)

und (wahrscheinlich!) beim zweiten Aufruf von ./launcher rebuild community.panodata.org wurde Folgendes angezeigt:

Creating scope :pending. Overwriting existing method DiscoursePostEvent::EventDate.pending.
Creating scope :open. Overwriting existing method Poll.open.
Migrating to CreateCalendarEvents (20200226183018)

Falco · 7. Dezember 2020 um 12:34

Ich schlage vor, das Kalender-Plugin zu entfernen und es erneut zu versuchen.

amotl · 7. Dezember 2020 um 12:35

Bin dabei, danke! Ich habe gerade beide deaktiviert und baue erneut auf.

#          - git clone https://github.com/discourse/discourse-calendar.git
#          - git clone https://github.com/angusmcleod/discourse-events.git

amotl · 7. Dezember 2020 um 13:09

Lieber Rafael,

ich kann bestätigen, dass das Plugin Discourse Calendar (and Event) hier tatsächlich die Ursache war. Ich werde daher den Titel dieses Beitrags entsprechend anpassen. Übrigens teile ich hiermit unsere aktuelle Plugin-Liste. Mit diesen installierten Plugins (und deaktiviertem discourse-calendar) verlief die Datenbank-Migration problemlos, und das Forum ist wieder online: https://community.panodata.org/.

  after_code:
    - exec:
        cd: $home/plugins
        cmd:
          - git clone https://github.com/discourse/docker_manager.git
          - git clone https://github.com/discourse/discourse-translator.git
          - git clone https://github.com/discourse/discourse-checklist.git
          - git clone https://github.com/discourse/discourse-assign.git
          - git clone https://github.com/discourse/discourse-solved.git
          - git clone https://github.com/discourse/discourse-math.git
          - git clone https://github.com/angusmcleod/discourse-tickets.git
          - git clone https://github.com/angusmcleod/discourse-knowledge-base.git
          - git clone https://github.com/angusmcleod/discourse-locations.git
          - git clone https://github.com/discourse/discourse-footnote.git
          - git clone https://github.com/discourse/discourse-graphviz.git
          - git clone https://github.com/angusmcleod/discourse-custom-wizard.git
          - git clone https://github.com/discourse/discourse-sitemap.git
          - git clone https://github.com/angusmcleod/discourse-events.git

#          - git clone https://github.com/discourse/discourse-calendar.git

Vielen Dank, behaltet diesen Elan bei, und mit freundlichen Grüßen,
Andreas.

P.S.: Wie sollten wir vorgehen, wenn wir einen Fehler im discourse-calendar-Plugin melden möchten, falls das angebracht ist?

Falco · 7. Dezember 2020 um 13:22

Da Sie nun ordnungsgemäß auf PG12 migriert wurden, können Sie versuchen, das Plugin erneut hinzuzufügen, um zu prüfen, ob die Migration erfolgreich ist.

amotl · 7. Dezember 2020 um 14:49

Das habe ich bereits getan. Allerdings läuft der Migrationsprozess immer wieder in dieselbe Situation.

amotl:

2020-12-07 11:33:41.954 UTC [3898] discourse@discourse LOG:  duration: 232.874 ms  statement: CREATE TABLE "calendar_events" ("id" bigserial primary key, "topic_id" integer NOT NULL, "post_id" integer, "post_number" integer, "user_id" integer, "username" character varying, "description" character varying, "start_date" timestamp NOT NULL, "end_date" timestamp, "recurrence" character varying, "region" character varying, "created_at" timestamp NOT NULL, "updated_at" timestamp NOT NULL)
2020-12-07 11:33:42.693 UTC [3898] discourse@discourse LOG:  duration: 349.048 ms  execute <unnamed>: SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc

Glaubst du, das hat etwas mit bestimmten Daten in unserer Instanz in den Tabellen calendar_events und post_custom_fields zu tun?

Anscheinend bleibt der Prozess bei post_id = 20 hängen. Also habe ich Folgendes versucht:

./launcher enter community.panodata.org
rails console
DB.query('SELECT "post_custom_fields"."name", "post_custom_fields"."value" FROM "post_custom_fields" WHERE "post_custom_fields"."post_id" = 20 ORDER BY id asc')

Danach wird das System vollständig unresponsiv und die Systemlast schießt in die Höhe.

`top`

top - 15:28:06 up 158 days, 14:05,  5 users,  load average: 19.28, 12.96, 5.94
Tasks: 289 total,   1 running, 288 sleeping,   0 stopped,   0 zombie
%Cpu(s):  2.3 us,  6.1 sy,  0.3 ni,  1.2 id, 90.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   7006.9 total,     40.1 free,   6177.4 used,    789.4 buff/cache
MiB Swap:   4096.0 total,   2048.4 free,   2047.6 used.    659.2 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
12470 xxx       25   5 9229456  89424   4604 S 117.4   1.2   0:35.66 ruby
   43 root      20   0       0      0      0 D   1.0   0.0  11:46.02 kswapd0
10035 xxx       20   0 7481716   4.2g   6020 D   1.0  61.3   0:12.60 bundle

`iotop`

Total DISK READ:      1373.05 K/s | Total DISK WRITE:        29.79 K/s
Current DISK READ:    1373.05 K/s | Current DISK WRITE:       3.17 M/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND
27667 be/4 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % sshd -D
10035 be/4 xxx         0.00 B/s    0.00 B/s  0.00 % 99.99 % pry
 4863 be/4 xxx         0.00 B/s    0.00 B/s  0.00 % 99.99 % bash config/unicorn_launcher -E production -c config/unicorn.conf.rb
11145 be/4 xxx         0.00 B/s    0.00 B/s  0.00 % 99.99 % unicorn worker[0] -E production -c config/unicorn.conf.rb
11363 be/4 xxx         0.00 B/s    0.00 B/s  0.00 % 99.99 % sleep 1
11362 be/4 xxx         0.00 B/s    0.00 B/s  0.00 % 99.99 % sleep 1
   43 be/4 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % [kswapd0]
  344 be/4 root       49.66 K/s    0.00 B/s  0.00 % 61.49 % [xfsaild/xvda4]
13189 be/4 xxx         0.00 B/s    9.93 K/s  0.00 % 56.78 % postgres: 12/main: walwriter
13357 be/5 xxx         0.00 B/s    0.00 B/s  0.00 % 20.45 % sidekiq 6.1.2 discourse [0 of 5 busy] [mini_scheduler*]
 5497 be/5 xxx         4.97 K/s    0.00 B/s  2.82 %  0.00 % sidekiq 6.0.5 discourse [0 of 5 busy] [heartbeat]

Erst nachdem ich

[3] pry(main)>

verlassen habe, erholt sich das System langsam und wird wieder reaktionsfähig. Es sieht so aus, als würde es zu einer massiven Ressourcenbelastung kommen.

DB.query_single('SELECT count(*) FROM "post_custom_fields"')
=> [2002]

DB.query_single('SELECT count(*) FROM "post_custom_fields" WHERE post_id=20')
=> [2]

DB.query_single('SELECT name FROM "post_custom_fields" WHERE post_id=20')
=> ["calendar-details", "post_detected_lang"]

Sobald ich jedoch die Spalte value auswähle, läuft alles schief.

amotl · 7. Dezember 2020 um 14:49

Ha. Ist das überhaupt noch zumutbar?

DB.query_single('SELECT name, length(value) FROM "post_custom_fields" WHERE post_id=20')
=> ["calendar-details", 83361791, "post_detected_lang", 2]

Die Spalte value dieses spezifischen calendar-details-Eintrags enthält also Daten im Umfang von etwa 80 MB. Ich glaube, wir sind auf der richtigen Spur.

Offenbar ist dies der einzige Eintrag, der in seinem calendar-details-Wert eine so große Nutzlast trägt.

print(DB.query("SELECT post_id, length(value) FROM post_custom_fields WHERE name='calendar-details' ORDER BY post_id").map { |r| r.post_id.to_s + ": " + r.length.to_s }.join("\n"))
20: 83361791
84: 113
133: 113
177: 58
223: 2
263: 113
379: 112
385: 130
439: 112
456: 112
457: 58
495: 117
552: 2

amotl · 7. Dezember 2020 um 15:10

Ich mache Fortschritte bei der Eingrenzung.

DB.query("SELECT topic_id, cooked FROM posts WHERE id=20")
=> [#<#<Class:0x0000560b91760168>:0x0000560b8b841880
  @cooked=
   "<p>Wenn Sie an den Aktivitäten in den <a href=\"https://github.com/panodata\" rel=\"nofollow noopener\">Panodata GitHub</a>-Repositories interessiert sind, verfolgen Sie bitte diesen Thread.</p>\n<p>Wir speisen Push-Benachrichtigungen von GitHub in Discourse ein, indem wir das hervorragende <a href=\"https://github.com/huw/github-to-discourse\" class=\"inline-onebox\" rel=\"nofollow noopener\">GitHub - huw/github-to-discourse: Leitet Commit-Daten von einem GitHub-Webhook an einen Discourse-Thread weiter</a> verwenden.</p>",
  @topic_id=16>]

Es sieht also so aus, als wäre dies der allererste Beitrag im Thema Logbook of code changes - The workbench - Panodata Community. Soweit ich meinem eigenen Verstand vertrauen kann, habe ich diesem Beitrag nie etwas im Zusammenhang mit einem Kalendereinträge zugewiesen.

Tatsächlich handelt es sich um ein Thema, in dem automatisch Beiträge erstellt werden, und zwar über GitHub - huw/github-to-discourse: Forwards commit data from a GitHub webhook to a Discourse thread · GitHub. Der erste Beitrag (id=20) wurde jedoch manuell erstellt.

Falco · 7. Dezember 2020 um 15:42

Nun, das bedeutet also, dass es nichts mit dem PG12-Update zu tun hat, also liegt es nicht an mir

Ja, wie wir bereits mehrfach sagten, ist die Verwendung des Plugin-Stores oder von post_custom_fields für komplexe Inhalte langfristig nicht nachhaltig. Deshalb führt das Kalender-Plugin diese Migration durch, um auf richtige Tabellen umzuziehen.

Leider scheint dies für dich nicht früh genug erfolgt zu sein, und ein Ereignis befindet sich in einem fehlerhaften Zustand. Lösche den problematischen Datensatz, und alles sollte wieder funktionieren.

amotl · 7. Dezember 2020 um 15:46

Auf keinen Fall! Ich habe den Titel des Themas bereits angepasst, um das aktuelle Ergebnis widerzuspiegeln. Vielen Dank für deine Hilfe und dein Feedback dazu.

Ich verstehe. Nochmals vielen Dank für deine Einsichten.

Alles klar, werde ich tun. Ich gehe also davon aus, dass es keinen Grund gibt, die Ursache weiter zu untersuchen, da du dir dessen bereits bewusst warst und die Situation durch die Anpassung des Datenbankschemas über die hier verlinkte Migration verbessert hast. Vielen Dank!

amotl · 7. Dezember 2020 um 16:01

Hallo nochmal,

[70] pry(main)> DB.query("DELETE FROM post_custom_fields WHERE post_id=20 AND name='calendar-details'")
=> []

Nachdem wir die störende Zeile gelöscht hatten, haben wir discourse-calendar erneut aktiviert. Nach einem weiteren Rebuild können wir bestätigen, dass die fehlenden Migrations erfolgreich angewendet wurden:

20200226183018 CreateCalendarEvents: migriert (0,8584s)
20200409102640 CreatePostEventsTable: migriert (0,0381s)
20200409102643 RenameTablesToDiscoursePostEvent: migriert (0,1840s)
20201110225115 CreatePostEventDatesTable: migriert (0,0655s)
20201111005205 MoveDataToEventDates: migriert (0,0039s)

Und alles ist wieder in Ordnung.

Vielen Dank für die hervorragende Arbeit, die ihr hier leistet.

Mit freundlichen Grüßen,
Andreas.

Thema		Antworten	Aufrufe
'bundle exec rake db:migrate' taking a long time due to calendar migration Self-hosting	33	908	5. Dezember 2023
Plugin causing errors during rebuild Self-hosting	21	1921	10. November 2022
Help! Upgrade led to complete fail Self-hosting	8	1378	9. März 2021
40 Fatals and 7 Errors in recent logs Support	13	1645	8. Juni 2024
Restore fails due to disk space on migration because of 70M calendar events Support calendar-and-event	11	171	14. Februar 2026

Datenbankmigration stockt bei riesigem Wert eines "calendar-details"-Elements in der Tabelle "post_custom_fields"

TLDR;

top

iotop

Verwandte Themen

`top`

`iotop`