Aggiornamento fallito con errore "duplicate key value violates unique constraint"

Hi!

Today I tried to upgrade my Discourse instance from “2.1.0.beta6” to latest one - “2.5.0.beta1”.

But web upgrade failed in the middle and after that my server displayed recommendation to update by executing ./launcher rebuild app.

I did that, but upgrade failed with error:

root@cloud:/var/discourse# ./launcher rebuild synfig-forums
Ensuring launcher is up to date
Fetching origin
Launcher is up-to-date
Stopping old container
+ /usr/bin/docker stop -t 10 synfig-forums
synfig-forums
cd /pups && git pull && /pups/bin/pups --stdin
Already up to date.
...
Bundle complete! 124 Gemfile dependencies, 157 gems now installed.
Gems in the groups test and development were not installed.
Bundled gems are installed into `./vendor/bundle`

I, [2020-02-27T10:37:49.176136 #1]  INFO -- : > cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate'
2020-02-27 10:38:06.784 UTC [414] discourse@discourse ERROR:  duplicate key value violates unique constraint "index_poll_options_on_poll_id_and_digest"
2020-02-27 10:38:06.784 UTC [414] discourse@discourse DETAIL:  Key (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) already exists.
2020-02-27 10:38:06.784 UTC [414] discourse@discourse STATEMENT:  INSERT INTO poll_options
	  (poll_id, digest, html, anonymous_votes, created_at, updated_at)
	VALUES
	  (30, '399fc6670871474cd7ce0458401fd299', '<ul>
	<li>
	</li>
	</ul>', 0, '2018-07-30 12:09:10 UTC', '2018-07-30 12:09:10 UTC'),(30, '59f25e0e204428418f22b441698f25dd', '**', 0, '2018-07-30 12:09:10 UTC', '2018-07-30 12:09:10 UTC'),(30, '399fc6670871474cd7ce0458401fd299', '<hr>', 0, '2018-07-30 12:09:10 UTC', '2018-07-30 12:09:10 UTC'),(30, '399fc6670871474cd7ce0458401fd299', '<hr>', 0, '2018-07-30 12:09:10 UTC', '2018-07-30 12:09:10 UTC'),(30, '399fc6670871474cd7ce0458401fd299', '<hr>', 0, '2018-07-30 12:09:10 UTC', '2018-07-30 12:09:10 UTC')
	RETURNING digest, id
	
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

ERROR:  duplicate key value violates unique constraint "index_poll_options_on_poll_id_and_digest"
DETAIL:  Key (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) already exists.
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.6/lib/patches/db/pg.rb:110:in `exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.6/lib/patches/db/pg.rb:110:in `async_exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.4/lib/mini_sql/postgres/connection.rb:118:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.4/lib/mini_sql/postgres/connection.rb:55:in `query_single'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:131:in `block (2 levels) in up'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:87:in `each'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:87:in `block in up'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:64:in `each'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:64:in `up'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:831:in `exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:9:in `block in exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:8:in `exec_migration'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:812:in `block (2 levels) in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:811:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:810:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:29:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1001:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1311:in `block in execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1362:in `block in ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:281:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:281:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/transactions.rb:212:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1362:in `ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1310:in `execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1282:in `block in migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1281:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1281:in `migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1229:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1382:in `with_advisory_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1229:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1061:in `up'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1036:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/tasks/database_tasks.rb:238:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:52:in `migrate'
/var/www/discourse/lib/tasks/db.rake:72:in `block in <top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rake-13.0.1/exe/rake:27:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'

Caused by:
PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_poll_options_on_poll_id_and_digest"
DETAIL:  Key (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) already exists.
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.6/lib/patches/db/pg.rb:110:in `exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.6/lib/patches/db/pg.rb:110:in `async_exec'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.4/lib/mini_sql/postgres/connection.rb:118:in `run'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_sql-0.2.4/lib/mini_sql/postgres/connection.rb:55:in `query_single'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:131:in `block (2 levels) in up'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:87:in `each'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:87:in `block in up'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:64:in `each'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:64:in `up'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:831:in `exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:9:in `block in exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:8:in `exec_migration'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:812:in `block (2 levels) in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:811:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:810:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:29:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1001:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1311:in `block in execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1362:in `block in ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:281:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:281:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/transactions.rb:212:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1362:in `ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1310:in `execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1282:in `block in migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1281:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1281:in `migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1229:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1382:in `with_advisory_lock'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1229:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1061:in `up'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/migration.rb:1036:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/tasks/database_tasks.rb:238:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:52:in `migrate'
/var/www/discourse/lib/tasks/db.rake:72:in `block in <top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rake-13.0.1/exe/rake:27:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'
Tasks: TOP => db:migrate
(See full trace by running task with --trace)
I, [2020-02-27T10:38:06.821527 #1]  INFO -- : == 20180820080623 MigratePollsData: migrating =================================
...
I, [2020-02-27T10:38:06.822339 #1]  INFO -- : Terminating async processes
I, [2020-02-27T10:38:06.822638 #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/10/bin/postmaster -D /etc/postgresql/10/main pid: 50
I, [2020-02-27T10:38:06.822850 #1]  INFO -- : Sending TERM to exec chpst -u redis -U redis /usr/bin/redis-server /etc/redis/redis.conf pid: 167
2020-02-27 10:38:06.822 UTC [50] LOG:  received fast shutdown request
167:signal-handler (1582799886) Received SIGTERM scheduling shutdown...
2020-02-27 10:38:06.825 UTC [50] LOG:  aborting any active transactions
167:M 27 Feb 2020 10:38:06.828 # User requested shutdown...
2020-02-27 10:38:06.828 UTC [50] LOG:  worker process: logical replication launcher (PID 59) exited with exit code 1
167:M 27 Feb 2020 10:38:06.829 * Saving the final RDB snapshot before exiting.
2020-02-27 10:38:06.839 UTC [54] LOG:  shutting down
2020-02-27 10:38:06.941 UTC [50] LOG:  database system is shut down
167:M 27 Feb 2020 10:38:07.170 * DB saved on disk
167:M 27 Feb 2020 10:38:07.171 # Redis is now ready to exit, bye bye...


FAILED
--------------------
Pups::ExecError: cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate' failed with return #<Process::Status: pid 385 exit 1>
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'"]}
77bc12013304841e8082e888a7a8c86adade040fd97b44fef1c1e85355ba2ae5
** 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.

Note: I am intentionally used ./launcher rebuild synfig-forums command, because my instance is described in synfig-forums.yml file, not app.yml.

As I understand, the problem described by this line:

ERROR:  duplicate key value violates unique constraint "index_poll_options_on_poll_id_and_digest"
DETAIL:  Key (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) already exists.

What can I do in this situation? Any assistance is much appreciated!

Okay, volevo esaminare il contenuto del database, quindi ho eseguito le seguenti operazioni:

cd /var/discourse
./launcher start synfig-forums
./launcher enter synfig-forums
su - postgres
psql

Ho ricevuto un errore:

psql: impossibile connettersi al server: Nessuno di tali file o directory
	Il server è in esecuzione localmente e accetta
	connessioni sul socket di dominio Unix "/var/run/postgresql/.s.PGSQL.5432"?

Hai un indice danneggiato. Consulta Can't restore due to corrupt indexes (with some clues on how to deal with corrupt indexes) per alcuni suggerimenti.

Hai un contenitore del database separato? Immagino di sì e che tu debba accedere a quel contenitore invece.

Grazie per i suggerimenti!

No, ho un’installazione con contenitore autonomo (immagino sia così che si chiami).

Ho provato ad avviare il servizio postgresql (dal contenitore docker) e ho ottenuto quanto segue:

root@cloud-synfig-forums:/var/www/discourse# service postgresql start
 * Starting PostgreSQL 10 database server                                        * Error: Config owner (postgres:107) and data owner (syslog:106) do not match, and config owner is not root
                                                                         [fail]

Ok, sono riuscito ad avviare il servizio PostgreSQL, ho eseguito il backup del database ed è entrato nel database:

# chown -R postgres /shared/postgres_data
# service postgresql start
 * Starting PostgreSQL 10 database server                                                                                        [ OK ] 
# psql
psql: FATAL:  role "root" does not exist
# su - discourse
$ pg_dump -xOf ~/discourse-backup.sql -d discourse -n public
$ exit
# mv /home/discourse/discourse-backup.sql /shared/discourse-backup-20200227-1.sql
# su - postgres
$ psql discourse
psql (10.4 (Ubuntu 10.4-2.pgdg16.04+1))
Type "help" for help.

discourse=#

Ora, cosa posso fare per ripristinare la mia installazione?

Non sembra una buona notizia.

Quando hai eseguito la ricostruzione, ha menzionato qualcosa riguardo all’aggiornamento di PostgreSQL? L’hai eseguita più di una volta?

Hai un backup recente? Potrebbe essere più semplice provare a ripristinarlo da quello, ma sarà comunque difficile.

Non me lo ricordo. C’erano troppi messaggi mentre stavo aggiornando tramite l’interfaccia web. :frowning:

Sì, ho eseguito l’aggiornamento più di una volta: la prima volta dall’interfaccia web (è fallito), poi dalla riga di comando (più volte).

Sì, ho un backup creato 24 ore fa. Posso ripristinarlo, ma perderò alcuni messaggi (quelli pubblicati dopo il backup).

Non si tratta di un indice corrotto.

Tra la versione 2.1 e la 2.5, abbiamo spostato i pool da PluginStore a tabelle dedicate. Uno dei motivi di questo spostamento è garantire la coerenza dei dati, che è esattamente il problema che stai riscontrando.

Hai un valore duplicato nella tabella poll_options. Puoi andare lì ed eliminare le voci duplicate?

Grazie per il chiarimento!
Non sono un esperto di PostgreSQL… puoi aiutarmi con i comandi necessari da eseguire? (considerando che sono già dentro psql). :slight_smile:

Ok, ho eseguito questo:

discourse=# SELECT * FROM poll_options;
 id | poll_id | digest | html | anonymous_votes | created_at | updated_at 
----+---------+--------+------+-----------------+------------+------------
(0 rows)

Come è possibile che questa tabella sia vuota?

Le altre tabelle non sono vuote:

discourse=# SELECT name FROM badges WHERE id = 13;
    name    
------------
 First Flag
(1 row)

Sospetto che la voce duplicata provenga da Plugin Store. Ma dove si trova e come posso visualizzarla/modificarla?

È solo un’altra tabella (plugin_store_rows).

Sembra che i voti del sondaggio siano effettivamente nella tabella post_custom_fields, dove la colonna name è ‘polls’.

Ciò è stato modificato da questo commit e la migrazione corrispondente popola la tabella poll_options. Quindi potrebbe essere in corso un tentativo di inserire un record duplicato.

https://github.com/discourse/discourse/blob/master/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb#L132-L138

Quindi, vedo due opzioni per me:

  1. Rimuovere tutti i dati dei sondaggi dal mio database ed eseguire di nuovo il processo di aggiornamento. In questo modo perderò tutti i sondaggi, ma va bene così.
  2. Modificare il codice di migrate_polls_data.rb in modo che salti l’inserimento di voci duplicate. Soluzione migliore, ma non so come farlo.

Come posso modificare il codice per permettere a questa parte di fallire silenziosamente?

https://github.com/discourse/discourse/blob/master/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb#L132-L138

Ok, penso che sia sufficiente modificare l’istruzione SQL aggiungendo ON CONFLICT DO NOTHING - https://stackoverflow.com/a/31742830
Funzionerebbe?

Ok, ho eseguito quanto segue da pgsql:

SELECT *
	FROM post_custom_fields
	WHERE name = 'polls'
	AND value LIKE '%399fc6670871474cd7ce0458401fd299%';

Mi ha restituito una riga. Quindi l’ho rimossa:

DELETE FROM post_custom_fields
	WHERE name = 'polls'
	AND value LIKE '%399fc6670871474cd7ce0458401fd299%';

Nota: il modo corretto sarebbe stato eliminare tramite l’ID della riga, ma dato che era stata restituita una sola riga, ho fatto così. :slight_smile:

Dopo di ciò ho riavviato l’aggiornamento ed è andato a buon fine. Grazie a tutti quelli che hanno condiviso i loro suggerimenti! :slight_smile: