OK, thanks, that confirms changing that setting is not a general solution.

Okay, problem was getting really annoying, so i'm plunging a little further in Docker domain.

 

I activated Docker Daemon debug, and now scroll through

/var/log/docker.log

after manually doing a

docker image pull ghcr.io/imagegenius/immich

in an unraid bash.

 

I see the extraction process is quite long, and when examining the log, it seems it need more than 5 minutes to finish extracting the image components. Hence the 300s timeout on docker gui / php commands not being enough I guess. Anyway, once the image is "correctly" pulled through bash without any timeout, unraid then obviously uses the already correctly pulled image through the GUI.

 

In order to know a bit more about this issue, I am trying again to do a reproductible docker image pull on a bigger (5gb) but simpler image, slightlytyler/large-image-test, that is currently ticking at 15+ mn and still extracting, hoping I would find something interesting in docker logs.

 

I'll post curated logs if anything interesting arises.

 

 

Edit : For review purpose, i launched

docker image pull slightlytyler/large-image-test

at :

time="2024-08-04T14:34:37.001528176+02:00"

 

And it just (successfully !) completed at  14:51 .

 

 

Edited August 4, 20241 yr by triskell34
Addentum

2 minutes ago, triskell34 said:

I see the extraction process is quite long, and when examining the log, it seems it need more than 5 minutes to finish extracting the image components.

That is a long time, does your docker image reside on an SSD based pool or the array?

I first moved it from an old HDD array as ISO to a SSD ZFS mirror, and then moved over to a full Directory, scrapping the ISO, on the SSD ZFS Mirror.

 

No performance improvement in any situation.

Well, it isn't as informative as i'd have liked, but i'm free to look through the logs if you think of anything interesting :

 

 

following 5f7e011 & 9320e8aff

 

time="2024-08-04T14:34:38.012257454+02:00" level=debug msg="Fetching manifest from remote" digest="sha256:16c4cd5625077aa183c4082f8ba8d146bcfd8baf14e6dac80e00e39ff1635ca8" error="<nil>" remote="docker.io/slightlytyler/large-image-test:latest"
time="2024-08-04T14:34:38.363291468+02:00" level=debug msg="Pulling ref from V2 registry: slightlytyler/large-image-test:latest"
time="2024-08-04T14:34:38.363454863+02:00" level=debug msg="pulling blob \"sha256:4fe2ade4980c2dda4fc95858ebb981489baec8c1e4bd282ab1c3560be8ff9bde\""
time="2024-08-04T14:34:38.363463109+02:00" level=debug msg="pulling blob \"sha256:108906d36b1d979ea5cd32cbf7f5d57ffe0c9ac0e098cc0462b2373e1aa4b2bc\""


time="2024-08-04T14:34:38.871739305+02:00" level=debug msg="Downloaded 4fe2ade4980c to tempfile /var/lib/docker/tmp/GetImageBlob3540964868"
time="2024-08-04T14:34:38.871835004+02:00" level=debug msg="unpigz binary not found, falling back to go gzip library"
time="2024-08-04T14:34:38.871891146+02:00" level=debug msg="[zfs] ID:fe21fcfc-7bed-4604-b54f-1c1992287d88 START /usr/sbin/zfs create -o mountpoint=legacy nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4" storage-driver=zfs

time="2024-08-04T14:34:45.298975099+02:00" level=debug msg="[zfs] ID:bd9ca438-05dc-469d-ba4e-2408b8f83ebc START /usr/sbin/zfs list -Hp -o name,origin,used,available,mountpoint,compression,type,volsize,quota,referenced,written,logicalused,usedbydataset nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4" storage-driver=zfs
time="2024-08-04T14:34:45.304228144+02:00" level=debug msg="[zfs] ID:bd9ca438-05dc-469d-ba4e-2408b8f83ebc FINISH" storage-driver=zfs
time="2024-08-04T14:34:45.304460850+02:00" level=debug msg="mount(\"nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4\", \"/var/lib/docker/zfs/graph/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4\", \"\")" storage-driver=zfs
time="2024-08-04T14:34:45.307260548+02:00" level=debug msg="Start untar layer" id=5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4
  
