docker-redmine icon indicating copy to clipboard operation
docker-redmine copied to clipboard
verified publisher icon sameersbn

unicorn can't start cause database.yml has wrong permission

Open marawu opened this issue 4 years ago • 7 comments

Hi, I updated redmine to 4.2.0 version and today I restarted my server and after it I got the error:

redmine_1  | 2021-04-07 23:04:55,861 INFO success: unicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
redmine_1  | 2021-04-07 23:04:55,861 INFO exited: unicorn (exit status 1; not expected)
redmine_1  | 2021-04-07 23:04:56,864 INFO spawned: 'unicorn' with pid 315
redmine_1  | 2021-04-07 23:04:58,171 INFO success: unicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
redmine_1  | 2021-04-07 23:04:58,172 INFO exited: unicorn (exit status 1; not expected)
redmine_1  | 2021-04-07 23:04:59,174 INFO spawned: 'unicorn' with pid 316
redmine_1  | 2021-04-07 23:05:00,428 INFO success: unicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
redmine_1  | 2021-04-07 23:05:00,428 INFO exited: unicorn (exit status 1; not expected)
redmine_1  | 2021-04-07 23:05:01,431 INFO spawned: 'unicorn' with pid 317
redmine_1  | 2021-04-07 23:05:02,695 INFO success: unicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
redmine_1  | 2021-04-07 23:05:02,695 INFO exited: unicorn (exit status 1; not expected)
redmine_1  | 2021-04-07 23:05:03,698 INFO spawned: 'unicorn' with pid 319
redmine_1  | 2021-04-07 23:05:05,158 INFO success: unicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

I found message in logs:

/home/redmine/redmine/Gemfile:56:in `read':  (Bundler::Dsl::DSLError)
[!] There was an error parsing `Gemfile`: Permission denied @ rb_sysopen - /home/redmine/redmine/config/database.yml. Bundler cannot continue.
 #  from /home/redmine/redmine/Gemfile:56
 #  -------------------------------------------
 #  if File.exist?(database_file)
 >    database_config = YAML::load(ERB.new(IO.read(database_file)).result)
 #    adapters = database_config.values.map {|c| c['adapter']}.compact.uniq
 #  -------------------------------------------
	from /home/redmine/redmine/Gemfile:56:in `eval_gemfile'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:50:in `instance_eval'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:50:in `eval_gemfile'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:12:in `evaluate'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/definition.rb:33:in `build'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler.rb:194:in `definition'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler.rb:142:in `setup'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/setup.rb:20:in `block in <top (required)>'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/ui/shell.rb:136:in `with_level'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/ui/shell.rb:88:in `silence'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/setup.rb:20:in `<top (required)>'
	from /usr/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in `require'
	from /usr/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in `require'
