`rake posts:rebake` crashed half way through

Hi there, I ran a rake posts:rebake on my testbed site, which would normally take over 24h to finish. This morning I logged into the session and found that it had crashed about 50% of the way through. I don’t think it was out of memory because the VPS has 8GB of RAM and 15GB of swap. I also had my customized Drupal importer script crash one time several days into the import process due to a Postgres error. I have successfully run the same import script multiple times, and at least one full rake posts:rebake too. I chalked it up to a fluke that time, but this time it appears to again be another random issue with Postgres:

Rebaking post markdown for 'default'                                                                                                                                                          
  1328000 / 2625793 ( 50.6%)rake aborted!                                                                                                                                                     
ActiveRecord::StatementInvalid: PG::DataCorrupted: ERROR:  invalid page in block 181250 of relation base/16384/16846                                                                          
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rack-mini-profiler-3.0.0/lib/patches/db/pg.rb:69:in `exec_params'                                                                            
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rack-mini-profiler-3.0.0/lib/patches/db/pg.rb:69:in `exec_params'                                                                            
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:768:in `block (2 levels) in exec_no_cache'                  
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'                                                     
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'                                           
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:767:in `block in exec_no_cache'                             
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'                                
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'                            
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'                                
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'                                     
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:765:in `block in log'                                         
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'                                                    
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:756:in `log'                                                  
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:766:in `exec_no_cache'                                      
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:745:in `execute_and_clear'                                  
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:54:in `exec_query'                              
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:560:in `select'                                   
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:66:in `select_all'                                
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/query_cache.rb:110:in `select_all'                                       
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/querying.rb:54:in `_query_by_sql'                                                                     
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:942:in `block in exec_main_query'                                                         
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'                                                    
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:928:in `exec_main_query'                                                                  
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:914:in `block in exec_queries'                                                            
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary' 
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:908:in `exec_queries'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:695:in `load'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:250:in `records'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation/delegation.rb:88:in `each'
/var/www/discourse/lib/tasks/posts.rake:128:in `block in rebake_posts'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/core_ext/range/each.rb:14:in `step'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/core_ext/range/each.rb:14:in `step'
/var/www/discourse/lib/tasks/posts.rake:123:in `rebake_posts'
/var/www/discourse/lib/tasks/posts.rake:108:in `block in rebake_posts_all_sites'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rails_multisite-4.0.1/lib/rails_multisite/connection_management.rb:80:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rails_multisite-4.0.1/lib/rails_multisite/connection_management.rb:90:in `each_connection'
/var/www/discourse/lib/tasks/posts.rake:108:in `rebake_posts_all_sites'
/var/www/discourse/lib/tasks/posts.rake:7:in `block in <main>'
/usr/local/bin/bundle:25:in `load'
/usr/local/bin/bundle:25:in `<main>'
Caused by:
PG::DataCorrupted: ERROR:  invalid page in block 181250 of relation base/16384/16846
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rack-mini-profiler-3.0.0/lib/patches/db/pg.rb:69:in `exec_params'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rack-mini-profiler-3.0.0/lib/patches/db/pg.rb:69:in `exec_params'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:768:in `block (2 levels) in exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:767:in `block in exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:765:in `block in log'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:756:in `log'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:766:in `exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:745:in `execute_and_clear'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:54:in `exec_query'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:560:in `select'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:66:in `select_all'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/connection_adapters/abstract/query_cache.rb:110:in `select_all'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/querying.rb:54:in `_query_by_sql'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:942:in `block in exec_main_query'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:928:in `exec_main_query'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:914:in `block in exec_queries'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:908:in `exec_queries'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:695:in `load'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation.rb:250:in `records'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activerecord-7.0.4.1/lib/active_record/relation/delegation.rb:88:in `each'
/var/www/discourse/lib/tasks/posts.rake:128:in `block in rebake_posts'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/core_ext/range/each.rb:14:in `step'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.4.1/lib/active_support/core_ext/range/each.rb:14:in `step'
/var/www/discourse/lib/tasks/posts.rake:123:in `rebake_posts'
/var/www/discourse/lib/tasks/posts.rake:108:in `block in rebake_posts_all_sites'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rails_multisite-4.0.1/lib/rails_multisite/connection_management.rb:80:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/3.1.0/gems/rails_multisite-4.0.1/lib/rails_multisite/connection_management.rb:90:in `each_connection'
/var/www/discourse/lib/tasks/posts.rake:108:in `rebake_posts_all_sites'
/var/www/discourse/lib/tasks/posts.rake:7:in `block in <main>'
/usr/local/bin/bundle:25:in `load'
/usr/local/bin/bundle:25:in `<main>'
Tasks: TOP => posts:rebake
(See full trace by running task with --trace)

Hi!

It sounds like your Postgres state on disk is bad, either due to a specific corruption event or to an ongoing problem, like filesystem corruption or underlying disk/memory hardware faults in your VPS.

For starters you should try fsck on your filesystem.

Next, If it’s a testbed and you can rebuild the data, try starting over from scratch with PG by completely removing its data directory and creating a fresh DB. Then try stressing things by importing/rebaking again to see if the problem persists.

3 Likes

Thanks a lot @leonardo for the tips.

Now that I think about it I remember that the previous crash I experienced last week during import was specifically due to a Postgres duplicate key error, so a different error this time.

I ran an xfs_repair , with the -e option, so from what I understand it appears to not have any corruption:

xfs_repair -e /dev/sda2 
Phase 1 - find and verify superblock...
Phase 2 - using internal log
        - zero log...
        - scan filesystem freespace and inode maps...
        - found root inode chunk
Phase 3 - for each AG...
        - scan and clear agi unlinked lists...
        - process known inodes and perform inode discovery...
        - agno = 0
        - agno = 1
        - agno = 2
        - agno = 3
        - agno = 4
        - agno = 5
        - agno = 6
        - agno = 7
        - agno = 8
        - agno = 9
        - agno = 10
        - agno = 11
        - agno = 12
        - agno = 13
        - agno = 14
        - agno = 15
        - agno = 16
        - process newly discovered inodes...
Phase 4 - check for duplicate blocks...
        - setting up duplicate extent list...
        - check for inodes claiming duplicate blocks...
        - agno = 0
        - agno = 3
        - agno = 1
        - agno = 2
        - agno = 4
        - agno = 5
        - agno = 6
        - agno = 7
        - agno = 8
        - agno = 9
        - agno = 10
        - agno = 11
        - agno = 12
        - agno = 13
        - agno = 14
        - agno = 15
        - agno = 16
clearing reflink flag on inodes when possible
Phase 5 - rebuild AG headers and trees...
        - reset superblock...
Phase 6 - check inode connectivity...
        - resetting contents of realtime bitmap and summary inodes
        - traversing filesystem ...
        - traversal finished ...
        - moving disconnected inodes to lost+found ...
Phase 7 - verify and correct link counts...
done

EDIT: After the reboot (I used the rescue system to run the fsck on the unmounted filesystem) the Discourse app would start and there were no errors in the logs, but I only got the white screen of death. I had to do a rebuild of the app to make the website load again. Really not sure what went wrong with all this.