Pull request #161 seems to have broken MongoDB 3.4 Docker image for me #164

rberlind · 2017-03-31T22:52:05Z

About an hour ago, shortly after #161 was merged into the Docker 3.4 image by docker-library/official-images#2805, I found that I could not start newly deployed Docker image mongo:3.4 on the Apcera platform.

I get the errors:

[stdout] about to fork child process, waiting until server is ready for connections.
[stdout] forked process: 18
[stdout] ERROR: child process failed, exited with error number 1
[system-error] Process 'app' failed with status "exited(1)"

I would appreciate it if the MongoDB team could investigate whether the modifications to the script (which admittedly seem harmless) could have caused the problem.

Thanks,
Roger Berlind
Apcera

faustman · 2017-04-03T12:49:55Z

Seems it broken for me too,

first things, it can't start in a usual way:

chown: cannot dereference '/proc/1/fd/1': Permission denied
chown: cannot dereference '/proc/1/fd/2': Permission denied
about to fork child process, waiting until server is ready for connections.
forked process: 18
ERROR: child process failed, exited with error number 1

with --user mongodb flag it just failed with

about to fork child process, waiting until server is ready for connections.
forked process: 18
ERROR: child process failed, exited with error number 1

numblr · 2017-04-03T12:55:28Z

Experience exactly the same problems as @faustman. I mounted a host directory as a data volume for /data (I'm running the container from a bamboo Docker task).

tianon · 2017-04-03T17:02:37Z

The references to chown: cannot dereference '/proc/1/fd/1': Permission denied are due to SELinux or AppArmor.

Can you please provide the full failing container logs (preferably with a full docker run line we can replicate)? It's probably also worth trying with --entrypoint mongod to verify that mongod by itself without our additions can even start successfully.

numblr · 2017-04-04T07:14:13Z

docker run line was:
/usr/bin/docker run --volume /home/bamboo-agent-home/xml-data/build-dir/SUM-VLE371-JOB1:/data --detach --name mongodb -p 27018:27017 mongo:3.0 --smallfiles
What @faustman posted is already the full container log for me (obtained with docker logs --tail=1000 mongodb). Possible that the permissions for the /data directory are not set correctly by the Dockerfile in my case, but it is working with 3.0.12.

faustman · 2017-04-04T08:48:43Z

So there some debug info:

$ uname -a
Linux semaphore-1703 3.13.0-32-generic #57-Ubuntu SMP Tue Jul 15 03:51:08 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

$ lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 14.04.1 LTS
Release:	14.04
Codename:	trusty

$ docker --version
Docker version 1.12.6, build 78d1802

The failed launch:

$ docker run -ti mongo:latest
Unable to find image 'mongo:latest' locally
latest: Pulling from library/mongo
e45e882ed798: Pull complete 
b03f96593290: Pull complete 
90df9ef9b571: Pull complete 
a647e09745f6: Pull complete 
b394c03fdf0b: Pull complete 
081d72a1938b: Pull complete 
7584b1f09d77: Pull complete 
9504d8d990d3: Pull complete 
ef2c764578cc: Pull complete 
72d6c3d04bd3: Pull complete 
c9f39c9396b6: Pull complete 
Digest: sha256:a7ceb608b83148802e418e7794f397540f41c8b595930541408f5c6e0f92bddc
Status: Downloaded newer image for mongo:latest
chown: cannot dereference '/proc/1/fd/1': Permission denied
chown: cannot dereference '/proc/1/fd/2': Permission denied
about to fork child process, waiting until server is ready for connections.
forked process: 18
ERROR: child process failed, exited with error number 1

Launch with new entrypoint:

$ docker run -ti --entrypoint mongod mongo:latest
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=1df98ec8291b
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] db version v3.4.3
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] git version: f07437fb5a6cca07c10bafa78365456eb1d6d5e1
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1t  3 May 2016
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] modules: none
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] build environment:
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten]     distmod: debian81
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten]     distarch: x86_64
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2017-04-04T08:43:04.176+0000 I CONTROL  [initandlisten] options: {}
2017-04-04T08:43:04.186+0000 I STORAGE  [initandlisten] 
2017-04-04T08:43:04.186+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2017-04-04T08:43:04.186+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2017-04-04T08:43:04.186+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1464M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] 
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] 
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] 
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] 
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2017-04-04T08:43:04.207+0000 I CONTROL  [initandlisten] 
2017-04-04T08:43:04.212+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
2017-04-04T08:43:04.216+0000 I INDEX    [initandlisten] build index on: admin.system.version properties: { v: 2, key: { version: 1 }, name: "incompatible_with_version_32", ns: "admin.system.version" }
2017-04-04T08:43:04.216+0000 I INDEX    [initandlisten] 	 building index using bulk method; build may temporarily use up to 500 megabytes of RAM
2017-04-04T08:43:04.217+0000 I INDEX    [initandlisten] build index done.  scanned 0 total records. 0 secs
2017-04-04T08:43:04.217+0000 I COMMAND  [initandlisten] setting featureCompatibilityVersion to 3.4
2017-04-04T08:43:04.217+0000 I NETWORK  [thread1] waiting for connections on port 27017

