boredazfcuk / docker-icloudpd

An Alpine Linux container for the iCloud Photos Downloader command line utility
1.64k stars 156 forks source link

Logs showing: ERROR IOError while writing file #108

Closed mikeyvt closed 2 years ago

mikeyvt commented 2 years ago

Hello. Just installed the container. First thanks for creating it. Awesome. The container is running right now and at first I didn't see any issues pop up in the log. Now it seems I am getting quite a bit of red errors with issue of it not being able to download an image. The process hasn't finished so I can't tell you what it says at the end yet. Any ideas?

2021-10-12 14:33:29 INFO Downloading /home/user/iCloud/2021/10/05/IMG_3307.PNG 2021-10-12 14:33:29 INFO Downloading /home/user/iCloud/2021/10/05/IMG_3306.PNG 2021-10-12 14:33:30 ERROR IOError while writing file to /home/user/iCloud/2021/10/05/IMG_3306.PNG! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

2021-10-12 14:33:30 INFO Downloading /home/user/iCloud/2021/10/05/IMG_3305.HEIC 2021-10-12 14:33:30 ERROR IOError while writing file to /home/user/iCloud/2021/10/05/IMG_3305.HEIC! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

2021-10-12 14:33:30 INFO Downloading /home/user/iCloud/2021/10/04/IMG_3303.JPG 2021-10-12 14:33:31 ERROR IOError while writing file to /home/user/iCloud/2021/10/04/IMG_3303.JPG! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

2021-10-12 14:33:31 INFO Downloading /home/user/iCloud/2021/10/04/IMG_3289.JPG 2021-10-12 14:33:31 INFO Downloading /home/user/iCloud/2021/10/03/IMG_3287.HEIC 2021-10-12 14:33:31 ERROR IOError while writing file to /home/user/iCloud/2021/10/04/IMG_3303.JPG! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

2021-10-12 14:33:31 INFO Downloading /home/user/iCloud/2021/10/04/IMG_3289.JPG 2021-10-12 14:33:31 INFO Downloading /home/user/iCloud/2021/10/03/IMG_3287.HEIC 2021-10-12 14:33:32 INFO Downloading /home/user/iCloud/2021/10/03/IMG_3286.HEIC 2021-10-12 14:33:32 INFO Downloading /home/user/iCloud/2021/10/02/IMG_3284.MOV 2021-10-12 14:33:35 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3273.MOV 2021-10-12 14:33:37 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3272.MOV 2021-10-12 14:33:41 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3271.MOV 2021-10-12 14:33:43 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3269.JPG 2021-10-12 14:33:44 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3267.PNG 2021-10-12 14:33:44 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3266.JPG 2021-10-12 14:33:44 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3267.PNG 2021-10-12 14:33:44 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3266.JPG 2021-10-12 14:33:44 ERROR IOError while writing file to /home/user/iCloud/2021/09/30/IMG_3266.JPG! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

2021-10-12 14:33:44 INFO Downloading /home/user/iCloud/2021/09/30/IMG_3265.JPG 2021-10-12 14:33:44 ERROR IOError while writing file to /home/user/iCloud/2021/09/30/IMG_3265.JPG! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...

mikeyvt commented 2 years ago

Here's a screenshot of the log.

image

FadingArabChristians commented 2 years ago

Same here.

image

boredazfcuk commented 2 years ago

Hi, sorry for not getting back sooner. Been a bit busy this week.

The only time I've seen this error was when I filled my drive up... That's why I created the fail-safe feature using the .mounted file, the drive mount had failed and I'd filled my root partition... whoops! lol

Another way of filling up the drive could be down to Docker... By default, Docker installs to /var/lib/docker and creates the persistent volumes in /var/lib/docker/volumes. If you have created your system with separate partitions for var, tmp, home etc, then the /var partition may be quite small. On my Debian 10 box, it's only 6.8GB and half full, just from the stuff the system installs. If I'd have create persistent volume to store my photos (instead of the recommended bind mapping) then I'd easily have filled the persistent volume. This might be something to check, just in case.

