Facing timeout issues on migration step

[piyush0609]

Recently we added timeouts for our database with configuration like
Configuration from database.yml
connect_timeout: 5
read_timeout: 5
write_timeout: 5
checkout_timeout: 5
All values are in seconds

---

Steps to reproduce

When i run cap production deploy the deployment fails on migration step and gives error
Mysql2::Error::TimeoutError: Timeout waiting for a response from the last query.

Expected behavior

We want use MAX_EXECUTION_TIME=90000 rake db:migrate during our cap deploy and we will add a variable max_execution_time in our database.yml which will default to 5 seconds.
Additionally we could inject read_timeout also along with it if the max execution time doesn't work alone.

Actual behavior

We cannot control the injection of this variable because our Capfile uses capistrano/rails which will run rake db:migrate without maximum execution time and our migration could take much more time than our DB timeouts.

[mattbrictson]

You could use the default env feature of Capistrano to prepend MAX_EXECUTION_TIME=90000 to every command, which would include rake db:migrate. Would that work?

# config/deploy.rb

set :default_env, { MAX_EXECUTION_TIME: "90000" }

[piyush0609]

Thanks @mattbrictson. Yeah that would work but recently i came across this https://capistranorb.com/documentation/advanced-features/overriding-capistrano-tasks/. So i am going ahead and using this

[mattbrictson]

Great thanks for the follow up. Please close this issue once you get it working.

[piyush0609]

Sure @mattbrictson. Will close the issue once i test your implementation as well as mine.

[piyush0609]

You could use the default env feature of Capistrano to prepend MAX_EXECUTION_TIME=90000 to every command, which would include rake db:migrate. Would that work?

# config/deploy.rb

set :default_env, { MAX_EXECUTION_TIME: "90000" }

Het @mattbrictson this didn't work. I still faced the timeout issue

[mattbrictson]

Can you add a debug statement in your app somewhere, maybe config/boot.rb to confirm that your app is actually receiving the environment as you expect?

# config/boot.rb
puts "MAX_EXECUTION_TIME: #{ENV['MAX_EXECUTION_TIME']}"

Also does the capistrano log show that MAX_EXECUTION_TIME=90000 is being set when rake db:migrate is run?

Mysql timeouts are outside my area of expertise so I can't really help you with that part, but please let me know if capistrano is not setting the env as you expect.

[piyush0609]

Also does the capistrano log show that MAX_EXECUTION_TIME=90000 is being set when rake db:migrate is run?

No MAX_EXECUTION_TIME=90000 was not being set when rake db:migrate was ran

[mattbrictson]

Thanks for following up. I will dig into this some more to see if a bug is lurking in :default_env or the db:migrate task.

[piyush0609]

Thanks for following up. I will dig into this some more to see if a bug is lurking in :default_env or the db:migrate task.

I believe there is no issue with default_env so don't worry about that

[mattbrictson]

I tested this and it seems to work fine for me.

I configured capistrano as follows:

# config/deploy.rb
set :default_env, { MAX_EXECUTION_TIME: "90000" }

And modified the Rails app for debugging purposes:

# config/boot.rb
puts "MAX_EXECUTION_TIME: #{ENV['MAX_EXECUTION_TIME']}"

When I run cap production deploy I see in the output:

00:51 deploy:migrating
      01 bundle exec rake db:migrate
      01 MAX_EXECUTION_TIME: 90000
    ✔ 01 deployer@xxx.xxx.xxx.xxx 3.053s

As you can see MAX_EXECUTION_TIME is printed so that means the environment variable is being received by the application.

If I look at log/capistrano.log I can see how it is being passed:

  INFO [17347914] Running bundle exec rake db:migrate as deployer@xxx.xxx.xxx.xxx
 DEBUG [17347914] Command: cd /var/www/rails-new/releases/20191005211316 && ( export MAX_EXECUTION_TIME="90000" RAILS_ENV="production" ; bundle exec rake db:migrate )
 DEBUG [17347914]   MAX_EXECUTION_TIME: 90000
  INFO [17347914] Finished in 3.053 seconds with exit status 0 (successful).

[mattbrictson]

Perhaps the problem is the :default_env is being overwritten by another task in your capistrano setup? One way to troubleshoot is to run:

$ cap production doctor:variables

Variables

...
    :default_env                 {:MAX_EXECUTION_TIME=>"90000"}