테이블 "post_custom_fields"의 "calendar-details" 항목 값이 너무 커서 데이터베이스 마이그레이션이 실패합니다

amotl · 12월 7, 2020, 11:54오전

요약

4번 게시물 이후, 이 문제가 Discourse Events 와 관련되어 있음을 확인했습니다. 해당 플러그인을 일시적으로 비활성화한 후 데이터베이스 마이그레이션이 성공적으로 완료되었습니다 – @falco 님께 감사드립니다.
9번 게시물 이후, 특정 게시물의 calendar-details 항목의 value에 약 80MB 분량의 데이터가 포함되어 있음을 발견했습니다.
13번 게시물에 설명된 대로 문제의 행을 삭제한 후, Discourse Events 를 다시 활성화해도 데이터베이스 마이그레이션이 완전히 성공적으로 완료되었습니다 – 다시 한번 @falco 님께 감사드립니다.
이 문제의 배경은 2020년 3월부터 적용되어 온 데이터베이스 마이그레이션으로, DEV: Migrate from custom fields to tables - Pull Request #23 - discourse/discourse-calendar - GitHub 를 참조하십시오. @nbianca, @eviltrout, @j.jaffeux 님께 감사드립니다.

Discourse 개발팀 여러분,

https://community.hiveeyes.org/ 와 https://community.panodata.org/ 의 Discourse 인스턴스에 대해 한동안 관리를 하지 못하다가, 어제 밤에 업그레이드를 진행했습니다.

Hiveeyes 커뮤니티 포럼의 업그레이드는 평소처럼 순조롭게 진행되었습니다. PostgreSQL은 10 버전에서 12 버전으로 업그레이드되었고, 업그레이드 과정을 지켜보는 것은 매우 만족스러웠습니다. Discourse에 쏟아부어 주시는 훌륭한 작업에 대해 팀 전체에게 감사의 말씀을 드립니다!

그러나 Panodata 커뮤니티 포럼의 업그레이드를 시도하는 동안 몇 가지 문제를 관찰하고 있습니다. ./launcher rebuild community.panodata.org 실행의 두 번째 단계에서 시스템이 극도로 높은 부하를 겪고 있으며, 현재 전체 머신을 마비시키고 있습니다.

이 문제가 어디서 시작되는지 어느 정도 파악했으며, 여기 로그의 일부 내용을 공유하겠습니다. 분명히 데이터베이스 마이그레이션 프로세스가 post_custom_fields 테이블을 처리할 때 어떤 종류의 루프에 갇혀 있는 것으로 보입니다. 추가 정보가 필요하시면 말씀해 주십시오.

이로 인해 심각한 문제에 처하게 된 것일까요? 이 상황을 해결하는 데 도움이 될 수 있는 어떤 정보라도 매우 기대하고 있습니다.

미리 감사드리며, 정중히 인사드립니다.
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 · 12월 7, 2020, 12:26오후

Upgrade of postgres failed 및 https://meta.discourse.org/t/postgresql-12-update/151236를 참고하였으나, 이 문제를 해결하는 데 도움이 될 만한 특정한 사항을 식별하지 못했습니다.

이 설치 환경은 특별히 크지 않습니다.

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

그리고

순서대로 애플리케이션을 다시 실행해 보았지만, Rails 앱이 PostgreSQL에 연결할 수 없어 실패했습니다:

==> 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 · 12월 7, 2020, 12:32오후

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

명령을 실행하면 다음과 같은 내용이 표시됩니다:

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)

그리고 (아마도!) ./launcher rebuild community.panodata.org를 두 번째로 실행했을 때 다음과 같이 표시되었습니다:

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

Falco · 12월 7, 2020, 12:34오후

캘린더 플러그인을 제거한 후 다시 시도해 보시는 것을 제안합니다.

amotl · 12월 7, 2020, 12:35오후

알겠습니다, 감사합니다! 방금 이 두 가지를 모두 비활성화하고 다시 빌드하고 있습니다.

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

amotl · 12월 7, 2020, 1:09오후

Rafael님,

Discourse Events 플러그인이 실제로 문제의 원인이었음을 확인했습니다. 따라서 이 게시물의 제목을 그에 맞게 수정하겠습니다. 참고로 현재 사용 중인 플러그인 목록도 공유합니다. 이 플러그인들이 설치된 상태에서 discourse-calendar를 비활성화하면 데이터베이스 마이그레이션 작업이 정상적으로 완료되었고, 포럼도 다시 정상적으로 작동하고 있습니다 – 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

정말 감사합니다. 좋은 기운을 유지하시고, 존경의 인사를 전합니다.
Andreas.

P.S.: discourse-calendar에 대한 버그를 신고하는 것이 적절하다면, 어떻게 진행해야 할까요?

Falco · 12월 7, 2020, 1:22오후

이제 PG12로 완전히 마이그레이션이 완료되었으므로, 마이그레이션이 정상적으로 작동하는지 확인해 보기 위해 플러그인을 다시 추가해 볼 수 있습니다.

amotl · 12월 7, 2020, 2:49오후

이미 그렇게 해 보았습니다. 하지만 마이그레이션 프로세스가 여전히 동일한 상황에 직면하고 있습니다.

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

저희 인스턴스의 calendar_events 및 post_custom_fields 테이블 내의 특정 데이터와 관련이 있다고 생각하시나요?