However, it would report this error for every single file, as it couldn't write any data to the drive at all. This only seems to be affecting specific files. Is the drive in good health? Possibly it's failing to write to specific parts of the drive and generating these errors... Can you recreate your container mapping to a volume on a different drive and test?

Also, what is the underlying filesystem? I'm running ext4 on my server. This could be filesystem related, I guess.

What version iOS are you running... and what model iPhone? I'm just wondering if the iPhone 13 max has bumped up the megapixels and the underlying script genuinely can't handle larger HEIC files for some reason. Can you verify the sizes of the the offending files on iCloud.com? Are they all significantly larger than the rest? Or all over certain size?

FadingArabChristians commented 2 years ago

I have not been able to reproduce the error yet.

The HEIC Pic from 1/4/21 in my post was a screen shot about 548kb and I have ~19TB of storage.

For me it was during my first "sync" using unRAID using the default file system (XFS I believe). The second "sync" successfully added ~10 items.

I have a fairly large library going back from multiple devices, the latest being an iPhone X.

After checking the size of my iCloud photo storage my iPhone says its 136.1GB and my local sync via iCloudpd is 176GB.

My main concern is verifying that everything was Downloaded correctly. So, does icloudPD go back on the second "Sync" and try to redownload the files skipped?

I hope this splurge of information is helpful for you. Thanks for everything <3

mikeyvt commented 2 years ago

Hey thanks for the reply.

This was the first sync in Unraid for me also. I do have a 13 pro max but 99% of the photos were taken with older iphones over the last 6 years.

I did notice that this was phones only on my mobile and non from my shared albums.

If I can provide you any more information let me know. Thanks for the awesome work on this.

boredazfcuk commented 2 years ago

Hi,

Are you guys using the latest version of the container? I have actually seen this issue before, but it was related to multi-threaded downloads... a feature which was removed about a year ago: https://github.com/icloud-photos-downloader/icloud_photos_downloader/issues/155

If the issue is something similar, like a locking problem, then the files should appear on a subsequent run. If the problem is due to the application not being able to handle specific files though, the same files will probably error out each time. Have you checked whether the files exist after a couple of runs?

FadingArabChristians commented 2 years ago

For me the skipped files have eventually downloaded correctly in the .mounted folder.

My disk might have been overwhelmed by write requests and thus skipping files.

Wish I knew how to save the logs then. But so far I believe its a non-issue for me.

For what it is worth I upgraded to the latest docker as of today.

LMK if you need anything else

jasonwaters commented 2 years ago

Thank you for creating this project, I am very excited to use it!

I just set up the cloudpd docker image and started the first run yesterday. But this morning i noticed this telegram error message:

screenshot-2021-10-30-080547@2x

I checked the log and found many of the files were skipped with the You might have run out of disk space, or the file might be too large for your OS. error message. I am running this in a docker container on a synology NAS with plenty of disk space, so i know thats not the issue.

screenshot-2021-10-30-080759@2x
2021-10-29 16:41:18 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1242.HEIC
2021-10-29 16:41:18 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1242_HEVC.MOV
2021-10-29 16:41:19 ERROR    IOError while writing file to /home/docker/iCloud/2021/10/22/IMG_1242_HEVC.MOV! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...
2021-10-29 16:41:19 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1241.HEIC
2021-10-29 16:41:19 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1241_HEVC.MOV
2021-10-29 16:41:20 ERROR    IOError while writing file to /home/docker/iCloud/2021/10/22/IMG_1241_HEVC.MOV! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...
2021-10-29 16:41:20 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1240.HEIC
2021-10-29 16:41:20 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1240_HEVC.MOV
2021-10-29 16:41:20 ERROR    IOError while writing file to /home/docker/iCloud/2021/10/22/IMG_1240_HEVC.MOV! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...
2021-10-29 16:41:20 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1239.HEIC
2021-10-29 16:41:21 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1239_HEVC.MOV
2021-10-29 16:41:21 ERROR    IOError while writing file to /home/docker/iCloud/2021/10/22/IMG_1239_HEVC.MOV! You might have run out of disk space, or the file might be too large for your OS. Skipping this file...
2021-10-29 16:41:21 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1238.HEIC
2021-10-29 16:41:22 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1238_HEVC.MOV
2021-10-29 16:41:22 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1237.HEIC
2021-10-29 16:41:23 INFO     Downloading /home/docker/iCloud/2021/10/22/IMG_1236.HEIC