/home/redmine/redmine/Gemfile:56:in `read': Permission denied @ rb_sysopen - /home/redmine/redmine/config/database.yml (Errno::EACCES)
	from /home/redmine/redmine/Gemfile:56:in `eval_gemfile'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:50:in `instance_eval'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:50:in `eval_gemfile'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/dsl.rb:12:in `evaluate'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/definition.rb:33:in `build'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler.rb:194:in `definition'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler.rb:142:in `setup'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/setup.rb:20:in `block in <top (required)>'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/ui/shell.rb:136:in `with_level'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/ui/shell.rb:88:in `silence'
	from /var/lib/gems/2.6.0/gems/bundler-2.2.15/lib/bundler/setup.rb:20:in `<top (required)>'
	from /usr/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in require
	from /usr/lib/ruby/2.6.0/rubygems/core_ext/kernel_require.rb:54:in require'

When I changed config/database.yml permission from 640 to 644, unicorn started, but after restart container I got the same error. How to fix it? I tried to remove image, but it didn't help

marawu avatar Apr 07 '21 20:04 marawu

What database are you using? And what env variables have you set?

I launched a 4.1.2 image with a fresh database. Then switched to the 4.2.0 image and let it do the migration. The image started just fine. And the permissions for database.yml are 640 which is correct:

 $ docker-compose exec redmine ls -la /home/redmine/redmine/config/database.yml
-rw-r----- 1 redmine redmine 170 Apr  8 03:02 /home/redmine/redmine/config/database.yml

When I changed config/database.yml permission from 640 to 644, unicorn started, but after restart container I got the same error. How to fix it? I tried to remove image, but it didn't help

The fact that setting the other permission value worked must mean that either unicorn is not being started as the redmine user or your database.yml file isn't owned by the redmine user. I'm not sure how either of these things could be wrong, but know how you start/configure the image may help reproduce this.

jcormier avatar Apr 07 '21 21:04 jcormier

FYI, I tested with the postgres database

jcormier avatar Apr 07 '21 21:04 jcormier

I use PostgreSQL 12, my env variables:

      - DB_ADAPTER=postgresql
      - DB_HOST=172.17.0.1
      - DB_NAME=redmine
      - DB_USER=redmine
      - DB_PASS=password

root@43ecc6ef767f:/home/redmine/redmine# ps -aux | grep [u]nicorn
redmine    292  0.0  0.7 272492 63960 ?        Sl   Apr07   0:03 unicorn_rails master -E production -c /home/redmine/redmine/config/unicorn.rb
redmine    294  0.0  2.6 602032 218992 ?       Sl   Apr07   0:25 unicorn_rails worker[0] -E production -c /home/redmine/redmine/config/unicorn.rb
redmine    296  0.0  2.6 539880 219496 ?       Sl   Apr07   0:27 unicorn_rails worker[1] -E production -c /home/redmine/redmine/config/unicorn.rb

I use docker-compose for start redmine:

version: '2'
services:
  redmine:
    image: sameersbn/redmine:4.2.0
    ports:
      - 3000:80
    environment:
      - TZ=Europe/Moscow
      - DB_ADAPTER=postgresql
      - DB_HOST=172.17.0.1
      - DB_NAME=redmine
      - DB_USER=redmine
      - DB_PASS=password
      - REDMINE_PORT=3000
      - SMTP_ENABLED=true
      - SMTP_METHOD=smtp
      - SMTP_DOMAIN=example.com
      - SMTP_HOST=smtp.example.com
      - SMTP_PORT=465
      - [email protected]
      - SMTP_PASS=password
      - SMTP_OPENSSL_VERIFY_MODE=none
      - SMTP_STARTTLS=true
      - SMTP_TLS=true
      - SMTP_AUTHENTICATION=:login
      - NGINX_MAX_UPLOAD_SIZE=100m
    volumes:
      - /srv/docker/redmine/rgloader:/home/redmine/redmine/rgloader
      - /srv/docker/redmine/redmine:/home/redmine/data

The redmine user is owner the file:

root@43ecc6ef767f:/home/redmine/redmine# ls -l config
total 96
-rw-rw-r-- 1 redmine redmine   219 Mar 28 11:00 additional_environment.rb.example
-rw-rw-r-- 1 redmine redmine  3609 Mar 28 11:00 application.rb
-rw-rw-r-- 1 redmine redmine   202 Mar 28 11:00 boot.rb
-rw-r----- 1 redmine redmine  9254 Apr  7 23:08 configuration.yml
-rw-rw-r-- 1 redmine redmine  8738 Mar 28 11:00 configuration.yml.example
-rw-r--r-- 1 redmine redmine   161 Apr  7 23:08 database.yml
-rw-rw-r-- 1 redmine redmine  1328 Mar 28 11:00 database.yml.example
-rw-rw-r-- 1 redmine redmine   617 Mar 28 11:00 environment.rb
drwxrwxr-x 2 redmine redmine  4096 Mar 28 11:00 environments
drwxrwxr-x 1 redmine redmine  4096 Apr  7 23:03 initializers
drwxrwxr-x 2 redmine redmine  4096 Mar 28 11:00 locales
-rw-rw-r-- 1 redmine redmine 19155 Mar 28 11:00 routes.rb
-rw-rw-r-- 1 redmine redmine  7264 Mar 28 11:00 settings.yml
-rw-r--r-- 1 redmine redmine  4513 Apr  7 23:08 unicorn.rb

When I updated redmine migration was successful

marawu avatar Apr 08 '21 07:04 marawu

I see the same thing except my database file doesn't have the group read attribute. And the unicorn process looks similiar.

 $ docker-compose exec redmine ls -l config
total 84
-rw-rw-r-- 1 redmine redmine   219 Mar 28 13:30 additional_environment.rb.example
-rw-rw-r-- 1 redmine redmine  3609 Mar 28 13:30 application.rb
-rw-rw-r-- 1 redmine redmine   202 Mar 28 13:30 boot.rb
-rw-r----- 1 redmine redmine  8951 Apr  9 21:59 configuration.yml
-rw-rw-r-- 1 redmine redmine  8738 Mar 28 13:30 configuration.yml.example
-rw-r----- 1 redmine redmine   170 Apr  9 21:59 database.yml
-rw-rw-r-- 1 redmine redmine  1328 Mar 28 13:30 database.yml.example
-rw-rw-r-- 1 redmine redmine   617 Mar 28 13:30 environment.rb
drwxrwxr-x 1 redmine redmine   124 Mar 28 13:30 environments
drwxrwxr-x 1 redmine redmine   222 Apr  8 03:02 initializers
drwxrwxr-x 1 redmine redmine   618 Mar 28 13:30 locales
-rw-rw-r-- 1 redmine redmine 19155 Mar 28 13:30 routes.rb
-rw-rw-r-- 1 redmine redmine  7264 Mar 28 13:30 settings.yml
-rw-r--r-- 1 redmine redmine  4513 Apr  9 21:59 unicorn.rb
 $ docker-compose exec redmine  ps -aux | grep [u]nicorn
redmine    257  1.8  0.4 252580 138964 ?       Sl   21:59   0:02 unicorn_rails m
redmine    262  0.0  0.3 253376 124556 ?       Sl   21:59   0:00 unicorn_rails w
redmine    264  0.0  0.3 253376 124860 ?       Sl   21:59   0:00 unicorn_rails w

Your docker-compose file looks fine. The biggest difference is your using your own postgres server but I don't see why that would cause this issue. Could you try the default docker-compose.yml from the repo as a test?

jcormier avatar Apr 09 '21 16:04 jcormier

Hi, i have the same error. I am trying upgrade 4.0.4 to latest and 4.0.4 to 4.1.2-1. I am using external postgres in version 9.4. Also i checked my postgres log. And there was a surprise:

redmine@postgres ERROR: database "redmine_production" already exists redmine@postgres STATEMENT: CREATE DATABASE "redmine_production" ENCODING = 'unicode'

For some reason, migration task trying create new database instade of update the old one.

So - the databace config is porpertly, because the connection is up and user is authenticated. Maybe this is a real reason of this error, not configuration file permission?

torer avatar Oct 08 '21 10:10 torer

@torer Could you post the full log? How are you launching the docker?

jcormier avatar Oct 08 '21 14:10 jcormier

@jcormier in attachment have full log. redmine.log

But propably it is other problem.

I make test on three docker server.

The first one is Server Version: 18.09.1 Storage Driver: aufs

The second one: Server Version: 19.03.5 Storage Driver: overlay2

The thrid one (exacly copy of second server): Server Version: 19.03.5 Storage Driver: overlay2

On the firs one, everyfing is fine, redmine is up and runnind. On the second one, ruby cant get access to database.yml (bash script succefuli modified this file) On the thrid, everyfing is fine, redmine is up and runnind.

So its look like docker engien problem on my system. But funny is, i can start sameersbn/redmine:4.0.4 on all three serwers. Weird stuff. If i find exacly reason, i will back here, but probably i'll just reinstll second server.

torer avatar Oct 11 '21 11:10 torer