No se puede restaurar debido a índices corruptos (con algunas pistas sobre cómo tratar índices corruptos)

Soporte Instalación
1

Esta copia de seguridad ha fallado varias veces debido a errores como:

ERROR:  no se pudo crear el índice único "index_incoming_referers_on_path_and_incoming_domain_id"
DETALLE:  La clave (path, incoming_domain_id)=(/@dataandme, 41) está duplicada.
ERROR:  la transacción actual está abortada; los comandos se ignorarán hasta el final del bloque de transacción

Fui y eliminé manualmente todos esos registros en Rails con comandos como:
IncomingReferer.where(path: ‘/@dataandme’).destroy_all

Aun así, sigue fallando y ahora:

...
[2019-12-30 20:29:16] 'pfaffman' ha iniciado la restauración.
[2019-12-30 20:29:16] Marcando la restauración como en ejecución...
[2019-12-30 20:29:16] Asegurando que exista /var/www/discourse/tmp/restores/default/2019-12-30-202916...
[2019-12-30 20:29:16] Descargando el archivo comprimido al directorio tmp...
[2019-12-30 20:29:38] No hay archivo de metadatos para extraer.
[2019-12-30 20:29:38] Validando metadatos...
[2019-12-30 20:29:38]   Versión actual: 20191129144706
[2019-12-30 20:29:38]   Versión restaurada: 20191129144706
[2019-12-30 20:29:38] Extrayendo el archivo volcado...
[2019-12-30 20:30:07] Creando funciones faltantes en el esquema discourse_functions
[2019-12-30 20:30:08] No se puede restaurar en un esquema diferente; restaurando in-place
[2019-12-30 20:30:08] Habilitando el modo solo lectura...
[2019-12-30 20:30:08] Pausando sidekiq...
[2019-12-30 20:30:08] Esperando a que sidekiq termine de ejecutar los trabajos...
[2019-12-30 20:30:08] Restaurando el archivo volcado... (puede tardar bastante)

 ----- y así sucesivamente -----
[2019-12-30 20:33:17] ERROR:  la transacción actual está abortada; los comandos se ignorarán hasta el final del bloque de transacción
[2019-12-30 20:33:17] ERROR:  la transacción actual está abortada; los comandos se ignorarán hasta el final del bloque de transacción
[2019-12-30 20:33:17] EXCEPCIÓN: psql falló
[2019-12-30 20:33:17] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
/var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
/var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
/var/www/discourse/lib/backup_restore.rb:163:in `fork'
/var/www/discourse/lib/backup_restore.rb:163:in `start!'
/var/www/discourse/lib/backup_restore.rb:22:in `restore!'
/var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/base.rb:196:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/base.rb:136:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:39:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.3/lib/mini_profiler/profiling_methods.rb:104:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal.rb:191:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal.rb:252:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:51:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/mapper.rb:18:in `block in <class:Constraints>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/mapper.rb:48:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:32:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:32:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:837:in `call'
/var/www/discourse/lib/middleware/omniauth_bypass_middleware.rb:68:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/tempfile_reaper.rb:15:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/conditional_get.rb:38:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/head.rb:12:in `call'
/var/www/discourse/lib/content_security_policy/middleware.rb:12:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:318:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:232:in `context'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:226:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/cookies.rb:648:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/actionable_exceptions.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.4.2/lib/logster/middleware/reporter.rb:43:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/rack/logger.rb:28:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:18:in `call'
/var/www/discourse/config/initializers/100-silence_logger.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/var/www/discourse/lib/middleware/enforce_hostname.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/method_override.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/sendfile.rb:111:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/host_authorization.rb:77:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.3/lib/mini_profiler/profiler.rb:296:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/message_bus-2.2.3/lib/message_bus/rack/middleware.rb:57:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:181:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/engine.rb:526:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/railtie.rb:190:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/railtie.rb:190:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:68:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:605:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:700:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:548:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:144:in `start'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/bin/unicorn:128:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `<main>'
[2019-12-30 20:33:17] Intentando revertir...
[2019-12-30 20:33:17] Revertiendo...
[2019-12-30 20:33:17] Limpiando archivos...
[2019-12-30 20:33:17] Eliminando función del esquema discourse_functions
[2019-12-30 20:33:17] Eliminando el directorio tmp '/var/www/discourse/tmp/restores/default/2019-12-30-202916'...
[2019-12-30 20:33:17] Reanudando sidekiq...
[2019-12-30 20:33:17] Deshabilitando el modo solo lectura...
[2019-12-30 20:33:17] Marcando la restauración como finalizada...
[2019-12-30 20:33:17] Notificando a 'pfaffman' del final de la restauración...
[2019-12-30 20:33:34] ¡Finalizado!

