Onwcloud Docker not starting at boot

sasa · June 18, 2018, 8:02am

Hello,

I did a server reboot and the owncloud docker does not start. I found an error message in journalctl:


Jun 18 08:52:25 server1 avahi-daemon[482]: New relevant interface vethade7071.IPv6 for mDNS.
Jun 18 08:52:25 server1 avahi-daemon[482]: Registering new address record for fe80::50de:feff:fe6a:819 on vethade7071.*.
Jun 18 08:52:25 server1 avahi-daemon[482]: Joining mDNS multicast group on interface veth95f6287.IPv6 with address fe80::80e:b3ff:fe4e:4da2.
Jun 18 08:52:25 server1 avahi-daemon[482]: New relevant interface veth95f6287.IPv6 for mDNS.
Jun 18 08:52:25 server1 avahi-daemon[482]: Registering new address record for fe80::80e:b3ff:fe4e:4da2 on veth95f6287.*.
Jun 18 08:52:26 server1 kernel: docker0: port 1(vethee670b0) entered disabled state
Jun 18 08:52:26 server1 kernel: device vethee670b0 left promiscuous mode
Jun 18 08:52:26 server1 kernel: docker0: port 1(vethee670b0) entered disabled state
Jun 18 08:52:26 server1 dockerd[1842]: time="2018-06-18T08:52:26.856048790+02:00" level=error msg="Handler for POST /v1.26/containers/3c1278c32207cb7837c35450b384f96d6ce22c13f252dd265798c58bc2765070/restart returned error: Cannot restart container 3c1278c32207cb7837c35450b384f96d6ce22c13f252dd265798c58bc2765070: oci runtime error: container_linux.go:247: starting container process caused \"process_linux.go:359: container init caused \\\"rootfs_linux.go:54: mounting \\\\\\\"/root/setup-ldap.sh\\\\\\\" to rootfs \\\\\\\"/var/lib/docker/overlay/f73c6222b183a1b58c9c52482f87a025c6ee123fc568012499b68a153c3cbb9a/merged\\\\\\\" at \\\\\\\"/var/lib/docker/overlay/f73c6222b183a1b58c9c52482f87a025c6ee123fc568012499b68a153c3cbb9a/merged/etc/owncloud.d/29-ldap.sh\\\\\\\" caused \\\\\\\"not a directory\\\\\\\"\\\"\"\n: Are you trying to mount a directory onto a file (or vice-versa)? Check if the specified host path exists and is the expected type"
Jun 18 08:52:26 server1 docker-app-owncloud[8449]: Starting owncloud Container 3c1278c32207cb7837c35450b384f96d6ce22c13f252dd265798c58bc2765070 ...Error response from daemon: Cannot restart container 3c1278c32207cb7837c35450b384f96d6ce22c13f252dd265798c58bc2765070: oci runtime error: container_linux.go:247: starting container process caused "process_linux.go:359: container init caused \"rootfs_linux.go:54: mounting \\\"/root/setup-ldap.sh\\\" to rootfs \\\"/var/lib/docker/overlay/f73c6222b183a1b58c9c52482f87a025c6ee123fc568012499b68a153c3cbb9a/merged\\\" at \\\"/var/lib/docker/overlay/f73c6222b183a1b58c9c52482f87a025c6ee123fc568012499b68a153c3cbb9a/merged/etc/owncloud.d/29-ldap.sh\\\" caused \\\"not a directory\\\"\""
Jun 18 08:52:26 server1 docker-app-owncloud[8449]: : Are you trying to mount a directory onto a file (or vice-versa)? Check if the specified host path exists and is the expected type
Jun 18 08:52:26 server1 systemd[1]: docker-app-owncloud.service: Control process exited, code=exited status=1
Jun 18 08:52:26 server1 systemd[1]: Failed to start LSB: Start the Container for owncloud.
-- Subject: Unit docker-app-owncloud.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit docker-app-owncloud.service has failed.
-- 
-- The result is failed.
Jun 18 08:52:26 server1 systemd[1]: docker-app-owncloud.service: Unit entered failed state.
Jun 18 08:52:26 server1 systemd[1]: docker-app-owncloud.service: Failed with result 'exit-code'.
Jun 18 08:52:26 server1 avahi-daemon[482]: Joining mDNS multicast group on interface vethe926316.IPv6 with address fe80::9c58:d0ff:fec0:d829.
Jun 18 08:52:26 server1 avahi-daemon[482]: New relevant interface vethe926316.IPv6 for mDNS.
Jun 18 08:52:26 server1 avahi-daemon[482]: Registering new address record for fe80::9c58:d0ff:fec0:d829 on vethe926316.*.
Jun 18 08:52:27 server1 docker-app-dudle[8450]: Starting dudle Container dd37640b8832577aec1ce95b8df6e52ab528dfa27dec38536eebcde45d24d617 ....

I made a update to 4.3.1 last week, perhaps this is the problem. I can see that the system is complaining about some pathes and I see a lot backslashes in some of the pathes (e.g.: \\\"/var/lib/docker/overlay/ ).
Unfortunately I don’t know where the path infos are taken from.

Does someone have an idea, how to fix this?

Kind regards,
sasa

Moritz_Bunkus · June 18, 2018, 8:14am

Hey,

I’ve had the same problem recently. The problem is that a directory from outside the Docker container is expected to be mounted within the Docker container in a certain place. Unfortunately there’s already a file system entry in that place, and the entry isn’t a directory, it’s a file.

Try the following:

find /var/lib/docker -type f -name 29-ldap.sh

It should yield one or more locations, something like /var/lib/docker/overlay/<long-id>/merged/etc/owncloud.d. Remove those files and try starting the container again.

It also might be the other way around: there’s a directory named 29-ldap.sh but Docker tries to bind-mount a file there. If the find above doesn’t emit anything, just leave out the -type f and try again. Just make sure to remove the existing entries. Docker should recreate them before trying to bind-mount anyway.

Kind regards,
mosu

sasa · June 18, 2018, 8:48am

Hi Moritz,

I just deleted the files as mentioned and did a reboot. I can see the owncloud service is running:

But when I try to open the website I get:

and the UCS website is telling me the same:

Do you have any idea what’s missing?

Kind regards,
sasa

Moritz_Bunkus · June 18, 2018, 8:50am

I don’t, sorry. Maybe removing the app and reinstalling it might help. Make sure to make a backup of your Owncloud files & the Owncloud database before you attempt that, though.

sasa · June 18, 2018, 10:18am

Hi,

I tried a manual start with:

docker start -a <ContainerID>

and this showed that there’s still a 29-ldap.sh folder, although I deleted it by:
sudo rm /var/lib/docker/overlay/<ContainerID>/upper/etc/owncloud.d/29-ldap.sh/ -R

here’s the output:

root@server1:~# docker start -a 3c1278c32207cb7837c35450b384f96d6ce22c13f252dd265798c58bc2765070
Creating volume folders...
Creating hook folders...
Waiting for MySQL...
wait-for-it: waiting 180 seconds for 172.17.42.1:3306
wait-for-it: 172.17.42.1:3306 is available after 0 seconds
Copying db file...
Fixing hook perms...
Fixing base perms...
Fixing data perms...
Fixing config perms...
Fixing file perms...
Fixing cert perms...
Fixing app perms...
Fixing session perms...
/usr/local/bin/owncloud: line 7: source: /etc/owncloud.d/29-ldap.sh: is a directory

EDIT:
I did some further research and found in the config file for the owncloud docker:
/var/lib/docker/containers/<ContainerID>/config.v2.json
this entry:
...,"/etc/owncl,"/etc/owncloud.d/29-ldap.sh":{"Source":"/root/setup-ldap.sh","Destination":"/etc/owncloud.d/29-ldap.sh","RW":true,"Name":"","Driver":"","Typoud.d/29-ldap.sh":{"Source...

I took a look into the source folder /root/ and there I found a folder setup-ldap.sh, which I guess should be a file rather than a folder in regards to the ending .sh?!
Is there perhaps an error on my file system or is it correct that there’s a setup-ldap.sh folder?

Maybe someone has an idea how to fix this without reinstalling.

Kind regards,
sasa

Moritz_Bunkus · June 18, 2018, 12:56pm

Hey,

Or it was that which posed the problem, yeah. Remove the folder from /root. I think the container setup tries to create a file with that name in order to set up the container’s LDAP connection, but if a directory exists with the same name creating the file will fail.

m.

sasa · June 18, 2018, 1:58pm

Hey Moritz,

I deleted both folders (root/setup-ldap.sh) and (/var/lib/docker/overlay/<ContainerID>/upper/etc/owncloud.d/29-ldap.sh/). Afterwards I tried to start owncloud docker image. I got the same error message as before and the folders were back in place. Therefore I deleted the folders again and created an empty file /root/setup-ldap.sh. I was able to start the owncloud, but I cannot login. Obviously due to the missing ldap connection…

At least this proved we are on the right direction.
Any idea what is triggering the recreation of /root/setup-ldap.sh?

kind regards,
sasa

Moritz_Bunkus · June 18, 2018, 2:03pm

Nope. I’m not one of the developers of the Owncloud app; all I have is conjecture and observations from my own tries.

Moritz_Bunkus · June 20, 2018, 8:45am

Hey,

after looking into this a bit more it seems that the process looks something like this:

During installation a preinst script is downloaded from the app center and executed on the host. This preinst script creates the file /root/setup-ldap.sh on the host. If the creation fails, the script still continues to execute (!) as it isn’t run with set -e. The only result is that later steps start failing, too.
Next the Docker image is created.
Now a join script is downloaded from the app center, too, and placed in /usr/lib/univention-install on the host.
That join script is now executed. It tries to move the file /root/setup-ldap.sh created by the preinst script to /var/lib/univention-appcenter/apps/owncloud/ on the host. If that fails, the join script fails, and an error is emitted by the app center. The app is now in a semi-installed state.
Even if everything works just fine, the Docker container is created with a bind-mount for the file /root/setup-ldap.sh on the host to /etc/owncloud.d/29-ldap.sh. This works when the container is started for the first time as that first start occurs between steps 2 and 4 — meaning at a point in time when /root/setup-ldap.sh has been created but hasn’t been moved to /var/…/owncloud/data yet. However, if you simply stop and start the container again, this will now fail with the message that /root/setup-ldap.sh doesn’t exist and can therefore not be bind-mounted into the container.

All of this looks like a big, buggy clusterfuck. You, the user, don’t even have a chance of getting the Owncloud app running properly. It may work just after installation if the installation succeeds, but it will fail as soon as you restart the container (e.g. when you want to reboot the host or if you want to update the Owncloud app).

I’ll file a bug report for this.

Kind regards,
mosu

damrose · June 20, 2018, 8:55am

I think there already is a fix for this in the next app version, which should be released soon. More reports about this are helpful.

Moritz_Bunkus · June 20, 2018, 8:56am

That’s good to hear, Erik. I’ve just filed this bug including steps how to reproduce the issue.

sasa · June 20, 2018, 11:11am

Hi Moritz,

thank you for your investigation efforts!
In the meantime I was able to uninstall and reinstall my owncloud via ssh and ucr commandline.
At the moment it is working fine and as I understood I shouldn’t reboot the host until a fix is available.

Kind regards,
sasa

sasa · July 6, 2018, 7:26am

I just installed the owncloud Update 10.0.8-20180604. After installation I did a whole server reboot and owncloud started without any errors.