Hope that helpful.

elouanKeryell-Even · 2017-04-11T12:24:01Z

Getting same issue with mongo:3.0.14. I fixed it by running it as mongodb user, following advice given by this comment:

docker run --user mongodb -ti mongo:3.0.14

rberlind · 2017-04-11T16:52:59Z

Running with user set to mongodb still fails for me with same error.

yosifkit · 2017-04-11T21:24:54Z

We added some fixes in #167 to hopefully account for this; can you pull and see if the latest image works for you?

Unfortunately we don't yet have a good way to have the initdb.d/ additions from #145 work with a config file.

You should be able to work around the new additions by setting ENTRYPOINT [] and USER mongodb at the end of your Dockerfile since that is what the previous entrypoint script provided (or docker run --user mongodb --entrypoint mongod mongo:3 --mongod-args). This would require you to ensure any external volumes used are the correct permissions for the mongodb user from the image.

We are trying to fix any bugs caused by adding the initdb.d/ functionality, but have been unable to reproduce and discover the cause.

rberlind · 2017-04-11T21:29:25Z

Thanks, but I'm not actually building my own docker image. I'm using a public demo (not under my control) that is using the mongo:3.4 docker image. I believe the test I did today which failed would have pulled in #167 as part of mongo:3.4. Right?

tianon · 2017-04-11T23:40:52Z

@rberlind if it did a docker pull of the latest image, it would include #167 for sure (can't say it definitely included it otherwise) 😞

I've tried CentOS 7, Ubuntu 16.04, and Ubuntu 14.04, stock configurations (SELinux, AppArmor, kernel, etc), and cannot reproduce the failures described. 😞

