Open eddified opened 6 months ago
Sorry, I did search for duplicates, I hope this isn't one.
Can you share screen capture of the backup page when you try to backup them as well as the mobile app log right after?
Yes. Something is wrong with iOS version (1.103.0 build 155). Upload is very slow or not start at all. After restart the photos are uploaded on server but cloud icons on photos show there is copy only on server (it is not true). When I disable autoupdate all icons changed to succesfull uploaded. Manual upload show success and photos are on server but in app there is still options to upload.
Logs from mobile app
2024-05-01 22:08:59.842094 | INFO | BackupNotifier | _getBackupAlbumsInfo: Found 37 available albums |
2024-05-01 22:08:59.841425 | INFO | BackupNotifier | Found 37 local albums |
2024-05-01 22:08:58.532674 | INFO | AlbumService | Syncing completed. Changes: false |
2024-05-01 22:08:58.527860 | INFO | AlbumService | 'Recents' is not selected, keeping only selected albums |
2024-05-01 22:08:58.527804 | INFO | AlbumService | Found 21 device albums |
2024-05-01 22:08:57.057473 | SEVERE | ImmichErrorLogger | FlutterError - Catch all |
Exception: Bad file descriptor
Library: image resource service
Context: resolving an image codec |
2024-05-01 22:08:57.057270 | SEVERE | ImmichErrorLogger | FlutterError - Catch all |
Exception: Bad file descriptor
Library: image resource service
Context: resolving an image codec |
2024-05-01 22:08:57.055529 | WARNING | UserService | Failed get all users | ApiException 400: HTTP connection failed: GET /user (Inner exception: Bad file descriptor)
#0 IOClient.send (package:http/src/io_client.dart:96)
<asynchronous suspension>
#1 BaseClient._sendUnstreamed (package:http/src/base_client.dart:93)
<asynchronous suspension>
#2 ApiClient.invokeAPI (package:openapi/api_client.dart:101)
<asynchronous suspension>
#3 UserApi.getAllUsers (package:openapi/api/user_api.dart:243)
<asynchronous suspension>
#4 UserService._getAllUsers (package:immich_mobile/shared/services/user.service.dart:42)
<asynchronous suspension>
#5 UserService.refreshUsers (package:immich_mobile/shared/services/user.service.dart:74)
<asynchronous suspension>
#6 AlbumService.refreshRemoteAlbums (package:immich_mobile/modules/album/services/album.service.dart:153)
<asynchronous suspension>
#7 Future.wait.<anonymous closure> (dart:async/future.dart:518)
<asynchronous suspension>
|
2024-05-01 22:08:41.412145 | INFO | AlbumService | Syncing completed. Changes: true |
2024-05-01 22:08:41.412113 | INFO | SyncService | Synced changes of local album Favorites to DB |
2024-05-01 22:08:41.388233 | INFO | AlbumService | 'Recents' is not selected, keeping only selected albums |
2024-05-01 22:08:41.388183 | INFO | AlbumService | Found 21 device albums |
2024-05-01 22:05:32.272239 | INFO | BackupNotifier | _getBackupAlbumsInfo: Found 37 available albums |
2024-05-01 22:05:32.271280 | INFO | BackupNotifier | Found 37 local albums |
2024-05-01 22:05:29.872683 | INFO | AlbumService | Syncing completed. Changes: true |
2024-05-01 22:05:29.872617 | INFO | SyncService | Added a new local album to DB: Favorites |
2024-05-01 22:05:29.869397 | INFO | SyncService | Upserted 14 assets into the DB |
2024-05-01 22:05:29.866258 | INFO | SyncService | 0 assets already existed in DB, to upsert 14 |
2024-05-01 22:05:29.301173 | INFO | SyncService | Syncing a new local album to DB: Favorites |
2024-05-01 22:05:29.300980 | INFO | AlbumService | 'Recents' is not selected, keeping only selected albums |
2024-05-01 22:05:29.300939 | INFO | AlbumService | Found 21 device albums |
2024-05-01 22:05:26.323225 | INFO | BackupNotifier | No assets are selected for back up |
2024-05-01 22:05:26.283973 | INFO | BackupNotifier | _getBackupAlbumsInfo: Found 37 available albums |
2024-05-01 22:05:26.283591 | INFO | BackupNotifier | Found 37 local albums |
2024-05-01 22:05:25.032966 | INFO | BackupNotifier | No assets are selected for back up |
2024-05-01 22:05:24.987100 | INFO | BackupNotifier | _getBackupAlbumsInfo: Found 37 available albums |
2024-05-01 22:05:24.986725 | INFO | BackupNotifier | Found 37 local albums |
It should have said "14 assets" on the immich app screen shot, but it says only 12 because it skipped 2. The 2 it skipped (which were not uploaded to immich server) appear to be related to these errors from the logs (but I'm totally guessing here):
2024-05-01 22:08:57.057473 | SEVERE | ImmichErrorLogger | FlutterError - Catch all |
Exception: Bad file descriptor
Library: image resource service
Context: resolving an image codec |
2024-05-01 22:08:57.057270 | SEVERE | ImmichErrorLogger | FlutterError - Catch all |
Exception: Bad file descriptor
Library: image resource service
Context: resolving an image codec |
The logs attached here were from when I reproduced the issue using the latest versions of app (1.103.0 build.155) and server (1.103.1)
So the two screenshots get sent to you by your friend after your friend edited the screenshot. Is that the correct way to reproduce it?
Well, @alextran1502, I attempted to reproduce it that way (using my son's iphone to take a live photo, edit it, then send it to my iphone) and I was unable to reproduce it that way. I have only been able to reproduce it by deleting the uploaded files from immich server and attempting to re-backup. The two original live photos I received from my friend are still reproducing the issue, and I am willing to upload them somewhere if you want to try that approach.
@eddified that works, I can get it on my phone to try
Or if there is a debug version of the app that I can install that will output more logs to show the exact error -- I am willing to do something like this.
@eddified that works, I can get it on my phone to try
Do you have a recommended way to transfer the files from my phone to you? Honestly, I don't know how to make sure I get the "originals" completely unmodified -- iOS likes to touch files and auto-convert them and such....
@eddified if you can use AirDrop to your laptop (assuming you have a Mac 😅) I think it will preserve the file that way
@alextran1502 These are "live photos", so they are an image with a short video. I can't guarantee this information is 100% accurate, but it matches up with what I've seen:
"Live Photos" only exist inside the Apple ecosystem, there are no Live Photos outside of it, so what you get on Windows is going to be, at best, an approximation.
https://www.reddit.com/r/ios/comments/qvnz8i/best_way_to_move_photos_from_ios_to_windows/
So, trying to export these to you may lose whatever it is that is causing the issue. Ie, without special instructions, I can just do my best.
First, note that using AirDrop to the mac loses the video portion (I tried it). So, I will try something else: on iOS in the "Photos" app, I found an "export unmodified originals" option. I will use this option to send the files.
Good luck getting these into iOS as "live photos" with the same name (They do not have the same name in the attached Archive -- also, unsure of whether they need to be the same name to reproduce the issue). 🤷
i am experiencing this bug too. not just with live photos, some other pictures too. looking at the postgres logs it says this:
2024-05-03 08:19:53.408 UTC [336454] ERROR: duplicate key value violates unique constraint "UQ_assets_owner_library_checksum"
2024-05-03 08:19:53.408 UTC [336454] DETAIL: Key ("ownerId", "libraryId", checksum)=(6e46def4-db89-4d2d-a7c4-174199f65980, 89c679f9-3d60-4101-bee5-a24c5fa140d6, \xe7fc5a120fc1800f7a3daa7a55bf1af1f0376676) already exists.
2024-05-03 08:19:53.408 UTC [336454] STATEMENT: INSERT INTO "assets"("id", "deviceAssetId", "ownerId", "libraryId", "deviceId", "type", "originalPath", "previewPath", "thumbnailPath", "thumbhash", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "fileCreatedAt", "localDateTime", "fileModifiedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "checksum", "duration", "isVisible", "livePhotoVideoId", "originalFileName", "sidecarPath", "stackId") VALUES (DEFAULT, $1, $2, $3, $4, $5, $6, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, $7, $8, $9, $10, $11, DEFAULT, $12, $13, $14, $15, $16, DEFAULT, $17, $18, DEFAULT) RETURNING "id", "thumbnailPath", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "isVisible"
it looks like it's because of broken uploads. is there a way to force it? or at least remove whichever entries from postgres?
edit: tried to manually remove the entry from postgres and then re-add the picture. the first time postgres shows no issue (because there was no entry), and of course trying to add it again gives that error. either way, the image isn't really added. it seems like something is stuck in between.
microservices log shows that the upload fails because of this:
[Nest] 7 - 05/03/2024, 8:41:26 AM ERROR [JobService] Unable to run job handler (videoConversion/video-conversion): Error: ffmpeg exited with code 1: upload/library/admin/2015/2015-11-14/IMG_5924.MOV+1.mov: No such file or directory
[Nest] 7 - 05/03/2024, 8:41:26 AM ERROR [JobService] Error: ffmpeg exited with code 1: upload/library/admin/2015/2015-11-14/IMG_5924.MOV+1.mov: No such file or directory
I also noticed a duplicate key error in the Postgres logs, but I’m not certain it appeared because of the same issue. I will try it again and see if the error corresponds with the failed upload
I created a brand new immich server installation to test this issue a different way. And I was unable to reproduce the issue: all assets uploaded just fine to the empty server. I will revert to the original installation (the one that has tens of thousands of photos at /mnt/media/pictures, ie, the one where I can reproduce the issue) and see if I can test it further -- ie, to see what I can see.
OK, so, I duplicated the issue on the immich install that I used originally. This time, when I duplicated the issue, I paid attention to the server logs when I did it. Apparently there are duplicate key errors. Using the error message, I looked up the offending records in Postgres. The offending records are not visible, and not deleted. Also, stackId
and livePhotoVideoId
are empty. (And, the files do not exist on disk).
My best guess so far is that there was an error the first time these items were uploaded, and as a result left dangling cruft in the database.
immich_postgres | 2024-05-07 00:58:23.587 UTC [188] ERROR: duplicate key value violates unique constraint "UQ_assets_owner_library_checksum"
immich_postgres | 2024-05-07 00:58:23.587 UTC [188] DETAIL: Key ("ownerId", "libraryId", checksum)=(f29d45b6-4987-4baa-8502-424f6ab455f8, b947dffc-57c4-483a-b274-d1329bbc9626, \xa8956b11a671a407c698e1549f4a0e6acf2feae5) already exists.
immich_postgres | 2024-05-07 00:58:23.587 UTC [188] STATEMENT: INSERT INTO "assets"("id", "deviceAssetId", "ownerId", "libraryId", "deviceId", "type", "originalPath", "previewPath", "thumbnailPath", "thumbhash", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "fileCreatedAt", "localDateTime", "fileModifiedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "checksum", "duration", "isVisible", "livePhotoVideoId", "originalFileName", "sidecarPath", "stackId") VALUES (DEFAULT, $1, $2, $3, $4, $5, $6, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, $7, $8, $9, $10, $11, DEFAULT, $12, $13, $14, $15, $16, DEFAULT, $17, $18, DEFAULT) RETURNING "id", "thumbnailPath", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "isVisible"
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:24 AM LOG [MediaService] Successfully generated JPEG image preview for asset e4e83c04-5a29-46d5-8e43-6d9875ba4ca3
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:25 AM LOG [MediaService] Successfully generated WEBP image thumbnail for asset e4e83c04-5a29-46d5-8e43-6d9875ba4ca3
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:25 AM WARN [MetadataRepository] Response from database for reverse geocoding latitude: 37.4819861111111, longitude: -111.216544444444 was null
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:26 AM WARN [MetadataRepository] Response from database for reverse geocoding latitude: 37.4819333333333, longitude: -111.216508333333 was null
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:27 AM LOG [MediaService] Successfully generated JPEG image preview for asset d651eb0d-dcbf-4128-a570-3906cd3ec66d
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:28 AM LOG [MediaService] Successfully generated WEBP image thumbnail for asset d651eb0d-dcbf-4128-a570-3906cd3ec66d
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:28 AM LOG [MediaService] Successfully generated JPEG image preview for asset df956e04-7960-4281-9b2b-dc5a679f3bcb
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:29 AM LOG [MediaService] Successfully generated WEBP image thumbnail for asset df956e04-7960-4281-9b2b-dc5a679f3bcb
immich_microservices | [Nest] 7 - 05/07/2024, 12:58:30 AM WARN [MetadataRepository] Response from database for reverse geocoding latitude: 37.4819027777778, longitude: -111.216469444444 was null
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] ERROR: duplicate key value violates unique constraint "UQ_assets_owner_library_checksum"
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] DETAIL: Key ("ownerId", "libraryId", checksum)=(f29d45b6-4987-4baa-8502-424f6ab455f8, b947dffc-57c4-483a-b274-d1329bbc9626, \x21df2236c4c322faa566583b6a23ec4062553810) already exists.
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] STATEMENT: INSERT INTO "assets"("id", "deviceAssetId", "ownerId", "libraryId", "deviceId", "type", "originalPath", "previewPath", "thumbnailPath", "thumbhash", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "fileCreatedAt", "localDateTime", "fileModifiedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "checksum", "duration", "isVisible", "livePhotoVideoId", "originalFileName", "sidecarPath", "stackId") VALUES (DEFAULT, $1, $2, $3, $4, $5, $6, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, $7, $8, $9, $10, $11, DEFAULT, $12, $13, $14, $15, $16, DEFAULT, $17, $18, DEFAULT) RETURNING "id", "thumbnailPath", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "isVisible"
Expanded display is on.
immich=# select * from "assets" where ("ownerId", "libraryId", "checksum")=('f29d45b6-4987-4baa-8502-424f6ab455f8', 'b947dffc-57c4-483a-b274-d1329bbc9626', '\xa8956b11a671a407c698e1549f4a0e6acf2feae5');
-[ RECORD 1 ]----+--------------------------------------------------------------------------------------------------
id | adc5dc2e-4eaa-4ccb-9eb1-65d61c008437
deviceAssetId | BDE7826C-F03E-4F80-A93B-9F951B9A8DD5/L0/001
ownerId | f29d45b6-4987-4baa-8502-424f6ab455f8
deviceId | 1e20357e41ed51157ac72eae2b7a35963a453e10f1d25dcb50c28cee6546ffaa
type | VIDEO
originalPath | upload/upload/f29d45b6-4987-4baa-8502-424f6ab455f8/2d/75/2d7554bf-0895-48e9-9391-163ac11f7370.mov
previewPath |
fileCreatedAt | 2023-10-07 16:59:54+00
fileModifiedAt | 2024-01-23 04:33:48+00
isFavorite | t
duration | 0:00:00.000000
thumbnailPath |
encodedVideoPath |
checksum | \xa8956b11a671a407c698e1549f4a0e6acf2feae5
isVisible | f
livePhotoVideoId |
updatedAt | 2024-04-24 14:55:23.657847+00
createdAt | 2024-04-24 14:55:23.657847+00
isArchived | f
originalFileName | FullSizeRender.MOV
sidecarPath |
isReadOnly | f
thumbhash |
isOffline | f
libraryId | b947dffc-57c4-483a-b274-d1329bbc9626
isExternal | f
deletedAt |
localDateTime | 2023-10-07 16:59:54+00
stackId |
immich=# select * from "assets" where ("ownerId", "libraryId", "checksum")=('f29d45b6-4987-4baa-8502-424f6ab455f8', 'b947dffc-57c4-483a-b274-d1329bbc9626', '\x21df2236c4c322faa566583b6a23ec4062553810');
-[ RECORD 1 ]----+--------------------------------------------------------------------------------------------------
id | 479ec0d0-be85-49fb-b6ec-91f2681b699f
deviceAssetId | 4208B09C-BF28-405C-9F6C-FD7CF9E48B23/L0/001
ownerId | f29d45b6-4987-4baa-8502-424f6ab455f8
deviceId | 1e20357e41ed51157ac72eae2b7a35963a453e10f1d25dcb50c28cee6546ffaa
type | VIDEO
originalPath | upload/upload/f29d45b6-4987-4baa-8502-424f6ab455f8/37/58/3758b3b5-6efc-4879-a49c-4fe3316503b9.mov
previewPath |
fileCreatedAt | 2023-10-07 16:56:29+00
fileModifiedAt | 2024-01-23 04:34:03+00
isFavorite | t
duration | 0:00:00.000000
thumbnailPath |
encodedVideoPath |
checksum | \x21df2236c4c322faa566583b6a23ec4062553810
isVisible | f
livePhotoVideoId |
updatedAt | 2024-04-24 14:55:24.132792+00
createdAt | 2024-04-24 14:55:24.132792+00
isArchived | f
originalFileName | FullSizeRender.MOV
sidecarPath |
isReadOnly | f
thumbhash |
isOffline | f
libraryId | b947dffc-57c4-483a-b274-d1329bbc9626
isExternal | f
deletedAt |
localDateTime | 2023-10-07 16:56:29+00
stackId |
is there a way to figure out which entries need to be deleted from the db then? removing the one from "assets" isn't enough
It seems these records are invalid? (I can't delete them in the UI because they're not visible. The files are actually deleted, but the db says they're NOT offline. The db records say duration is 0.0, but I know the original files are valid and not empty, so they actually have a duration.) Perhaps originally my docker permissions were not set correctly, so it might be that at the time these records were created, the ffmpeg microservice wasn't working properly -- could that could explain the 0 duration?
Is there a way to make the server more robust? It might be impossible to know what exactly went wrong in this case, but ideally one or more of the following could be implemented (if not already implemented):
There is a decent chance that this issue has been resolved, as we've fixed the way uploads work, especially around live photos. Can you retest this and let me know the results?
A friend of mine is actually experiencing the same issue on my server. He uploaded all photos from one album that he selected in the app but due to my incorrect storage setup, I had to delete all of the files from immich and asked him to reupload it again.
The first upload was without any issue. All photos were uploaded. However after the reupload, there are 6 videos that can't be uploaded for some reason.
The logs on the phone show the same as eddified has mentioned at the start of this post.
Currently running v1.118.2
Immich_log_2024-10-24T22_45_09.025610.log
Server log in docker doesn't show anything except that the connection was established
@NightMean , in my case I believe that the issue was related to file system permissions: the original upload did not complete due to inability to write to the file system. But, it did leave an entry in the database. Then, when I attempted to upload the same files again later, the entries in the db caused immich server believe that the files had already been properly uploaded. I imagine (that is, I'm guessing) the order of operations made by immich server is something like this:
When (2) fails, the db record that was created in step (1) should be removed, but it is not properly being removed. This is my best guess as to what is going on. (This is why I have suggested making the error handling more robust in my previous comment on this issue.)
In my case, I fixed the issue by doing the following:
In my case, I fixed the issue by doing the following:
I looked at the immich server logs. I noticed logs saying "duplicate key constraint violation" (or similar). These logs helped me know which primary key to use to locate the offending db records.
I have enabled Verbose logging but I'm not able to see any mention about it when friend is doing the upload. I have a screenshot from his phone where I can see the Asset ID but when I tried to search for it in postgres, I didn't find anything. I was about to do the same but as I can't find those photos in postgres, I don't know how to proceed from there to be honest.
@NightMean , I apologize, I misspoke. The "duplicate key constraint violation" logs were emitted from the postgres container, not the immich server container. Example (copied from my above comment made on May 6):
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] ERROR: duplicate key value violates unique constraint "UQ_assets_owner_library_checksum"
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] DETAIL: Key ("ownerId", "libraryId", checksum)=(f29d45b6-4987-4baa-8502-424f6ab455f8, b947dffc-57c4-483a-b274-d1329bbc9626, \x21df2236c4c322faa566583b6a23ec4062553810) already exists.
immich_postgres | 2024-05-07 00:58:31.547 UTC [188] STATEMENT: INSERT INTO "assets"("id", "deviceAssetId", "ownerId", "libraryId", "deviceId", "type", "originalPath", "previewPath", "thumbnailPath", "thumbhash", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "fileCreatedAt", "localDateTime", "fileModifiedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "checksum", "duration", "isVisible", "livePhotoVideoId", "originalFileName", "sidecarPath", "stackId") VALUES (DEFAULT, $1, $2, $3, $4, $5, $6, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, $7, $8, $9, $10, $11, DEFAULT, $12, $13, $14, $15, $16, DEFAULT, $17, $18, DEFAULT) RETURNING "id", "thumbnailPath", "encodedVideoPath", "createdAt", "updatedAt", "deletedAt", "isFavorite", "isArchived", "isExternal", "isReadOnly", "isOffline", "isVisible"
@eddified were you able to see this right after the photo was uploaded or did you find that in the old logs?
My today's postgres log does not show anything other than 2024-10-25 08:45:15.215 UTC [1869] FATAL: role "root" does not exist
which I already saw previously but this is not related.
@NightMean that message shows up not the first time, but all subsequent times when the upload occurs.
Thanks for the heads up. As I don't see anything in logs when the upload starts, I suspect the culprit is the file size as it is above 100MB and I'm running it via cloudflare tunnel. Strange that it worked in the first upload.
The bug
I am not 100% sure why, but some of my photos won't upload to Immich server. It seems it might be related to files that have the same name.
Normally, files on the iPhone don't have the same name. But, if a friend edits a live photo they took (clicking "auto" in the photo edit flow seems to do it) and then shares the photo via messages to your iPhone, and then on your own phone, you click the download icon next to the image in Messages, it will often end up in your photo roll with the name "FullSizeRender", with no number on the end. If the friend does this a few times, you will have lots of files with duplicate name "FullSizeRender".
Other settings: I have "storage template" enabled, "{{y}}/{{y}}-{{MM}}/{{y}}-{{MM}}-{{dd}}/{{filename}}". On my phone, I did not backup the main photo roll. I only backed up one album with 14 items. I also verified that the two photos that won't upload are not duplicates on the server nor in the album. Monument 2 (with which I backup the entire Camera roll) was able to upload these photos without issue.
iOS Immich App v1.102.2
Immich server v1.102.3
The OS that Immich Server is running on
Ubuntu 22.04.4
Version of Immich Server
v1.102.3
Version of Immich Mobile App
v1.102.2
Platform with the issue
Your docker-compose.yml content
Your .env content
Reproduction steps
Relevant log output
No response
Additional information
No response