표면적으로 프로세스는 post_id = 20에서 멈추는 것 같습니다. 그래서 저는 다음을 시도해 보았습니다:

./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')

그 후 시스템이 완전히 응답을 멈추고 시스템 부하가 급상승했습니다.

`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]

다음에서 벗어난 후에만

[3] pry(main)>

시스템이 서서히 회복되고 다시 반응이 시작됩니다. 심각한 리소스 스래싱(thrashing)이 일어나고 있는 것으로 보입니다.

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"]

하지만 value 컬럼을 선택하는 순간 모든 것이 꼬입니다.

amotl · 12월 7, 2020, 2:49오후

하. 이게 정상적인가요?

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

즉, 이 특정 calendar-details 항목의 value 열에는 약 80MB에 달하는 데이터가 포함되어 있습니다. 여기에서 뭔가 중요한 단서를 찾은 것 같습니다.

어떤 면에서, 이렇게 큰 페이로드를 calendar-details 값에 가진 항목은 이 항목이 유일합니다.

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 · 12월 7, 2020, 3:10오후

이 문제를 좁혀가는 데 진전을 이루고 있습니다.

DB.query("SELECT topic_id, cooked FROM posts WHERE id=20")
=> [#<#<Class:0x0000560b91760168>:0x0000560b8b841880
  @cooked=
   "<p>If you are interested in the activities on the <a href=\"https://github.com/panodata\" rel=\"nofollow noopener\">Panodata GitHub</a> repositories, please track this thread.</p>\n<p>We are feeding push notifications from GitHub into Discourse by using the fine <a href=\"https://github.com/huw/github-to-discourse\" class=\"inline-onebox\" rel=\"nofollow noopener\">GitHub - huw/github-to-discourse: Forwards commit data from a GitHub webhook to a Discourse thread</a>.</p>",
  @topic_id=16>]

즉, 이것은 Logbook of code changes - The workbench - Panodata Community 주제의 첫 번째 게시글인 것 같습니다. 제 판단을 신뢰할 수 있다면, 저는 이 게시글에 캘린더 항목과 관련된 것을 절대 지정하지 않았습니다.

실제로 이 주제는 https://github.com/huw/github-to-discourse를 사용하여 자동 게시글이 생성되는 곳입니다. 그러나 첫 번째 게시글(id=20)은 수동으로 생성되었습니다.

Falco · 12월 7, 2020, 3:42오후

음, 그렇다면 PG12 업데이트와는 아무런 관련이 없다는 뜻이므로 제 잘못은 아닙니다

네, 몇 번이나 말했지만 복잡한 데이터에 대해 plugin store나 post_custom_fields를 사용하는 것은 장기적으로 지속 가능하지 않습니다. 그래서 캘린더는 이 마이그레이션을 통해 정규화된 테이블로 데이터를 이동시키고 있습니다.

불행히도 당신에게는 이 마이그레이션이 너무 늦게 적용된 것 같아 이벤트가 잘못된 상태가 되었습니다. 문제 있는 행을 삭제하면 다시 정상적으로 작동할 것입니다.

amotl · 12월 7, 2020, 3:46오후

그렇습니다! 현재 결과를 반영하도록 주제 제목을 이미 수정해 두었습니다. 이에 대한 도움과 피드백에 진심으로 감사드립니다.

알겠습니다. 통찰을 공유해 주셔서 다시 한번 감사드립니다.

좋습니다, 그렇게 하겠습니다. 그러니까, 당신은 이미 그 원인을 인지하고 있었고 여기서 언급한 마이그레이션을 통해 데이터베이스 스키마를 적절히 수정하여 상황을 개선했으므로, 근본 원인에 대해 더 이상 조사할 필요가 없다고 생각합니다. 감사합니다!

amotl · 12월 7, 2020, 4:01오후

다시 인사드립니다.

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

해당 행을 삭제한 후 discourse-calendar 플러그인을 다시 활성화했습니다. 이후 재구축을 수행한 결과, 누락된 마이그레이션이 성공적으로 적용되었음을 보고합니다.

20200226183018 CreateCalendarEvents: migrated (0.8584s)
20200409102640 CreatePostEventsTable: migrated (0.0381s)
20200409102643 RenameTablesToDiscoursePostEvent: migrated (0.1840s)
20201110225115 CreatePostEventDatesTable: migrated (0.0655s)
20201111005205 MoveDataToEventDates: migrated (0.0039s)

그리고 모든 것이 다시 정상적으로 작동하고 있습니다.

여기서 수행해 주신 훌륭한 작업에 대해 진심으로 감사드립니다.

존경의 뜻으로,
Andreas.

글		댓글	조회수
'bundle exec rake db:migrate' taking a long time due to calendar migration Self-hosting	33	1220	12월 5, 2023
Plugin causing errors during rebuild Self-hosting	20	2396	10월 11, 2022
Help! Upgrade led to complete fail Self-hosting	7	1555	3월 9, 2021
40 Fatals and 7 Errors in recent logs Product Support	12	1915	2월 17, 2017
Restore fails due to disk space on migration because of 70M calendar events Product Support events	10	379	2월 14, 2026

테이블 "post_custom_fields"의 "calendar-details" 항목 값이 너무 커서 데이터베이스 마이그레이션이 실패합니다

요약

top

iotop

Related topics

`top`

`iotop`