Falha na atualização com erro "duplicate key value violates unique constraint"

Olá!

Hoje tentei atualizar minha instância do Discourse da versão “2.1.0.beta6” para a mais recente — “2.5.0.beta1”.

No entanto, a atualização via web falhou no meio do processo e, em seguida, meu servidor exibiu a recomendação de atualizar executando ./launcher rebuild app.

Fiz isso, mas a atualização falhou com o seguinte erro:

root@cloud:/var/discourse# ./launcher rebuild synfig-forums
Garantindo que o launcher está atualizado
Buscando origin
Launcher está atualizado
Parando o container antigo
+ /usr/bin/docker stop -t 10 synfig-forums
synfig-forums
cd /pups && git pull && /pups/bin/pups --stdin
Já está atualizado.
...
Bundle completo! 124 dependências do Gemfile, 157 gems agora instaladas.
Gems nos grupos test e development não foram instaladas.
Gems do bundle estão instaladas em `./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:  valor de chave duplicada viola a restrição de unicidade "index_poll_options_on_poll_id_and_digest"
2020-02-27 10:38:06.784 UTC [414] discourse@discourse DETAIL:  A chave (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) já existe.
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: Ocorreu um erro; esta e todas as migrações posteriores foram canceladas:

ERROR:  valor de chave duplicada viola a restrição de unicidade "index_poll_options_on_poll_id_and_digest"
DETAIL:  A chave (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) já existe.
/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>'

Causado por:
PG::UniqueViolation: ERROR:  valor de chave duplicada viola a restrição de unicidade "index_poll_options_on_poll_id_and_digest"
DETAIL:  A chave (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) já existe.
/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
(Consulte o rastreamento completo executando a tarefa com --trace)
I, [2020-02-27T10:38:06.821527 #1]  INFO -- : == 20180820080623 MigratePollsData: migrando =================================
...
I, [2020-02-27T10:38:06.822339 #1]  INFO -- : Encerrando processos assíncronos
I, [2020-02-27T10:38:06.822638 #1]  INFO -- : Enviando INT para 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 -- : Enviando TERM para 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:  requisição de desligamento rápido recebida
167:signal-handler (1582799886) Recebeu SIGTERM agendando desligamento...
2020-02-27 10:38:06.825 UTC [50] LOG:  abortando todas as transações ativas
167:M 27 Feb 2020 10:38:06.828 # Usuário solicitou desligamento...
2020-02-27 10:38:06.828 UTC [50] LOG:  processo worker: lançador de replicação lógica (PID 59) saiu com código de saída 1
167:M 27 Feb 2020 10:38:06.829 * Salvando o snapshot final do RDB antes de sair.
2020-02-27 10:38:06.839 UTC [54] LOG:  desligando
2020-02-27 10:38:06.941 UTC [50] LOG:  sistema de banco de dados desligado
167:M 27 Feb 2020 10:38:07.170 * Banco de dados salvo no disco
167:M 27 Feb 2020 10:38:07.171 # Redis agora está pronto para sair, tchau tchau...


FALHA
--------------------
Pups::ExecError: cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate' falhou com retorno #<Process::Status: pid 385 exit 1>
Local da falha: /pups/lib/pups/exec_command.rb:112:in `spawn'
exec falhou com os parâmetros {"cd"=>"$home", "hook"=>"db_migrate", "cmd"=>["su discourse -c 'bundle exec rake db:migrate'"]}
77bc12013304841e8082e888a7a8c86adade040fd97b44fef1c1e85355ba2ae5
** FALHA AO INICIAR ** por favor, role para cima e procure por mensagens de erro anteriores; pode haver mais de uma.
./discourse-doctor pode ajudar a diagnosticar o problema.

Nota: Usei intencionalmente o comando ./launcher rebuild synfig-forums, pois minha instância está descrita no arquivo synfig-forums.yml, e não em app.yml.

Entendo que o problema é descrito por esta linha:

ERROR:  valor de chave duplicada viola a restrição de unicidade "index_poll_options_on_poll_id_and_digest"
DETAIL:  A chave (poll_id, digest)=(30, 399fc6670871474cd7ce0458401fd299) já existe.