time="2024-08-04T14:34:45.402526149+02:00" level=debug msg="Untar time: 0.095264762s" id=5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4
time="2024-08-04T14:34:45.402547513+02:00" level=debug msg="unmount(\"/var/lib/docker/zfs/graph/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4\")" storage-driver=zfs  
  
  
time="2024-08-04T14:38:19.595225023+02:00" level=debug msg="Applied tar sha256:df64d3292fd6194b7865d7326af5255db6d81e9df29f48adde61a918fbd8c332 to 5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4, size: 4408974"  
  
time="2024-08-04T14:38:29.737543284+02:00" level=debug msg="Downloaded 108906d36b1d to tempfile /var/lib/docker/tmp/GetImageBlob1322585465"
time="2024-08-04T14:38:30.285166304+02:00" level=debug msg="unpigz binary not found, falling back to go gzip library"
time="2024-08-04T14:38:30.285218863+02:00" level=debug msg="[zfs] ID:437cfc7c-cac8-4288-aa82-40195d0a6e00 START /usr/sbin/zfs snapshot nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4@285199159" storage-driver=zfs

time="2024-08-04T14:43:24.704424846+02:00" level=debug msg="[zfs] ID:437cfc7c-cac8-4288-aa82-40195d0a6e00 FINISH" storage-driver=zfs
time="2024-08-04T14:43:24.704466298+02:00" level=debug msg="[zfs] ID:635d558f-b532-4bc8-a422-8db338b00763 START /usr/sbin/zfs list -Hp -o name,origin,used,available,mountpoint,compression,type,volsize,quota,referenced,written,logicalused,usedbydataset nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4@285199159" storage-driver=zfs
time="2024-08-04T14:43:24.709830531+02:00" level=debug msg="[zfs] ID:635d558f-b532-4bc8-a422-8db338b00763 FINISH" storage-driver=zfs
time="2024-08-04T14:43:24.709874950+02:00" level=debug msg="[zfs] ID:544a3059-3445-40ae-bdd9-bc8d9fdaff1a START /usr/sbin/zfs clone -p -o mountpoint=legacy nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4@285199159 nvmecache/system/9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715" storage-driver=zfs  
  
time="2024-08-04T14:43:28.855926205+02:00" level=debug msg="[zfs] ID:544a3059-3445-40ae-bdd9-bc8d9fdaff1a FINISH" storage-driver=zfs
time="2024-08-04T14:43:28.855964763+02:00" level=debug msg="[zfs] ID:7fb4e543-4379-4be0-aefe-a6ec91bea830 START /usr/sbin/zfs list -Hp -o name,origin,used,available,mountpoint,compression,type,volsize,quota,referenced,written,logicalused,usedbydataset nvmecache/system/9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715" storage-driver=zfs
time="2024-08-04T14:43:28.861321585+02:00" level=debug msg="[zfs] ID:7fb4e543-4379-4be0-aefe-a6ec91bea830 FINISH" storage-driver=zfs
time="2024-08-04T14:43:28.861355250+02:00" level=debug msg="[zfs] ID:0b358449-4da2-4d38-b277-e0509fc6bf8f START /usr/sbin/zfs destroy -d nvmecache/system/5f7e011ea2378c5199460f075912561daaaf6d56e3f3ecca649eb997913766d4@285199159" storage-driver=zfs
time="2024-08-04T14:43:29.542925040+02:00" level=debug msg="[zfs] ID:0b358449-4da2-4d38-b277-e0509fc6bf8f FINISH" storage-driver=zfs
time="2024-08-04T14:43:29.543178856+02:00" level=debug msg="mount(\"nvmecache/system/9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715\", \"/var/lib/docker/zfs/graph/9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715\", \"\")" storage-driver=zfs
time="2024-08-04T14:43:29.548556200+02:00" level=debug msg="Start untar layer" id=9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715
  

time="2024-08-04T14:45:20.260217928+02:00" level=debug msg="Untar time: 110.711660022s" id=9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715
time="2024-08-04T14:45:20.260244739+02:00" level=debug msg="unmount(\"/var/lib/docker/zfs/graph/9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715\")" storage-driver=zfs  
  
time="2024-08-04T14:51:44.489953855+02:00" level=debug msg="Applied tar sha256:85bc43fa95f1401eb66eb810c47b866a84c5e361f52f399ec4554e2c9efcc04a to 9320e8aff28292c0452d113c937c5939eb10a2d3b99ce7d1d0cf1a9045aa1715, size: 5120000000"