Ahora no veo nada que sepa cómo solucionar.

Podría actualizar el sitio de staging al que estoy intentando restaurar, pero preferiría no actualizar el sitio de producción sin antes haber confirmado que todo funciona en staging…

2

¿Estás seguro de que psql no registró ningún otro error antes de eso? Esto suele ocurrir cuando un comando SQL anterior falló.

Además, ¿por qué la base de datos original tiene registros duplicados en la tabla incoming_referers? El índice único en esa tabla existe desde 2014. Quizás la base de datos que estás intentando restaurar tenga muchos más problemas que este.

3

¡Gracias, Gerhard! Agradezco tu ayuda. Esto se está volviendo cada vez más extraño.

Tampoco tiene sentido para mí que hubiera un problema con incoming_referers. He realizado una restauración desde producción a este sitio de staging tan recientemente como en octubre.

Parece que hay algo mal con la base de datos o con los índices. Sospeché de un plugin, pero los errores aparecen en tantos índices diferentes que parece improbable que un solo plugin sea el culpable. Un grep anterior a través de los plugins en busca de problemas con índices rotos no dio ningún resultado.

En una restauración obtuve esto:

[2020-01-03 16:25:30] ERROR:  could not create unique index "index_plugin_store_rows_on_plugin_name_and_key"

Hice lo siguiente:

[10] pry(main)> PluginStoreRow.where(plugin_name: 'discourse-data-explorer',key: 'q:-8').destroy_all

Y volví a intentarlo:

[2020-01-03 16:49:16] ERROR:  could not create unique index "index_tags_on_lower_name"
[2020-01-03 16:49:16] DETAIL:  Key (lower(name::text))=(addins) is duplicated.

Aquí está el inicio completo de la última restauración:

[2020-01-03 16:41:34] 'pfaffman' ha iniciado la restauración.
[2020-01-03 16:41:34] Marcando la restauración como en ejecución...
[2020-01-03 16:41:34] Asegurando que /var/www/discourse/tmp/restores/default/2020-01-03-164133 exista...
[2020-01-03 16:41:34] Descargando el archivo comprimido al directorio tmp...
[2020-01-03 16:45:20] No hay archivo de metadatos para extraer.
[2020-01-03 16:45:20] Validando metadatos...
[2020-01-03 16:45:20]   Versión actual: 20191220134101
[2020-01-03 16:45:20]   Versión restaurada: 20191129144706
[2020-01-03 16:45:20] Extrayendo el archivo volcado...
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] ERROR:  could not create unique index "index_tags_on_lower_name"
[2020-01-03 16:49:16] DETAIL:  Key (lower(name::text))=(addins) is duplicated.
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
4

Supongo que tendrás que limpiar los datos manualmente hasta que la restauración funcione y se puedan crear todos los índices únicos.

Aparte de eso, me pregunto si lanzamos una versión defectuosa de PostgreSQL en una de las imágenes base recientes. Hubo bastantes informes sobre problemas con índices corruptos en el último mes o dos. Parece una coincidencia extraña. :thinking:

6

Me encantaría una explicación que no fuera simplemente “Jay hizo algo estúpido de nuevo”. :wink:

Por cierto, estoy bastante seguro de que recientemente actualicé el contenedor de datos de este sitio justo antes de que esto comenzara.

8

Podrías revisar las fechas created_at de los registros duplicados e intentar averiguar qué versión de Postgres se utilizó en ese momento. @falco mencionó que PG 10.0 y 10.1 tenían problemas con índices corruptos, pero eso fue hace mucho tiempo (la versión 10.2 se lanzó el 8 de febrero de 2018) y solo comenzamos a distribuir PG 10 en abril de 2018 (después del lanzamiento de 10.2). Así que, o es un nuevo error en PG o simplemente mala suerte. :man_shrugging:

9

Hmm. Bueno, en producción tenemos la 10.10 y en staging la 10.11.

Además, en algunos de los registros que los logs indicaron como fallidos por duplicados, solo había un registro. ¿Será que el registro se eliminó pero no se borró también del índice? ¿Tiene sentido eso?

10

Ahora bien, los índices no se recrean en cada actualización.

Sí, ya que son objetos distintos en el disco.

11

Bueno, aquí tienes una pista:

discourse=> reindex table tags;
ERROR:  could not create unique index "index_tags_on_lower_name"
DETAIL:  Key (lower(name::text))=(addins) is duplicated.

discourse=> select * from tags where name='addins';
 id  |  name  | topic_count |         created_at         |         updated_at         | pm_topic_count 
-----+--------+-------------+----------------------------+----------------------------+----------------
 143 | addins |          16 | 2017-11-13 20:08:51.345607 | 2017-11-13 20:08:51.345607 |              0
(1 row)

discourse=> select * from tags where name like '%dins';
 id  |  name  | topic_count |         created_at         |         updated_at         | pm_topic_count 
-----+--------+-------------+----------------------------+----------------------------+----------------
 143 | addins |          16 | 2017-11-13 20:08:51.345607 | 2017-11-13 20:08:51.345607 |              0
 721 | addins |           3 | 2019-11-19 10:01:32.406178 | 2019-11-19 10:01:32.406178 |              0

No logro ver la diferencia entre esos dos, pero la primera consulta solo encontró uno de ellos.

12

Si ejecutas EXPLAIN ANALYZE select * from tags where name='addins';, descubrirás por qué.

Fue o bien un escaneo solo de índice (dudo que sea así, ya que estás seleccionando demasiadas columnas) o un escaneo de montón con mapa de bits, donde se usa el índice para saber qué filas seleccionar. Como el índice está corrupto…

13

Este es exactamente el problema que tuve recientemente con mi índice corrupto. Terminé inspeccionando estas cuentas y a menudo descubría que eran iguales (la misma dirección de correo electrónico); renombré una y luego las fusioné. Fue bastante trabajo, ya que fue principalmente manual, pero ahora tengo un índice nuevo y brillante :slight_smile:

Edición: ups, mi problema estaba en la tabla de usuarios. Aunque seguía siendo el mismo problema de clave duplicada.

14

Este también tenía dos entradas donde ‘shiny-server’ coincidía solo con una, pero ‘%hiney-server’ coincidía con ambas. No veo cómo esto me ayuda a entenderlo, pero creo que estás diciendo que el select que estoy haciendo espera que solo se devuelva un elemento, lo extrae del índice e ignora el otro, pero cuando uso el %, busca en los campos.

discourse=> EXPLAIN ANALYZE select * from tags where name='shiny-server'; 
                                                        QUERY PLAN                                                        
--------------------------------------------------------------------------------------------------------------------------
 Index Scan using index_tags_on_name on tags  (cost=0.28..8.29 rows=1 width=36) (actual time=0.038..0.040 rows=1 loops=1)
   Index Cond: ((name)::text = 'shiny-server'::text)
 Planning time: 0.129 ms
 Execution time: 0.070 ms
(4 filas)

Dudo bastante que alguien que no pueda resolver esto por sí mismo encuentre esto útil, pero… hice una serie de búsquedas para encontrar los dos tag_id con el mismo nombre y realicé operaciones como:

 TopicTag.where(tag_id: 717).update_all(tag_id: 611)
 Tag.ensure_consistency!
 Tag.find(717) # asegurarse de que no esté en ningún tema
 Tag.find(717).destroy

y luego ejecuté reindex table tags; en psql.

Y parece que ahora tendré que hacer lo mismo para users, algo así como @bartv describió. Aunque con mis usuarios, veo un usuario David y otro usuario david, además de [Mm]ark.

Esos los solucioné así:

marks=User.where("username similar to  '[Mm]+ark'").pluck(:id,:username,:created_at)

Luego, busqué el nuevo Mark en /admin/users y renombré al usuario allí. Después, intenté ejecutar reindex table users; en psql. (sudo su - discourse y luego psql).

15

Piénsalo de esta manera. Si necesitas buscar a Pfaffman en una guía telefónica, vas a la sección de la P, luego intentas encontrar las entradas entre Pe y Pg, después entre Pfa y Pfb, etcétera. Aprovechas que las entradas están ordenadas alfabéticamente para buscar rápidamente la entrada correspondiente. Ahora imagina, como un experimento mental, que uno de los editores de la guía telefónica no memorizó correctamente el alfabeto e insertó algunos Pfaffman en el lugar equivocado (un índice corrupto). No los encontrarás.

Ahora necesitas buscar a todas las personas cuyo apellido termine en faffman. No hay una forma rápida de hacerlo; tendrás que revisar toda la guía telefónica. ¡Eso es mucho trabajo! Pero… ¡de esta manera encontrarás a los Pfaffman insertados incorrectamente!