O que posso fazer nessa situação? Qualquer ajuda será muito apreciada!

Ok, eu quis examinar o conteúdo do banco de dados, então fiz o seguinte:

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

obtendo um erro:

psql: não foi possível conectar ao servidor: Arquivo ou diretório não encontrado
	O servidor está rodando localmente e aceitando
	conexões no socket de domínio Unix "/var/run/postgresql/.s.PGSQL.5432"?

Você tem um índice corrompido. Consulte Can't restore due to corrupt indexes (with some clues on how to deal with corrupt indexes) para algumas dicas.

Você possui um container de banco de dados separado? Minha suposição é que sim e que você precisa entrar nesse container.

Obrigado pelas dicas!

Não, tenho uma instalação com contêiner independente (acho que é assim que se chama).

Tentei iniciar o serviço do PostgreSQL (do contêiner Docker) e obtive o seguinte:

root@cloud-synfig-forums:/var/www/discourse# service postgresql start
 * Inicializando servidor de banco de dados PostgreSQL 10                                        * Erro: O proprietário da configuração (postgres:107) e o proprietário dos dados (syslog:106) não correspondem, e o proprietário da configuração não é root
                                                                         [falha]

Ok, consegui iniciar o serviço do PostgreSQL, fiz um backup do banco de dados (Manually create and restore Discourse backups) e entrei no banco de dados:

# 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=#

Agora, o que posso fazer para recuperar minha instalação?

Isso não parece bom.

Quando você fez a reconstrução, apareceu alguma mensagem sobre atualizar o PostgreSQL? Você executou mais de uma vez?

Você tem um backup recente? Pode ser mais fácil tentar restaurar a partir dele, mas isso também será difícil.

Não me lembro. Havia muitas mensagens quando eu estava atualizando via interface web. :frowning:

E sim, executei a atualização mais de uma vez: a primeira vez pela interface web (falhou), depois pelo console (várias vezes).

Sim, tenho um backup feito há 24 horas. Posso restaurá-lo, mas algumas mensagens serão perdidas (as que foram publicadas após o backup).

Isso não é um índice corrompido.

Entre as versões 2.1 e 2.5, movemos os pools do PluginStore para tabelas adequadas. Um dos motivos para essa mudança é garantir a consistência dos dados, que é exatamente o problema que você está enfrentando.

Você tem um valor duplicado na tabela poll_options. Você pode acessá-la e excluir as entradas duplicadas?

Obrigado pela esclarecimento!
Não sou especialista em PostgreSQL… pode me ajudar com os comandos necessários para executar? (considerando que já entrei no psql). :slight_smile:

Ok, executei o seguinte:

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

Como é possível que eu tenha essa tabela vazia?

Outras tabelas não estão vazias:

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

Suspeito que a entrada duplicada venha da Loja de Plugins. Mas onde ela está localizada e como posso visualizá-la/editá-la?

É apenas mais uma tabela (plugin_store_rows).

Parece que os votos da enquete estão realmente na tabela post_custom_fields, onde a coluna name é ‘polls’.

Isso foi alterado por este commit e a migração correspondente preenche a tabela poll_options. Portanto, isso pode estar tentando inserir um registro duplicado.

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

Então, vejo duas opções para mim:

  1. Remover todos os dados de enquetes do meu banco de dados e executar o processo de atualização novamente. Dessa forma, perderei todos os enquetes, mas estou bem com isso.
  2. Modificar o código de migrate_polls_data.rb, para que ele pule a inserção de entradas duplicadas. Solução melhor, mas não sei como fazer isso.

Como posso modificar o código para permitir que essa parte falhe silenciosamente?

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

Ok, acho que basta modificar a instrução SQL adicionando ON CONFLICT DO NOTHING - https://stackoverflow.com/a/31742830
Isso funcionaria?

Ok, fiz o seguinte a partir do pgsql:

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

Ele exibiu uma linha. Então, eu a removi:

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

Nota: A maneira correta seria remover pelo ID da linha, mas como retornou apenas uma linha, fiz exatamente isso. :slight_smile:

Depois disso, reiniciei a atualização e ela foi concluída com sucesso. Obrigado a todos que compartilharam suas dicas! :slight_smile: