willbrowning's avatar

production.ERROR: Call to a member function beginTransaction() on null

I have just created a digitalocean droplet and pushed my local app to the server and changed the environment to production.

I am using the database queue driver to process jobs, this has worked perfectly fine on my local development server however on the live production server I keep getting the following error in storage/logs/laravel.log

[2017-02-24 10:03:50] production.ERROR: Symfony\Component\Debug\Exception\FatalThrowableError: Call to a member function beginTransaction() on null in /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Database/Concerns/ManagesTransactions.php:108
Stack trace:
#0 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Database/Concerns/ManagesTransactions.php(92): Illuminate\Database\Connection->createTransaction()
#1 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Queue/DatabaseQueue.php(192): Illuminate\Database\Connection->beginTransaction()
#2 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(236): Illuminate\Queue\DatabaseQueue->pop('default')
#3 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(101): Illuminate\Queue\Worker->getNextJob(Object(Illuminate\Queue\DatabaseQueue), 'default')
#4 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(100): Illuminate\Queue\Worker->daemon('database', 'default', Object(Illuminate\Queue\WorkerOptions))
#5 /srv/users/serverpilot/apps/myapp/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(83): Illuminate\Queue\Console\WorkCommand->runWorker('database', 'default')
#6 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()

etc...

I am not sure but does this mean the database connection is not connected? The website itself appears to work correctly with all data from the database being returned.

I have supervisor configured correctly.

I've searched everywhere but cannot find any solutions to this. It keeps constantly logging this same error to the log file every 3 seconds.

Any help would be greatly appreciated.

Thanks

0 likes
22 replies
willbrowning's avatar

I think it is an error related to the database queue with supervisor. It is printing the error out every three seconds even though the website has connected correctly to the database and is working as it should.

This is my supervisor config file contents

[program:my-app]
process_name=%(program_name)s_%(process_num)02d
command=/usr/bin/php /srv/users/serverpilot/apps/my-app/artisan queue:work database --sleep=3 --tries=3
autostart=true
autorestart=true
user=serverpilot
numprocs=8
redirect_stderr=true
stdout_logfile=/srv/users/serverpilot/apps/my-app/supervisor.log
willbrowning's avatar

I am certain it is related to supervisor as I just ran

sudo supervisorctl stop my-app:*

and the errors immediately stopped being posted to the laravel log file.

So there seems to be an error where supervisor is not connecting to the database correctly?

Should the user be root and do I need to include a password in the config file? Also is /usr/bin/php correct for the command line?

It is strange because even though it was printing errors it still seemed to process the jobs fine.

willbrowning's avatar

After stopping and then starting supervisor again, it works normally for a day or so then the error starts again.

Beginning with:

production.ERROR: PDOException: SQLSTATE[HY000] [2002] Connection refused in /srv/users/serverpilot/apps/my-app/vendor/laravel/framework/src/Illuminate/Database/Connectors/Connector.php:68

I am not sure but I think it may be a permission error, as after I push an update to the server with git and git hooks then run ls -l in the app root directory. The artisan file and some others have root as the owner and group.

Could this be what is causing the error, because I have user=serverpilot in the supervisor config?

I have just run sudo chown -R supervisor:supervisor /srv/users/supervisor/apps So will see if the error still appears after a day or so.

willbrowning's avatar

The strange thing is that the connection refused error message seems to be appearing at exactly 06:25:17 in the log each morning.

After the connection refused error appears it is then followed by the "Call to a member function beginTransaction() on null" error being printed every 3 seconds until I restart the supervisor worker.

Does anybody have any ideas at all as to what might be causing the connection to be refused at this time each day?

ifpingram's avatar

@ttwb no idea what is causing this, but we are having exactly the same problem currently. We will post more as/when/if we find anything...

1 like
willbrowning's avatar

Same errors were logged at [2017-03-02 06:25:15] again this morning.

I am also using laravel 5.4.12 @komirad @ifpingram are you both using the database as the queue driver? Do you have similar supervisor configurations? Are your servers with digitalocean?

It's very odd that it seems to be happening at the exact same time each day.

ifpingram's avatar

@ttwb we can't find a solution to this, so what we have done is we restart the relevant supervisor jobs via a cron every hour. It's not ideal, but it seems to work, as we've not had these PDO exceptions thrown this morning...

willbrowning's avatar

@ifpingram I was thinking of doing something similar, thanks. Would you be able to post the cron job config you've set up to do this?

willbrowning's avatar

@ifpingram I set an hourly cron job in the root users crontab -e @hourly /root/restart-supervisor.sh

Where restart-supervisor.sh contains:

#!/bin/sh

sudo supervisorctl stop my-app:*
sudo supervisorctl start my-app:*

The errors were again logged at 06:25:19 this morning and began throwing the beginTransaction() on null exception every 3 seconds.

It did however then stop at 07:00:01 when the cron job was run on the hour. Ideally need to stop it from being logged at all as the log file had already grown 10mb in size.

I have a feeling it may be something to do with the server?

ifpingram's avatar

@ttwb I just put the command in Forge as:

157276 Hourly 0 * * * * root /usr/bin/supervisorctl restart laravel-worker-scriptname:*

I haven't had a chance yet to analyse the logs, but should do so next week to see if it is causing errors still for a while like yours is.

No idea if it is the server, or something in the code base / supervisor. This is on a box provisioned by Laravel Forge (Ubuntu) using php7.1; is that a similar server environment to yours?

willbrowning's avatar

@ifpingram I changed the crontab to

26 06 * * * /root/restart-supervisor.sh

So that it runs at 06:25am each day and I checked the log this morning and no errors had been printed. Hopefully this temporary fix will do for the time being.

Our server is Ubuntu 16.04 with digital ocean. Using serverpilot, php 7.1 only been running for just over a week.

ifpingram's avatar

@ttwb good stuff - fingers crossed it works! I have a feeling that this temporary fix will become permanent, as it looks like it might take quite a lot of work to get to the bottom of, and I don't have the time to investigate any further. :( I'll keep an eye on the thread in case you have the chance to investigate further yourself, but I would say that this hack should suffice...

willbrowning's avatar

@ifpingram I have found the source of the problem, turns out it was related to the server.

I am going to assume your server is with Digital Ocean as mine was.

If you go to /var/log/syslog on your server and scroll to 06:25:00 where the errors start occurring you can see that it happens because the mysqld process gets killed to free up memory.

If you look at the droplet usage graphs in your DO dashboard you can see a spike at this time.

I considered upgrading the droplet as I was on the $5 plan, however I then saw this thread:

https://www.digitalocean.com/community/questions/getting-regular-out-of-memory-kill-process-how-to-resolve-this-isse

Where people were saying they were still getting the issue even after upgrading. There was no response from DO support and I couldn't find a solution to it anywhere.

I decided in the end to migrate my sites to Vultr. I am on the $5 but getting twice the memory and more SSD space for the same price.

Have had it running a few days now and not had a single error in the log. Very happy with the decision to migrate so far.

1 like
ifpingram's avatar

@ttwb good find! Yes, this is on a Digital Ocean VM, although we're not reporting any errors since adding the supervisor restarting job, but if / once it rears it's ugly head again we'll follow your findings above. I just don't have the time at present to re-provision a new server... Many thanks for all your digging here; much appreciated!

bretto36's avatar

I'm getting the same issue, on Digital Ocean, at 6:26 AM GMT. My error logs start producing this.

Did anyone actually find a permanent solution to this that isn't just restarting supervisor job every hour?

willbrowning's avatar

@bretto36 are you on the $5 plan? To be honest the only permanent solution I know of is migrating your server to vultr. This is what I've done and not had a single error since, the issue is with the digital ocean servers.

bretto36's avatar

@tttwb Yes i'm on the $5 plan. Thanks for the info! I'm just using DO as a staging server. Will be using aws for the production, but might switch my staging over to vultr. Thanks for the headsup

mkwsra's avatar

Same issue here! (DigitalOcean) and the same time, same shit!!

I'm going to move to AWS or Vultr!

Please or to participate in this conversation.