time="2024-08-04T14:51:44.692815607+02:00" level=debug msg="Adding content digest to lease" digest="sha256:16c4cd5625077aa183c4082f8ba8d146bcfd8baf14e6dac80e00e39ff1635ca8" lease="moby-image-sha256:39be0df3f2c748ab7be6e4d3ed7c8c7a0184a548ce1839268ced3d5f582d4c4d" remote="docker.io/slightlytyler/large-image-test:latest"

 

 

Adding an unraid diag as well in case.

unraid-804-diagnostics-20240804-1501.zip

Edited August 4, 20241 yr by triskell34
Edit : Added more log lines

Another thing I notice during these issues.

 

When my Unraid instance waits for a Pull to finish, all the Dockers seems to hang / pause (I serve the Unraid UI through a Nginx reverse proxy in the Docker instance)

 

But if I access the Unraid UI through it's direct IP and no longer the Docker NPM, it's responsive.

 

So, during a pending docker deployment that necessitates a Pull of a fresh image I ran

 

ps auxw | grep docker

 

Both ~1mn after beginning the deployment of the new docker image, as well as ~4mn after the beginning of the deployment (It needed more than that to deploy successfully, didn't check)

 

root@UNRAID-804:~# ps auxw | grep docker
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root       748  0.0  0.0   4052  2148 pts/0    S+   14:17   0:00 grep docker
root      1662  0.0  0.0 722964 21440 ?        Sl   Aug04   0:04 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 85472eddaaafc32dc0d861f6e78e1e81965402b8cb0029865dc3741c7d158223 -address /var/run/docker/containerd/containerd.sock
root      2262  0.0  0.0 722964 21020 ?        Sl   Aug04   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id d1a0a45af36d140c398428e70b0a9eb72d5feabbfcc76770a587e9437c21a286 -address /var/run/docker/containerd/containerd.sock
root      6157  0.2  0.2 2941176 108372 ?      Sl   Jul30  21:13 /usr/bin/dockerd -p /var/run/dockerd.pid --log-opt max-size=50m --log-opt max-file=1 --log-level=fatal --storage-driver=zfs
root      6172  0.0  0.1 753356 56624 ?        Ssl  Jul30   3:37 containerd --config /var/run/docker/containerd/containerd.toml --log-level fatal
root     23824  0.0  0.0 722964 21192 ?        Sl   03:45   0:02 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 0fd6f7bf2869f47de42fcf83e696d8447db02cb46d701dbc2974048680cc09cc -address /var/run/docker/containerd/containerd.sock
root     24043  0.0  0.0 723220 20820 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 1653757449f77486eedb48fa3696a1dad439a38adc37e8a4091b9f83bdea5942 -address /var/run/docker/containerd/containerd.sock
root     24877  0.0  0.0 722964 20768 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id e50fc4affb82cdcbe1c90bf4fe1701928aad3532fb48af0a71f856143320462c -address /var/run/docker/containerd/containerd.sock
root     25075  0.0  0.0 710824  9884 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7901 -container-ip 172.18.0.15 -container-port 5900
root     25083  0.0  0.0 710824  9848 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7901 -container-ip 172.18.0.15 -container-port 5900
root     25097  0.0  0.0 711080  7864 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7801 -container-ip 172.18.0.15 -container-port 5800
root     25104  0.0  0.0 710824  9908 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7801 -container-ip 172.18.0.15 -container-port 5800
root     25122  0.0  0.0 722964 21240 ?        Sl   Aug04   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 50a3ad5871a764d3f0ed267a3757d7d708bf9fd028b654e6df09b236868623b4 -address /var/run/docker/containerd/containerd.sock
root     25633  0.0  0.0 723220 20136 ?        Sl   03:45   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 030783ddeed7c0496355a6f6c53befb41fafddf591a5d8f0feb2f947976f1d9b -address /var/run/docker/containerd/containerd.sock
root     26774  0.0  0.0 722964 17304 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 7b74d9ccfce438b92a7c1734536ac8111818794d98f56e0799dd1d95b9dee2ef -address /var/run/docker/containerd/containerd.sock
root     27396  0.0  0.0 710824  9848 ?        Sl   03:45   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8792 -container-ip 172.18.0.16 -container-port 80
root     27405  0.0  0.0 710824  9916 ?        Sl   03:45   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8792 -container-ip 172.18.0.16 -container-port 80
root     27424  0.0  0.0 722964 18896 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id fd08bdb4ab3e10aaf2ffdeb2fb32b425a6e10039f73ae33807abc89f2a0141dd -address /var/run/docker/containerd/containerd.sock
root     27757  0.0  0.0 722964 20536 ?        Sl   03:45   0:02 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 56aae4eb74408c89e37501e7698151cc301c1f98f963b0af02d4507096ded45e -address /var/run/docker/containerd/containerd.sock
root     28279  0.0  0.0 723220 16980 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 5d8de47351a07931ca0b1748108956c07c7e9cb444f654353e24971db5d40a1f -address /var/run/docker/containerd/containerd.sock
root     28568  0.0  0.0 723220 19504 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 8365a73015cda816f7ccaeb7bb88050a82456e0223e532b88aa2b9afb1fe8e0b -address /var/run/docker/containerd/containerd.sock
root     29771  0.0  0.0 722964 18772 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id a0ba9b274de9c59d63f44ecf19043f87098de46d567d0cf06bbfe1bcb3660749 -address /var/run/docker/containerd/containerd.sock
root     30414  0.0  0.0 710824  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8101 -container-ip 172.18.0.9 -container-port 81
root     30420  0.0  0.0 710824  7864 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8101 -container-ip 172.18.0.9 -container-port 81
root     30432  0.0  0.0 710824  9888 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 443 -container-ip 172.18.0.9 -container-port 443
root     30441  0.0  0.0 711080  7864 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 443 -container-ip 172.18.0.9 -container-port 443
root     30454  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 80 -container-ip 172.18.0.9 -container-port 80
root     30461  0.0  0.0 711080  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 80 -container-ip 172.18.0.9 -container-port 80
root     30477  0.0  0.0 722964 18200 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id f83973c71e4a51444e3b597f1899e5545a7eb881e8a40f1bf1e9fe78f3fc6540 -address /var/run/docker/containerd/containerd.sock
root     31038  0.0  0.0 722964 19540 ?        Sl   03:46   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id fa6985a7d944f04fab0dfab5324cec159676dc7aacd2baf49953d24514390388 -address /var/run/docker/containerd/containerd.sock
root     31349  0.0  0.0 710568  7884 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8081 -container-ip 172.18.0.8 -container-port 8080
root     31356  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8081 -container-ip 172.18.0.8 -container-port 8080
root     31368  0.0  0.0 710824  7836 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7422 -container-ip 172.18.0.8 -container-port 7422
root     31375  0.0  0.0 710824  9892 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7422 -container-ip 172.18.0.8 -container-port 7422
root     31388  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 6060 -container-ip 172.18.0.8 -container-port 6060
root     31395  0.0  0.0 711080  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 6060 -container-ip 172.18.0.8 -container-port 6060
root     31413  0.0  0.0 722964 20216 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 81a0e2a0caa0346f55bd2b3fd824826ba509b0ddc0edd551842c20a90af41066 -address /var/run/docker/containerd/containerd.sock


root@UNRAID-804:~# ps auxw | grep docker
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root      1662  0.0  0.0 722964 21376 ?        Sl   Aug04   0:04 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 85472eddaaafc32dc0d861f6e78e1e81965402b8cb0029865dc3741c7d158223 -address /var/run/docker/containerd/containerd.sock
root      2262  0.0  0.0 722964 21084 ?        Sl   Aug04   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id d1a0a45af36d140c398428e70b0a9eb72d5feabbfcc76770a587e9437c21a286 -address /var/run/docker/containerd/containerd.sock
root      6157  0.2  0.2 2941176 106256 ?      Sl   Jul30  21:17 /usr/bin/dockerd -p /var/run/dockerd.pid --log-opt max-size=50m --log-opt max-file=1 --log-level=fatal --storage-driver=zfs
root      6172  0.0  0.1 753356 51332 ?        Ssl  Jul30   3:37 containerd --config /var/run/docker/containerd/containerd.toml --log-level fatal
root     10411  0.0  0.0 711080  3804 ?        Sl   14:19   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8484 -container-ip 172.17.0.2 -container-port 8484
root     10418  0.0  0.0 710824  3800 ?        Sl   14:19   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8484 -container-ip 172.17.0.2 -container-port 8484
root     10438  0.0  0.0 722708 12124 ?        Sl   14:19   0:00 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 34ff96249ae47c9183345bd70af8ce6139403cf2e4000adbf4c50d81a5e00bfd -address /var/run/docker/containerd/containerd.sock
root     12109  0.0  0.0   4052  2288 pts/0    S+   14:20   0:00 grep docker
root     23824  0.0  0.0 722964 21248 ?        Sl   03:45   0:02 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 0fd6f7bf2869f47de42fcf83e696d8447db02cb46d701dbc2974048680cc09cc -address /var/run/docker/containerd/containerd.sock
root     24043  0.0  0.0 723220 20820 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 1653757449f77486eedb48fa3696a1dad439a38adc37e8a4091b9f83bdea5942 -address /var/run/docker/containerd/containerd.sock
root     24877  0.0  0.0 722964 20768 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id e50fc4affb82cdcbe1c90bf4fe1701928aad3532fb48af0a71f856143320462c -address /var/run/docker/containerd/containerd.sock
root     25075  0.0  0.0 710824  9884 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7901 -container-ip 172.18.0.15 -container-port 5900
root     25083  0.0  0.0 710824  9848 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7901 -container-ip 172.18.0.15 -container-port 5900
root     25097  0.0  0.0 711080  7864 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7801 -container-ip 172.18.0.15 -container-port 5800
root     25104  0.0  0.0 710824  9908 ?        Sl   Aug04   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7801 -container-ip 172.18.0.15 -container-port 5800
root     25122  0.0  0.0 722964 21272 ?        Sl   Aug04   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 50a3ad5871a764d3f0ed267a3757d7d708bf9fd028b654e6df09b236868623b4 -address /var/run/docker/containerd/containerd.sock
root     25633  0.0  0.0 723220 20364 ?        Sl   03:45   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 030783ddeed7c0496355a6f6c53befb41fafddf591a5d8f0feb2f947976f1d9b -address /var/run/docker/containerd/containerd.sock
root     26774  0.0  0.0 722964 17304 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 7b74d9ccfce438b92a7c1734536ac8111818794d98f56e0799dd1d95b9dee2ef -address /var/run/docker/containerd/containerd.sock
root     27396  0.0  0.0 710824  9848 ?        Sl   03:45   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8792 -container-ip 172.18.0.16 -container-port 80
root     27405  0.0  0.0 710824  9916 ?        Sl   03:45   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8792 -container-ip 172.18.0.16 -container-port 80
root     27424  0.0  0.0 722964 18928 ?        Sl   03:45   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id fd08bdb4ab3e10aaf2ffdeb2fb32b425a6e10039f73ae33807abc89f2a0141dd -address /var/run/docker/containerd/containerd.sock
root     27757  0.0  0.0 722964 20496 ?        Sl   03:45   0:02 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 56aae4eb74408c89e37501e7698151cc301c1f98f963b0af02d4507096ded45e -address /var/run/docker/containerd/containerd.sock
root     28279  0.0  0.0 723220 16980 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 5d8de47351a07931ca0b1748108956c07c7e9cb444f654353e24971db5d40a1f -address /var/run/docker/containerd/containerd.sock
root     28568  0.0  0.0 723220 19568 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 8365a73015cda816f7ccaeb7bb88050a82456e0223e532b88aa2b9afb1fe8e0b -address /var/run/docker/containerd/containerd.sock
root     29771  0.0  0.0 722964 18772 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id a0ba9b274de9c59d63f44ecf19043f87098de46d567d0cf06bbfe1bcb3660749 -address /var/run/docker/containerd/containerd.sock
root     30414  0.0  0.0 710824  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8101 -container-ip 172.18.0.9 -container-port 81
root     30420  0.0  0.0 710824  7864 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8101 -container-ip 172.18.0.9 -container-port 81
root     30432  0.0  0.0 710824  9888 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 443 -container-ip 172.18.0.9 -container-port 443
root     30441  0.0  0.0 711080  7864 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 443 -container-ip 172.18.0.9 -container-port 443
root     30454  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 80 -container-ip 172.18.0.9 -container-port 80
root     30461  0.0  0.0 711080  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 80 -container-ip 172.18.0.9 -container-port 80
root     30477  0.0  0.0 722964 18232 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id f83973c71e4a51444e3b597f1899e5545a7eb881e8a40f1bf1e9fe78f3fc6540 -address /var/run/docker/containerd/containerd.sock
root     31038  0.0  0.0 722964 19636 ?        Sl   03:46   0:03 /usr/bin/containerd-shim-runc-v2 -namespace moby -id fa6985a7d944f04fab0dfab5324cec159676dc7aacd2baf49953d24514390388 -address /var/run/docker/containerd/containerd.sock
root     31349  0.0  0.0 710568  7884 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 8081 -container-ip 172.18.0.8 -container-port 8080
root     31356  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 8081 -container-ip 172.18.0.8 -container-port 8080
root     31368  0.0  0.0 710824  7836 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 7422 -container-ip 172.18.0.8 -container-port 7422
root     31375  0.0  0.0 710824  9892 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 7422 -container-ip 172.18.0.8 -container-port 7422
root     31388  0.0  0.0 710824  7868 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip 0.0.0.0 -host-port 6060 -container-ip 172.18.0.8 -container-port 6060
root     31395  0.0  0.0 711080  9900 ?        Sl   03:46   0:00 /usr/bin/docker-proxy -proto tcp -host-ip :: -host-port 6060 -container-ip 172.18.0.8 -container-port 6060
root     31413  0.0  0.0 722964 20216 ?        Sl   03:46   0:01 /usr/bin/containerd-shim-runc-v2 -namespace moby -id 81a0e2a0caa0346f55bd2b3fd824826ba509b0ddc0edd551842c20a90af41066 -address /var/run/docker/containerd/containerd.sock

 

Doesn't seem to be so busy...

 

Edited August 5, 20241 yr by triskell34

Just a fyi -

I tried to update immich today with only the time out set to 300 (did not use the init flag and it also failed for me.

Looks as thou the larger img pull did not complete

Hey there,

 

Not going to help the inherent problem, but if you have the same problem than I do, and experience an excruciating slow docker pull, you may run the pull command from an Unraid shell, that will not timeout according to Unraid Docker timeout value.

 

I needed 5+ mins to pull the immich image a couple days ago.

 

For me (check the exact image you use!) that'd be :

 

Unraid bash +

docker image pull ghcr.io/imagegenius/immich

 

... wait

 

Then safely clic "Update" on the Docker unraid GUI, the image being already present, she'll get used in a snap.

 

Actually, I noticed there is a new immich update, I am doing it right now.

Edited August 8, 20241 yr by triskell34
Edit : Changed duration above, immich needed 5+ minuts, it was another huge image that needed 15+ minuts.

Hey - thanks for the tip.  I tried it and it did work.

Very strange how it hangs at certain points (above and below) for an extended period

but it does complete and then can update from GUI

 

 

I tired running pull from CLI on paperless-ngx, which I was also having problems updating and it worked here also

Again, it took an extended period, but it did work

Thanks for the updates guys, still looking into it, so a manual pull appears to always work, right? Even if it takes an extreme amount to do it? And for this last posts the docker image/folder resides on an SSD pool, correct?

Hello JorgeB, that is correct on all topics for myself.

 

I actually did some more tests on my side, that were sadly not fruitful, but may allow some more insight on the problem.

 

• Disabled Docker Engine, then used a fresh BTRFS ISO on ZFS SSD pool : Exact same symptoms (sometimes VERY slow docker pulls)
• Moved the above BTRFS ISO on the "classic" Unraid HDD Array (2x 4tb + 2x 4tb parity, new disks, no issues unlike previous spinners on the unraid server) : Exact same symptoms (sometimes VERY slow docker pulls)

I was suspecting ZFS issues with long snapshotting during the image pull processes, but the exact same problem on a non ZFS array invalidates this idea.

 

I also tested my SSD's with Diskspeed app, I get a constant 350Mb/s bandwidth, tested the array as well, 100 or 130Mb bandwidth, can't remember.

 

At last, I also plugged the SSD's directly on the motherboard's SATA ports instead of my SAS controller, still exact same issues.

 

Ah yes, there might be something I begin to see :

 

When I was on a Docker directory (and not an ISO), and while there was a slow pull running, I think I remember the Unraid Web UI was still responsive, I could browse it without any issue. Still, any Docker container was practically halted until the pull was complete.

 

Now that I am back on a BTRFS Docker ISO, it seems the whole Unraid UI (not just docker containers) is systematically unresponsive when this slow docker pull is pending.

 

Take this specific point with a grain of salt, I still have to confirm it's systematic, but it might be symptomatic of a specific process, who knows.

Edited August 10, 20241 yr by triskell34

CLI pull does seem to work for me also.

Cache is on SSD on zfs mirror

 

I did notice something unusual,  This was under ZFS Master tab.  There are approximately 170 entries like this

Are these the orphaned images?

(I am not as technically savvy as the two of you)

 

On 8/10/2024 at 4:00 PM, uglytuna said:

Are these the orphaned images?

This is normal if you are using a docker directory on zfs storage.

Just wanted to update -

Anytime I have a container that fails to update "normally", I just run the docker pull command and it works.  May take a while, but it works so far every time.

Please try this after an update using the GUI fails, edit /usr/local/emhttp/plugins/dynamix.docker.manager/include/DockerClient.php and look for the entries below, they are in the fist page:

curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, 15);
curl_setopt($ch, CURLOPT_TIMEOUT, 45);

 

Add a zero the each value, i.e.:

curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, 150);
curl_setopt($ch, CURLOPT_TIMEOUT, 450);

 

