Hello Eric,
Am 03.10.2017 um 18:48 schrieb Eric W. Biederman:
> ebiederm@xxxxxxxxxxxx (Eric W. Biederman) writes:
>
>> Philipp Hahn <hahn@xxxxxxxxxxxxx> writes:
>>
>>> We will try 4.9.52 next and see, if we can still reproduce it.
>
> Can you still reproduce this on 4.9.52?
My college Dirk is able to reproduce it only with .33, but not with .52
(yet).
> I am not seeing anything obvious that would result in last_source
> becomming NULL there so knowing I am not lookning for a phantom would be very
> helpful.
Looks like .52 closed the race windows sufficiently enough, so the bug
does not get triggered there.
The bug is triggered when using "docker cp" to copy a file into the
container. It communicates with the long-running 'dockerd', which
rebuilds the overlay FS itself to access the file. The failing syscall is:
> mount("/fw/data_folder", "/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/fwxserver/Data Folder", 0xc82135e5c8, MS_BIND|MS_REC, NULL
I just now noticed that before the mount() docker did this:
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/media", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/tmp", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/etc", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/log", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/var/lib/univention-appcenter/apps/filewave/data", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/var/lib/univention-appcenter/apps/filewave/conf", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/certs", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/fwcld", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/fwxserver/Data Folder", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/apache/conf", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/fwxserver/DB", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/apache/logs", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/private/var/log", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/apache/passwords", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/sys/fs/cgroup", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/ipa", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/etc/apt/apt.conf.d/80proxy", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/usr/local/filewave/postgresql/conf", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/etc/resolv.conf", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/etc/hostname", MNT_DETACH) = 0
> umount("/var/lib/docker/overlay/038e54bc5db6a180409aa0e5b0f84087b93ac7ffe4eaa3c8908aea79d43a45d3/merged/etc/hosts", MNT_DETACH) = 0
Is MNT_DETACH a problem, as it is described to do a "lazy" umount? Doing
another
> strace -ttt -b execve -f -ff -s 65536 -o /var/tmp/docker.strace -p $(</run/docker.pid)
shows the mount() following the umounts() < 0.2s, so maybe that's the
missing detail.
If you need more data, just ask Dirk: he's able to re-produce the bug
every time.
If you need more data from the kernel, I can build a customized kernel
with more debug output if that helps.
Philipp
