Creating beackup fails: Dumping the contents of table "unsubscribe_keys" failed


(Ralf Jung) #1

Trying to create a backup (with or “without files” doesn’t matter) in the admin interface fails with the following log:

[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET stylesheet_cache_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.tag_group_memberships"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.tag_group_memberships"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET tag_group_memberships_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.tag_groups"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.tag_groups"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET tag_groups_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.tag_search_data"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.tag_search_data"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET tag_search_data_tag_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.tag_users"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.tag_users"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET tag_users_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.tags"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.tags"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET tags_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.theme_fields"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.theme_fields"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET theme_fields_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.themes"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.themes"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET themes_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.top_topics"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.top_topics"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET top_topics_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_allowed_groups"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_allowed_groups"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_allowed_groups_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_allowed_users"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_allowed_users"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_allowed_users_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_custom_fields"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_custom_fields"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_custom_fields_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_embeds"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_embeds"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_embeds_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_invites"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_invites"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_invites_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_link_clicks"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_link_clicks"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_link_clicks_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_links"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_links"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_links_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_search_data"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_search_data"
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_tags"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_tags"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_tags_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_timers"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_timers"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_timers_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_users"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_users"
[2018-01-25 16:40:22] pg_dump: executing SEQUENCE SET topic_users_id_seq
[2018-01-25 16:40:22] pg_dump: processing data for table "public.topic_views"
[2018-01-25 16:40:22] pg_dump: dumping contents of table "public.topic_views"
[2018-01-25 16:40:23] pg_dump: processing data for table "public.topics"
[2018-01-25 16:40:23] pg_dump: dumping contents of table "public.topics"
[2018-01-25 16:40:23] pg_dump: executing SEQUENCE SET topics_id_seq
[2018-01-25 16:40:23] pg_dump: processing data for table "public.translation_overrides"
[2018-01-25 16:40:23] pg_dump: dumping contents of table "public.translation_overrides"
[2018-01-25 16:40:23] pg_dump: executing SEQUENCE SET translation_overrides_id_seq
[2018-01-25 16:40:23] pg_dump: processing data for table "public.twitter_user_infos"
[2018-01-25 16:40:23] pg_dump: dumping contents of table "public.twitter_user_infos"
[2018-01-25 16:40:23] pg_dump: executing SEQUENCE SET twitter_user_infos_id_seq
[2018-01-25 16:40:23] pg_dump: processing data for table "public.unsubscribe_keys"
[2018-01-25 16:40:23] pg_dump: dumping contents of table "public.unsubscribe_keys"
[2018-01-25 16:40:23] pg_dump: Dumping the contents of table "unsubscribe_keys" failed: PQgetResult() failed.
[2018-01-25 16:40:23] pg_dump: Error message from server: ERROR:  could not access status of transaction 3607772529
[2018-01-25 16:40:23] DETAIL:  Could not open file "pg_clog/0D70": No such file or directory.
[2018-01-25 16:40:23] pg_dump: The command was: COPY public.unsubscribe_keys (key, user_id, created_at, updated_at, unsubscribe_key_type, topic_id, post_id) TO stdout;
[2018-01-25 16:40:23] EXCEPTION: pg_dump failed
[2018-01-25 16:40:23] /var/www/discourse/lib/backup_restore/backuper.rb:170:in `dump_public_schema'
/var/www/discourse/lib/backup_restore/backuper.rb:35:in `run'
/var/www/discourse/lib/backup_restore/backup_restore.rb:167:in `block in start!'
/var/www/discourse/lib/backup_restore/backup_restore.rb:164:in `fork'
/var/www/discourse/lib/backup_restore/backup_restore.rb:164:in `start!'
/var/www/discourse/lib/backup_restore/backup_restore.rb:18:in `backup!'
/var/www/discourse/app/controllers/admin/backups_controller.rb:32:in `create'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/abstract_controller/base.rb:186:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/rendering.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:131:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/abstract_controller/callbacks.rb:19:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/rescue.rb:20:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.4/lib/active_support/notifications.rb:166:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.4/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.4/lib/active_support/notifications.rb:166:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.1.4/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/abstract_controller/base.rb:124:in `process'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionview-5.1.4/lib/action_view/rendering.rb:30:in `process'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-mini-profiler-0.10.7/lib/mini_profiler/profiling_methods.rb:102:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal.rb:189:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_controller/metal.rb:253:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/routing/mapper.rb:16:in `block in <class:Constraints>'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/routing/mapper.rb:46:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/journey/router.rb:33:in `each'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/journey/router.rb:33:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/routing/route_set.rb:834:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-protection-2.0.0/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:189:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/strategy.rb:167:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/omniauth-1.6.1/lib/omniauth/builder.rb:63:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/conditional_get.rb:38:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/head.rb:12:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:149:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activesupport-5.1.4/lib/active_support/callbacks.rb:97:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/logster-1.2.9/lib/logster/middleware/reporter.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/railties-5.1.4/lib/rails/rack/logger.rb:36:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/railties-5.1.4/lib/rails/rack/logger.rb:26:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:16:in `call'
/var/www/discourse/config/initializers/100-silence_logger.rb:29:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/actionpack-5.1.4/lib/action_dispatch/middleware/executor.rb:12:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-mini-profiler-0.10.7/lib/mini_profiler/profiler.rb:282:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/message_bus-2.1.1/lib/message_bus/rack/middleware.rb:63:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:138:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/railties-5.1.4/lib/rails/engine.rb:522:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/railties-5.1.4/lib/rails/railtie.rb:185:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/railties-5.1.4/lib/rails/railtie.rb:185:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/urlmap.rb:68:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `each'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `call'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/unicorn-5.3.1/lib/unicorn/http_server.rb:606:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/unicorn-5.3.1/lib/unicorn/http_server.rb:702:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/unicorn-5.3.1/lib/unicorn/http_server.rb:549:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/unicorn-5.3.1/lib/unicorn/http_server.rb:142:in `start'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/unicorn-5.3.1/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.4.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.4.0/bin/unicorn:23:in `<main>'
[2018-01-25 16:40:23] Notifying 'ralf' of the end of the backup...
[2018-01-25 16:40:33] Removing old backups...
[2018-01-25 16:40:33] Cleaning stuff up...
[2018-01-25 16:40:33] Removing '.tar' leftovers...
[2018-01-25 16:40:33] Unpausing sidekiq...
[2018-01-25 16:40:33] Marking backup as finished...
[2018-01-25 16:40:33] Finished!

This is using Discourse 1.9.2.

The server has >5GB of free disk space, so that should be fine.


(Régis Hanol) #2

Looks like a commit log corruption in your database… I hope you have another backup?


(Ralf Jung) #3

This is not about restoring, it’s about creating a backup, so I’m not sure what you mean by “another” backup?

It seems there are some backups from July, that must have been automatically created, and then it stopped doing automatic backups or so? First time I got an error was last week though. Also, the forum is otherwise working fine.