Save the file and please retry the update using the GUI.

Hey there JorgeB

 

I did apply the above settings to DockerClient.php after a failed batch of updates, but so far images still seem to fail to pull successfully, doesn't seem to grant successful results

 

By the way, unless dynamix docker manager has inference with native docker commands, as said above - I feel with 'docker image pull whatever' + 'docker image rm whatever'  commands sometimes fast extractions, and sometimes, docker as a whole comes to a litteral crawl - a decompression / check stage that would have taken 2 seconds on a previous trial then takes sometimes minutes.

 

And again, docker as a whole seems to come to a crawl, until (it seems) the pull process comes to a stop as a whole for a couple minuts, then there is the possibility another docker pull could get fast.

 

2 hours ago, triskell34 said:

I did apply the above settings to DockerClient.php after a failed batch of updates, but so far images still seem to fail to pull successfully, doesn't seem to grant successful results

Thanks, if I understand correctly it's the same exact behavior as before, or were there any changes despite still failing?

 

Also please post a set of diags just after a failed updated like the one above.

Yep, still the same behaviour

 

I did put the values back to default after the unsuccessful try, now just reverted values back in the PHP file to x10, running (trying!) to run a batch of updates, i'll post the diag once the updates fail, currently pending.

 

Edited August 15, 20241 yr by triskell34