The script failed with this in the logs

2021-10-30 02:11:19 INFO     Downloading /home/docker/iCloud/2020/04/17/IMG_7317.HEIC
2021-10-30 02:11:19 INFO     Downloading /home/docker/iCloud/2020/04/17/IMG_7316.HEIC
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 445, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/lib/python3.8/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 755, in urlopen
    retries = retries.increment(
  File "/usr/lib/python3.8/site-packages/urllib3/util/retry.py", line 531, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3.8/site-packages/urllib3/packages/six.py", line 734, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 445, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/lib/python3.8/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/icloudpd", line 33, in <module>
    sys.exit(load_entry_point('icloudpd==1.7.2', 'console_scripts', 'icloudpd')())
  File "/usr/lib/python3.8/site-packages/click/core.py", line 722, in __call__
    return self.main(*args, **kwargs)
  File "/usr/lib/python3.8/site-packages/click/core.py", line 697, in main
    rv = self.invoke(ctx)
  File "/usr/lib/python3.8/site-packages/click/core.py", line 895, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/lib/python3.8/site-packages/click/core.py", line 535, in invoke
    return callback(*args, **kwargs)
  File "/usr/lib/python3.8/site-packages/icloudpd-1.7.2-py3.8.egg/icloudpd/base.py", line 561, in main
    item = next(photos_iterator)
  File "/usr/lib/python3.8/site-packages/pyicloud_ipd/services/photos.py", line 295, in photos
    request = self.photos_request(offset)
  File "/usr/lib/python3.8/site-packages/pyicloud_ipd/services/photos.py", line 276, in photos_request
    return self.service.session.post(
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 590, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3.8/site-packages/pyicloud_ipd/base.py", line 68, in request
    response = super(PyiCloudSession, self).request(*args, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))

Hopefully it gives some clues...

jasonwaters commented 2 years ago

I wonder if it could be apple throttling API access? I have a very large photo/video library (almost 130K items). The script seems to download for many hours and then starts to receive these type of errors -- and then ultimately fails with the final error. I wonder if i just let it continue to sync on schedule (every 24 hours), if it will eventually successfully download all media.

boredazfcuk commented 2 years ago

Hi

Usually, when Apple throttle the API access, you'll see an error along the lines of this: https://github.com/boredazfcuk/docker-icloudpd/issues/109

However, when the script runs, it connects to Apple servers and just generates a list of the file names. It has to scan through every file to do this. If it finds a new file available to download, it will re-run the sync, but this time download files.

In your case, it has to scan through files twice, so must be processing 260k files, which is quite a few. Maybe Apple is rate limiting it due to the number of requests.

There is a variable you can set called skip_check which will skip the check for new files and just process the download section each time. It should cut your average runtime in half (or thereabouts), but it will spam your logs with a list of your files for every run.

Try switching it on and seeing if you still see the errors.

Thanks.

jasonwaters commented 2 years ago

@boredazfcuk i will try the skip_check setting. What are the down sides? What functionality is lost if I do that?

My library from years ago won't change much, so if I can get the full sync to happen then maybe i can configure the script to only look for new/changed photos over the past month or so on each sync. That would limit how many files it has to iterate.

boredazfcuk commented 2 years ago

No functionality will be lost, I just put the check in to reduce the hits on the apple servers. I was syncing hourly at that point, so it reduced the load on the Apple servers.

I believe Apple changed their rate limiting settings some time after that though, as I started hitting issues when syncing that frequently. I set it to sync twice a day now, so to be honest the download check is probably a little redundant nowadays.

jasonwaters commented 2 years ago
2021-11-05 08:10:47 INFO     All photos have been downloaded!

It did the trick! Thanks 🙏

boredazfcuk commented 2 years ago

Awesome. I'll close this off. Any more problems, just create another issue. Hopefully I'll get to it in a bit of a more timely fashion. Been pushed and pulled all over recently so haven't had the time or motivation to get on top of these recent issues that popped up.