Job Composer breaking issue: database is locked for all (ood 3.1.7/rhel 8.10 update)

UPDATE: this has been solved! See reply below – but root issue was external to OOD


Hi all, we need some Job Composer triage help!
This is following updating ood 3.1.4->3.1.7 and rhel 8.9->8.10 and issues persist through system reboots. It seems to effect all users I’ve talked to so far, including we admins. It happens on both my production and dev boxes, too. (I recognize the irony of seeing it in dev, yes. I’m not sure if I missed it, or if “it” started after I updated -dev in July.)

Seemingly any launch of the job-composer results in:

A problem occurred while initializing your data for this app.
At your own risk you can still open the app or you can just go back to the dashboard

Share this with the developer of your app: The setup production script is supposed to be idempotent and is run each time the user opens the app through the dashboard.

Exception: OodApp::SetupScriptFailed
Per user setup failed for script at /var/www/ood/apps/sys/myjobs/./bin/setup-production for user jtb49 with output: Exception occurred: database is locked

It appears to be a virtually identical error to one @rgas20 recently encountered, 3 months ago on 3.0.3:

Sqlite3 database is locked issue

My stacktrace also is virtually identical to theirs: myjobs-stacktrace.txt (8.4 KB)

I’d love to entertain any and all pokings and proddings that might reveal more clues or solutions!

Thank you for anything you can suggest!!
–jason


PS:

Job Composer “crashes” also if you have outright removed your ~/ondemand/ directory.

Maybe I have a poor understanding of sqlite locks (odds are high, in fact) but it seems like at a minimum, creation of a new file should be possible. However, it leaves me with a touched-but-empty production.sqlite3 file…

$ ls -l ~/ondemand/data/sys/myjobs
total 0
-rw-r--r-- 1 jtb49 adm 0 Aug 19 15:00 production.sqlite3

…and with a slightly different error that starts out with the same “Exception occurred: database is locked” but is followed by some stacktrace and a smattering of debug statements:

Per user setup failed for script at /var/www/ood/apps/sys/myjobs/./bin/setup-production for user jtb49 with output: rake aborted!
ActiveRecord::StatementInvalid: SQLite3::BusyException: database is locked
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `initialize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `new'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `prepare'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:52:in `block (2 levels) in exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:49:in `block in exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:48:in `exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:107:in `query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:103:in `query_values'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/schema_statements.rb:35:in `data_sources'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/schema_cache.rb:239:in `prepare_data_sources'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/schema_cache.rb:89:in `data_source_exists?'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/model_schema.rb:380:in `table_exists?'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1108:in `get_all_versions'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1116:in `current_version'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1169:in `last_stored_environment'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/tasks/database_tasks.rb:60:in `check_protected_environments!'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/railties/databases.rake:18:in `block (2 levels) in <top (required)>'

Caused by:
SQLite3::BusyException: database is locked
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `initialize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `new'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/sqlite3-1.4.2/lib/sqlite3/database.rb:147:in `prepare'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:52:in `block (2 levels) in exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:49:in `block in exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block (2 levels) in log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activesupport-6.1.7.6/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/sqlite3/database_statements.rb:48:in `exec_query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:107:in `query'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:103:in `query_values'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/schema_statements.rb:35:in `data_sources'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/schema_cache.rb:239:in `prepare_data_sources'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/schema_cache.rb:89:in `data_source_exists?'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/model_schema.rb:380:in `table_exists?'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1108:in `get_all_versions'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1116:in `current_version'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/migration.rb:1169:in `last_stored_environment'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/tasks/database_tasks.rb:60:in `check_protected_environments!'
/opt/ood/ondemand/root/usr/share/gems/3.1/ondemand/3.1.7-1/gems/activerecord-6.1.7.6/lib/active_record/railties/databases.rake:18:in `block (2 levels) in <top (required)>'
Tasks: TOP => db:setup => db:schema:load => db:check_protected_environments
(See full trace by running task with --trace)
'RAILS_ENV=production bin/rake db:setup' failed with output: [2024-08-19 15:00:38 -0700 ] DEBUG "\e[1m\e[35m (10193.9ms)\e[0m  \e[1m\e[34mSELECT sqlite_version(*)\e[0m"
Created database '/home/jtb49/ondemand/data/sys/myjobs/production.sqlite3'
[2024-08-19 15:00:53 -0700 ] DEBUG "\e[1m\e[35m (10190.6ms)\e[0m  \e[1m\e[34mSELECT sqlite_version(*)\e[0m"

The final debug statement has an interesting mention of “SELECT sqlite_version”… interesting because we just updated to rhel 8.10 but seemingly the newest sqlite dates to 8.9. I have no idea if this is relevant though.

[root@ondemand-dev myjobs]# dnf --showduplicates list sqlite | tail -4
sqlite.i686             3.26.0-18.el8_8           rhel-8-for-x86_64-baseos-rpms
sqlite.x86_64           3.26.0-18.el8_8           rhel-8-for-x86_64-baseos-rpms
sqlite.i686             3.26.0-19.el8_9           rhel-8-for-x86_64-baseos-rpms
sqlite.x86_64           3.26.0-19.el8_9           rhel-8-for-x86_64-baseos-rpms
[root@ondemand-dev myjobs]# rpm -qa | grep -i sqlite
sqlite-devel-3.26.0-19.el8_9.x86_64
sqlite-libs-3.26.0-19.el8_9.x86_64
sqlite-3.26.0-19.el8_9.x86_64
[root@ondemand-dev myjobs]# uname -r
4.18.0-553.16.1.el8_10.x86_64

SOLVED!
Here’s how things shook out:

We received multiple other reports from researchers using different software packages that were complaining about file locks. rgas20’s post had clearly been suspecting some NFS issue, but we had not changed anything about our /home exports or mount options in a very long time.

Nonetheless, it occurred to me that if I could remove nfs from the equation, that would be smart. I was still perplexed that myjobs could touch but not “inflate” production.sqlite3 and wanted to see if that held true for local storage on, say, /tmp.

I hunted through this invaluable discourse forum and found exactly what I needed, a way to relocate “~/ondemand” (OOD_DATAROOT) for the dashboard and job-composer: Relocating /home/$user/ondemand folder
Once this was pointing at /tmp instead of /home, the Job Composer started working fine! Very interesting. I then redefined OOD_DATAROOT to point to /scratch which is also nfs, but exported from a different box.
…success again! Ah-HA.

As it turns out, on the system that exports /home, /var was 100% full. Clearing that situation up immediately allowed me to unset OOD_DATAROOT and use Job Composer like normal. No other write operations, anywhere, seemed to be impacted. Just this novel scattershot of file-lock reports. Hope this helps someone in the future!

1 Like

Great detective work! And thank you for coming back and updating to let others know, greatly appreciated!