Here is the diag, just after an unsuccessful upgrade through the GUI, with values set as you recomended :

 

		curl_setopt($ch, CURLOPT_URL, $url);
		curl_setopt($ch, CURLOPT_FRESH_CONNECT, true);
		curl_setopt($ch, CURLOPT_RETURNTRANSFER, true);
		curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, 150);
		curl_setopt($ch, CURLOPT_TIMEOUT, 450);
		curl_setopt($ch, CURLOPT_ENCODING, "");
		curl_setopt($ch, CURLOPT_FOLLOWLOCATION, true);
		curl_setopt($ch, CURLOPT_REFERER, "");
		curl_setopt($ch, CURLOPT_FAILONERROR, true);

 

unraid-804-diagnostics-20240815-1137.zip

Thanks, don't see anything relevant logged, even in the docker log, can you post the actual container log? Should be under the container ID, see here:

https://forums.unraid.net/topic/60699-where-are-docker-logs-stored-by-default/?do=findComment&comment=595757

 

Well, nothing really interesting since the docker log starts when the container itself starts, and it starts nicely, excepted it's on the "old" undecomissionned image

 

Homeassistant for instance

 

 

I will re activate docker daemon debug logs, run the upgrade test through GUI and post curated log here.

Okay, so...

 

I activated the docker daemon debug again, and ran :

 

