error when visiting brand new course

[Alex-Jordan]

On develop, go into the admin course. Create a new course. Then go to that new course. For me, I see this error:

DBI connect('dbname=$webwork_dir/DATA/webwork2_job_queue.db','',...) failed: unable to open database file at /usr/local/share/perl5/Mojo/SQLite.pm line 83. 

After I reload the page, everything is fine. Or if I return to the admin course and follow the link again, everything is fine. This suggests that something is initialized the first time I see that error and then it's no longer a problem

I do not see this on my production server, which is on main but perhaps without the most recent hotfixes applied.

Is anyone able to reproduce this?

[Alex-Jordan]

To be clear, I have restarted both webwork2 and webwork2-job-queue and the issue persists.

[drgrice1]

I am unable to produce this. Can you give more precise details of how you are creating the course, or how you are entering the course? It may be that I am doing something slightly different that doesn't cause the issue.

[Alex-Jordan]

In the admin course,

1. Go to Add Course
2. Enter a course ID (I'm entering error_message)
3. I'm not entering anything else or checking any boxes. Just clicking "Add Course"
4. Click the "Log into ____" link at the bottom of the page under the success message.
5. Profit. Er... DBI connect('dbname=$webwork_dir/DATA/webwork2_job_queue.db','',...) failed: unable to open database file at /usr/local/share/perl5/Mojo/SQLite.pm line 83.
6. Reload the page, things are fine (the usual login screen for the course)

[Alex-Jordan]

I tried completely rebooting too, just to try it. And the issue persists.

[drgrice1]

That still doesn't cause the error for me.

Looking closer at your error, I see that it is failing to open the webwork2_job_queue.db file. Do you see that file in /opt/webwork/webwork2/DATA? That file should be created if not present, so does your server have read and write permissions for that directory?

[Alex-Jordan]

Yes, it's there,and the permissions all seem fine. Also it is odd that this error happens, but then upon refreshing the page it does not happen. And then I can repeat the experiment with a second course and it happens again.

[Alex-Jordan]

Would the file be locked for some reason?

[drgrice1]

Clearly something odd seems to be occurring with the job queue for you since that is what that file is for. I am guessing that you have LTI and mass grade pass back enabled site wide. Thus when you enter the course for the first time it triggers the first mass grade pass back. That is expected, but then something goes wrong and the webwork2 app is unable to access the job queue database which triggers the error.

The file isn't locked (well it probably is, but file locking generally doesn't work the way you insinuate to completely stop access). The whole point of the job queue using the database is that the webwork2 app and the job queue worker app can both access it. The webwork2 app adds jobs to the database, and then the worker queue sees them and performs them.

Can you try moving the webwork2_job_queue.db file somewhere else, and then create a course? See if the error still occurs. Then you can move the original file back.

[drgrice1]

By the way, you will need to reload the webwork2 app and restart the webwork2 job queue in between times when you move the database file.

[Alex-Jordan]

I tried what you suggested and the behavior was the same.

In site.conf, I have $job_queue{database_dsn} = 'sqlite:$webwork_dir/DATA/webwork2_job_queue.db';, which is what I have in production. And I ran check_modules to be sure, and I have Minion::Backend::SQLite.

[Alex-Jordan]

I've run through the special note about downgrading SQLite in the installation guide, etc. And everything seems to be in order. But the issue still happens.

Here is a more complete error report:

Error messages

DBI connect('dbname=$webwork_dir/DATA/webwork2_job_queue.db','',...) failed: unable to open database file at /usr/local/share/perl5/Mojo/SQLite.pm line 83.
Context

    78:   # Fork-safety

    79:   delete @$self{qw(pid queue)} unless ($self->{pid} //= $$) eq $$;

    80: 

    81:   while (my $dbh = shift @{$self->{queue} || []}) { return $dbh if $dbh->ping }

    82:   

    83:   my $dbh = DBI->connect($self->dsn, undef, undef, $self->options)

    84:     // croak "DBI connection to @{[$self->dsn]} failed: $DBI::errstr"; # RaiseError disabled

    85:   unless ($self->options->{no_wal}) {

    86:     $dbh->do('pragma journal_mode=WAL');

    87:     $dbh->do('pragma synchronous=NORMAL');

    88:   }

Call stack

    in Mojolicious::_die called at line 167 of /usr/share/perl5/vendor_perl/Carp.pm
    in Carp::croak called at line 690 of /usr/lib64/perl5/vendor_perl/DBI.pm
    in DBI::__ANON__ called at line 746 of /usr/lib64/perl5/vendor_perl/DBI.pm
    in DBI::connect called at line 83 of /usr/local/share/perl5/Mojo/SQLite.pm
    in Mojo::SQLite::_dequeue called at line 119 of /usr/local/share/perl5/Mojo/SQLite.pm
    in Mojo::SQLite::_prepare called at line 41 of /usr/local/share/perl5/Mojo/SQLite.pm
    in Mojo::SQLite::db called at line 53 of /usr/local/share/perl5/Mojo/SQLite/Migrations.pm
    in Mojo::SQLite::Migrations::migrate called at line 116 of /usr/local/share/perl5/Mojo/SQLite.pm
    in Mojo::SQLite::_prepare called at line 41 of /usr/local/share/perl5/Mojo/SQLite.pm
    in Mojo::SQLite::db called at line 59 of /usr/local/share/perl5/Minion/Backend/SQLite.pm
    in Minion::Backend::SQLite::enqueue called at line 49 of /usr/local/share/perl5/Minion.pm
    in Minion::enqueue called at line 66 of /opt/webwork/webwork2/lib/WeBWorK/Authen/LTI/MassUpdate.pm
    in WeBWorK::Authen::LTI::MassUpdate::mass_update called at line 114 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm
    in (eval) called at line 109 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm
    in WeBWorK::ContentGenerator::go called at line 247 of /opt/webwork/webwork2/lib/WeBWorK.pm
    in (eval) called at line 60 of /opt/webwork/webwork2/lib/WeBWorK.pm
    in WeBWorK::dispatch called at line 162 of /opt/webwork/webwork2/lib/Mojolicious/WeBWorK.pm
    in (eval) called at line 162 of /opt/webwork/webwork2/lib/Mojolicious/WeBWorK.pm
    in (eval) called at line 145 of /opt/webwork/webwork2/lib/Mojolicious/WeBWorK.pm
    in Mojolicious::WeBWorK::__ANON__ called at line 15 of /usr/local/share/perl5/Mojolicious/Plugins.pm
    in Mojolicious::Plugins::__ANON__ called at line 18 of /usr/local/share/perl5/Mojolicious/Plugins.pm
    in Mojolicious::Plugins::emit_chain called at line 88 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::_action called at line 161 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::_controller called at line 44 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::continue called at line 46 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::continue called at line 46 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::continue called at line 52 of /usr/local/share/perl5/Mojolicious/Routes.pm
    in Mojolicious::Routes::dispatch called at line 127 of /usr/local/share/perl5/Mojolicious.pm
    in Mojolicious::dispatch called at line 136 of /usr/local/share/perl5/Mojolicious.pm
    in Mojolicious::__ANON__ called at line 15 of /usr/local/share/perl5/Mojolicious/Plugins.pm
    in Mojolicious::Plugins::__ANON__ called at line 203 of /usr/local/share/perl5/Mojolicious.pm
    in (eval) called at line 203 of /usr/local/share/perl5/Mojolicious.pm
    in Mojolicious::_exception called at line 15 of /usr/local/share/perl5/Mojolicious/Plugins.pm
    in Mojolicious::Plugins::__ANON__ called at line 18 of /usr/local/share/perl5/Mojolicious/Plugins.pm
    in Mojolicious::Plugins::emit_chain called at line 141 of /usr/local/share/perl5/Mojolicious.pm
    in Mojolicious::handler called at line 72 of /usr/local/share/perl5/Mojo/Server.pm
    in Mojo::Server::__ANON__ called at line 15 of /usr/local/share/perl5/Mojo/EventEmitter.pm
    in Mojo::EventEmitter::emit called at line 103 of /usr/local/share/perl5/Mojo/Server/Daemon.pm
    in Mojo::Server::Daemon::__ANON__ called at line 15 of /usr/local/share/perl5/Mojo/EventEmitter.pm
    in Mojo::EventEmitter::emit called at line 60 of /usr/local/share/perl5/Mojo/Transaction/HTTP.pm
    in Mojo::Transaction::HTTP::server_read called at line 224 of /usr/local/share/perl5/Mojo/Server/Daemon.pm
    in Mojo::Server::Daemon::_read called at line 202 of /usr/local/share/perl5/Mojo/Server/Daemon.pm
    in Mojo::Server::Daemon::__ANON__ called at line 15 of /usr/local/share/perl5/Mojo/EventEmitter.pm
    in Mojo::EventEmitter::emit called at line 109 of /usr/local/share/perl5/Mojo/IOLoop/Stream.pm
    in Mojo::IOLoop::Stream::_read called at line 57 of /usr/local/share/perl5/Mojo/IOLoop/Stream.pm
    in Mojo::IOLoop::Stream::__ANON__ called at line 141 of /usr/local/share/perl5/Mojo/Reactor/Poll.pm
    in (eval) called at line 141 of /usr/local/share/perl5/Mojo/Reactor/Poll.pm
    in Mojo::Reactor::Poll::_try called at line 60 of /usr/local/share/perl5/Mojo/Reactor/Poll.pm
    in Mojo::Reactor::Poll::one_tick called at line 101 of /usr/local/share/perl5/Mojo/Reactor/Poll.pm
    in Mojo::Reactor::Poll::start called at line 134 of /usr/local/share/perl5/Mojo/IOLoop.pm
    in Mojo::IOLoop::start called at line 152 of /usr/local/share/perl5/Mojo/Server/Prefork.pm
    in Mojo::Server::Prefork::_spawn called at line 93 of /usr/local/share/perl5/Mojo/Server/Prefork.pm
    in Mojo::Server::Prefork::_manage called at line 78 of /usr/local/share/perl5/Mojo/Server/Prefork.pm
    in Mojo::Server::Prefork::run called at line 74 of /usr/local/share/perl5/Mojo/Server/Hypnotoad.pm
    in Mojo::Server::Hypnotoad::run called at line 14 of /usr/local/bin/hypnotoad

[drgrice1]

I recommend now that instead of downgrading Mojo::SQLite, you upgrade to the newest version which is 3.009. There was a problem with the version 3.008 that was in the Ubuntu 22.04 repositories. Ubuntu 24.04 has version 3.009, and the issue was fixed in that version.

So instead try to upgrade to 3.009 (just run sudo cpanm Mojo::SQLite to get the newest version) and see if that fixes the issue.

[drgrice1]

I just tested with Ubuntu 22.04 (which my production servers are still running), and version 3.009 still doesn't work. On Ubuntu 22.04 you still need to downgrade to 3.002. So the issue with newer versions of Mojo::SQLite probably has to do with other versions of related packages in the Ubuntu repositories.

[drgrice1]

Another thing to try is to switch to the Minion::Backend::mysql. I gave you instructions on how to do this at one point. That probably won't have this issue. It doesn't use that file at least.

[Alex-Jordan]

I'm only seeing this on my development server. I'm thinking for now that I will leave it be, and as I have time I will probe to see what is really going on in the hopes of learning something.

[duffee]

Please forgive me if this is a bone-headed suggestion (but on occasion it helps to ask the stupid question when you're just starting out), but

In site.conf, I have $job_queue{database_dsn} = 'sqlite:$webwork_dir/DATA/webwork2_job_queue.db';, which is what I have in production.

uses the single quote, but the sample file uses the double quote for interpolating $webwork_dir

conf/site.conf.dist:$job_queue{database_dsn} = "sqlite:$webwork_dir/DATA/webwork2_job_queue.db";

If it's working in production, then my comment is probably a red herring.

[Alex-Jordan]

This was it! $webwork_dir needs to be interpolated.

I must have been wrong about what I had in production. At this time, I have something completely different. But based on how this fixed my develop issue, I must have wrong before, at least about the quotes.

Thank you!