Anyone have any tips for reproducing? (or have a throwaway system that exhibits the issue that they'd be willing/able to get me access to so I can debug and figure out a fix?)

jperville · 2017-04-12T07:48:35Z

@tianon

We have the issue on our CI servers, which run docker 1.9.1(because of https://bugzilla.redhat.com/show_bug.cgi?id=1346167). The issue does not show up on my developer workstation, which runs docker 1.13.1.

Our current workaround is to replace "mongodb:3" with "mongodb:3.2.10" in the CI configuration for our applications that use mongodb.

# docker pull mongo:3.2
3.2: Pulling from library/mongo

Digest: sha256:921a00b8fb34be1b0daacacd28f2514b5345b7415cd64c88ba885bdffa9168d9
Status: Image is up to date for mongo:3.2

# docker run --rm -ti mongo:3.2
chown: cannot dereference '/proc/1/fd/1': Permission denied
chown: cannot dereference '/proc/1/fd/2': Permission denied
about to fork child process, waiting until server is ready for connections.
forked process: 19
ERROR: child process failed, exited with error number 1

# docker run --rm -ti -u mongodb mongo:3.2
about to fork child process, waiting until server is ready for connections.
forked process: 11
ERROR: child process failed, exited with error number 1

# docker info
Containers: 308
Images: 370
Server Version: 1.9.1
Storage Driver: overlay
 Backing Filesystem: xfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.4.0-66-generic
Operating System: Ubuntu 14.04.5 LTS
CPUs: 4
Total Memory: 5.797 GiB
Name: staging4-ci
ID: DQMV:EDFS:56O6:ICHH:XCHV:ZZIP:5JGG:QQZI:2644:NK3U:OALO:RBMK
root@staging4-ci:~#

elouanKeryell-Even · 2017-04-12T09:44:13Z

@tianon is there a way I can contact you privately? Maybe I can help you debug that issue.

tianon · 2017-04-12T17:10:46Z

@elouanKeryell-Even yeah, I'm tianon on Freenode IRC, OFTC IRC, and the Docker Community Slack, if any of those work for you

@jperville hmm, I wonder if Docker 1.9 isn't setting up something AppArmor-related in the same way as more recent versions?

tianon · 2017-04-13T17:05:07Z

Ok, I've reproduced. I had to get a little crazy to do so (Ubuntu 14.04 and Docker 1.9.1), but here we go:

root@ubuntu:~# docker version
Client:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:12:04 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:12:04 UTC 2015
 OS/Arch:      linux/amd64
root@ubuntu:~# docker run -it --rm mongo
Unable to find image 'mongo:latest' locally
latest: Pulling from library/mongo
46fb18fe2b28: Pull complete 
6663ec33e418: Pull complete 
a6364f26734e: Pull complete 
4b208dafe437: Pull complete 
03508c869c20: Pull complete 
dc11d2b6d89e: Pull complete 
dc99e3401f88: Pull complete 
9da419f53201: Pull complete 
51e3dc891d7d: Pull complete 
f9bee0a48714: Pull complete 
b5157dc51f09: Pull complete 
5937baf8ba1f: Pull complete 
f1ccdda06994: Pull complete 
cb890acc553e: Pull complete 
63a3495fb354: Pull complete 
dae54b472975: Pull complete 
371f686c501e: Pull complete 
5d84202328d2: Pull complete 
2d38d4c16a00: Pull complete 
d953c06809dc: Pull complete 
559a3b2b592b: Pull complete 
Digest: sha256:e8b292cca3cd3bb9ba09cd0cfbcbb81ec55cf7f6de3d389ad4e99e46b426dafd
Status: Downloaded newer image for mongo:latest
chown: cannot dereference '/proc/1/fd/1': Permission denied
chown: cannot dereference '/proc/1/fd/2': Permission denied
about to fork child process, waiting until server is ready for connections.
forked process: 18
ERROR: child process failed, exited with error number 1
root@ubuntu:~# docker run -it --rm mongo gosu mongodb bash
mongodb@92ff45ed6adb:/$ ls -l /proc/1/fd/1
ls: cannot read symbolic link /proc/1/fd/1: Permission denied
lrwx------ 1 mongodb mongodb 64 Apr 13 17:02 /proc/1/fd/1
mongodb@92ff45ed6adb:/$ echo hi >> /proc/1/fd/1
bash: /proc/1/fd/1: Permission denied
mongodb@92ff45ed6adb:/$ test -w /proc/1/fd/1 && echo yay || echo oh no
oh no
mongodb@92ff45ed6adb:/$

tianon · 2017-04-13T17:19:26Z

Ok, my planned workaround won't work with newer Docker versions -- I upgraded to 17.04, and now I can write to /proc/1/fd/1 just fine, my test -w /proc/1/fd/1 tells me we're fine, but mongod still fails:

mongodb@f76e9ea37a0b:/data/db$ mongod --logpath /proc/1/fd/1 --logappend
2017-04-13T17:18:28.753+0000 F CONTROL  [main] Failed global initialization: FileNotOpen: Failed probe for "/proc/1/fd/1": Permission denied

tianon · 2017-04-13T17:22:37Z

Ah, it uses boost::filesystem::absolute to test for existence of the file, which will resolve to /1, and fails. 😞 😭

Edit: ala:

mongodb@9c72eaed7974:/$ readlink -f /proc/1/fd/1
mongodb@9c72eaed7974:/$

tianon · 2017-04-13T17:24:33Z

Honestly, I can't see how this ever worked. 😅

tianon · 2017-04-13T17:26:18Z

Ah, boost::filesystem::absolute isn't readlink -f -- that'd be boost::filesystem::canonical: http://www.boost.org/doc/libs/1_51_0/libs/filesystem/doc/reference.html#absolute

tianon · 2017-04-13T17:26:39Z

(For reference, the mongod code I'm looking at is https://github.com/mongodb/mongo/blob/38c0eb538d0fd390c6cb9ce9ae9894153f6e8ef5/src/mongo/db/initialize_server_global_state.cpp#L237-L251)

tianon · 2017-04-13T17:29:20Z

Interesting:

mongodb@9c72eaed7974:/$ stat /proc/1/fd/1
  File: '/proc/1/fd/1'stat: cannot read symbolic link '/proc/1/fd/1': Permission denied

  Size: 64        	Blocks: 0          IO Block: 1024   symbolic link
Device: 24h/36d	Inode: 13038       Links: 1
Access: (0700/lrwx------)  Uid: (  999/ mongodb)   Gid: (  999/ mongodb)
Access: 2017-04-13 17:20:56.548558557 +0000
Modify: 2017-04-13 17:20:51.440497742 +0000
Change: 2017-04-13 17:20:51.440497742 +0000
 Birth: -

(same error message we're getting!)

tianon mentioned this issue Apr 13, 2017

Detect whether our logpath might work #170

Merged

yosifkit closed this as completed in #170 Apr 13, 2017

jpitchardu mentioned this issue Jun 5, 2017

SELinux is preventing chown from setattr access on the fifo_file . moby/moby#33270

Open

matu3ba mentioned this issue Jul 31, 2019

mongo 3.0.15 seems broken ds-wizard/dsw-deployment-example#2

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Pull request #161 seems to have broken MongoDB 3.4 Docker image for me #164

Pull request #161 seems to have broken MongoDB 3.4 Docker image for me #164

rberlind commented Mar 31, 2017

faustman commented Apr 3, 2017

numblr commented Apr 3, 2017 •

edited

Loading

tianon commented Apr 3, 2017

numblr commented Apr 4, 2017 •

edited

Loading

faustman commented Apr 4, 2017

elouanKeryell-Even commented Apr 11, 2017

rberlind commented Apr 11, 2017

yosifkit commented Apr 11, 2017

rberlind commented Apr 11, 2017

tianon commented Apr 11, 2017

jperville commented Apr 12, 2017 •

edited

Loading

elouanKeryell-Even commented Apr 12, 2017

tianon commented Apr 12, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017 •

edited

Loading

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

Pull request #161 seems to have broken MongoDB 3.4 Docker image for me #164

Pull request #161 seems to have broken MongoDB 3.4 Docker image for me #164

Comments

rberlind commented Mar 31, 2017

faustman commented Apr 3, 2017

numblr commented Apr 3, 2017 • edited Loading

tianon commented Apr 3, 2017

numblr commented Apr 4, 2017 • edited Loading

faustman commented Apr 4, 2017

elouanKeryell-Even commented Apr 11, 2017

rberlind commented Apr 11, 2017

yosifkit commented Apr 11, 2017

rberlind commented Apr 11, 2017

tianon commented Apr 11, 2017

jperville commented Apr 12, 2017 • edited Loading

elouanKeryell-Even commented Apr 12, 2017

tianon commented Apr 12, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017 • edited Loading

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

tianon commented Apr 13, 2017

numblr commented Apr 3, 2017 •

edited

Loading

numblr commented Apr 4, 2017 •

edited

Loading

jperville commented Apr 12, 2017 •

edited

Loading

tianon commented Apr 13, 2017 •

edited

Loading