- A tentative to update 3 pending dockers through the GUI, while running a tail -f docker.log on a screen, and captured the process with a timewatch besides the GUI,

- As the update didn't stick, I ran a docker image pull of 1 of the 3 images that didn't run, waited... and then updated the container through the GUI,

All this while screen filming the whole process

 

@JorgeB , if you don't mind, I will send you a private video link to a drive, as there are potentially private datas (IP, adresses, whatever...) that I wouldn't really like to fly around unwatched.

 

Here is the SYSLOG of the video times, again you can directly correlate with the time displayed in the video :

 

Aug 15 13:42:34 UNRAID-804 emhttpd: read SMART /dev/sdb
Aug 15 13:47:07 UNRAID-804 kernel: veth4c14b52: renamed from eth0
Aug 15 13:47:07 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(vethe686811) entered disabled state
Aug 15 13:47:07 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(vethe686811) entered disabled state
Aug 15 13:47:07 UNRAID-804 kernel: device vethe686811 left promiscuous mode
Aug 15 13:47:07 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(vethe686811) entered disabled state
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered blocking state
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered disabled state
Aug 15 13:47:08 UNRAID-804 kernel: device veth1fed7be entered promiscuous mode
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered blocking state
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered forwarding state
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered disabled state
Aug 15 13:47:08 UNRAID-804 kernel: eth0: renamed from veth9ad67be
Aug 15 13:47:08 UNRAID-804 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth1fed7be: link becomes ready
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered blocking state
Aug 15 13:47:08 UNRAID-804 kernel: br-bd1e88d5e61d: port 17(veth1fed7be) entered forwarding state
Aug 15 13:48:41 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth3b40833) entered disabled state
Aug 15 13:48:41 UNRAID-804 kernel: veth2c39390: renamed from eth0
Aug 15 13:48:41 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth3b40833) entered disabled state
Aug 15 13:48:41 UNRAID-804 kernel: device veth3b40833 left promiscuous mode
Aug 15 13:48:41 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth3b40833) entered disabled state
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered blocking state
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered disabled state
Aug 15 13:48:43 UNRAID-804 kernel: device veth0cd9917 entered promiscuous mode
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered blocking state
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered forwarding state
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered disabled state
Aug 15 13:48:43 UNRAID-804 kernel: eth0: renamed from veth159702b
Aug 15 13:48:43 UNRAID-804 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth0cd9917: link becomes ready
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered blocking state
Aug 15 13:48:43 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered forwarding state
Aug 15 13:51:03 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(veth715172f) entered disabled state
Aug 15 13:51:03 UNRAID-804 kernel: veth0732680: renamed from eth0
Aug 15 13:51:03 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(veth715172f) entered disabled state
Aug 15 13:51:03 UNRAID-804 kernel: device veth715172f left promiscuous mode
Aug 15 13:51:03 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(veth715172f) entered disabled state
Aug 15 13:51:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(vetha8ac421) entered blocking state
Aug 15 13:51:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(vetha8ac421) entered disabled state
Aug 15 13:51:04 UNRAID-804 kernel: device vetha8ac421 entered promiscuous mode
Aug 15 13:51:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(vetha8ac421) entered blocking state
Aug 15 13:51:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 19(vetha8ac421) entered forwarding state
Aug 15 13:51:04 UNRAID-804 kernel: eth0: renamed from vethdfb4065
Aug 15 13:51:04 UNRAID-804 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): vetha8ac421: link becomes ready
Aug 15 13:57:56 UNRAID-804 kernel: veth159702b: renamed from eth0
Aug 15 13:57:56 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered disabled state
Aug 15 13:57:57 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered disabled state
Aug 15 13:57:57 UNRAID-804 kernel: device veth0cd9917 left promiscuous mode
Aug 15 13:57:57 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(veth0cd9917) entered disabled state
Aug 15 13:58:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered blocking state
Aug 15 13:58:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered disabled state
Aug 15 13:58:04 UNRAID-804 kernel: device vethebc9e0a entered promiscuous mode
Aug 15 13:58:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered blocking state
Aug 15 13:58:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered forwarding state
Aug 15 13:58:04 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered disabled state
Aug 15 13:58:09 UNRAID-804 kernel: eth0: renamed from vethf398245
Aug 15 13:58:09 UNRAID-804 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): vethebc9e0a: link becomes ready
Aug 15 13:58:09 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered blocking state
Aug 15 13:58:09 UNRAID-804 kernel: br-bd1e88d5e61d: port 18(vethebc9e0a) entered forwarding state

 

Docker daemon log also contains variables I wouldn't like to make public, but I guess video content should be plentiful to explore.

 

Some timestamps... :

 

6:30 : Finished manual GUI update tentative

7:20 : docker image pull of a previously unsuccessful update

10:09 : First "big" missing layer successfully downloaded extracted etc

12:48 : Second missing layer successful & end of image pull

13:00 : "Update" container (to latest image) through GUI

 

As stated above, I'm sending you this video through PM in a couple seconds

 

 

 

Thanks, I'll take a look to see if I can see something there.

Tried to updated Immich today.  Both times, with and w/o x10 in php file, failed to update

Have included diagnostic file just in case

untower-diagnostics-20240815-0947.zip