[BUG] Image autoupload uploads images twice under certain conditions

[Dehumanizer77]

Actual behaviour

When image autoupload is turned on, images are uploaded twice, the second time with (2) at the end of the file name.

Expected behaviour

Images get uploaded only once.

Steps to reproduce

It usually happens when both image and video autoupload is turned on, however for example right now I only have image autoupload turned on and it still happens. Also yesterday, I took two images, one was uploaded once and the second one got uploaded twice. Fiddling with enabling/disabling image and/or video autoupload sometimes fixes the issue.

Can this problem be reproduced with the official owncloud server?
not when I tried it now

Environment data

Android version:
12

Device model:
Xiaomi Poco F3

Stock or customized system:
Custom ROM (Pixel Experience 12)

ownCloud app version:
4.0-beta1 (but I have the problem with the latest stable version as well)

ownCloud server version:
10.11

Logs

ownCloud log (data/owncloud.log)

owncloud.2023-03-22.log

[JuancaG05]

Hi @Dehumanizer77! Thanks for opening a new issue for this! We'll take a look and let you know about our findings 😉

[web2wire]

I have had this for several months now, it basically happens every time. The difference being for me I often get (2), (3) and several more versions of the same file. The original is sometimes, but not always zero sized. I am happy to provide further info if this helps.

[Dehumanizer77]

It's totally unreliable, sometimes it uploads the file fine, sometimes with zero size, sometimes multiple times, sometimes just once...

[vvzinovyev]

Hi. Same for me. I did not notice zero size on the original file. I get even (3), (4), (5) sometimes. Usually I just delete such files and the original ones seem to be OK. It happens for quite a while already - half a year for sure and survived a few app upgrades. Just upgraded to the most recent version recently. I have Samsung S10e.

[vvzinovyev]

Actually, I upgraded to v3.0.4, and first time in a while did not have these dupes today. Let's see..

[Dehumanizer77]

Since 4.0 beta does have the problem as well, I would be surprised if it was fixed in 3.0.4, but maybe some accidental change fixed it, let us know if the problem didn't reappear later.

[vvzinovyev]

So far only one file got a dupe since I upgraded to 3.0.4. This version is definitely better than whatever 2.x I had before.

[web2wire]

I'm on 3.0.4 and still getting the same issues. Multiple dupes, sometimes zero sized, along with sometimes originals zero sized also. This is the most worrying for me as it means that images are not in fact being synced but the OwnCloud app thinks they have been. Until later when I go to import them for processing and find that the images are empty/broken and have to see if I've still got the originals on my phone.

[mihha]

I have a similar issue where one image is uploaded to the /CameraUploads folder and the same image is uploaded to the /Camera/Igor folder.

That second folder is actually the one I configured in the ownCloud android client Settings and that is the folder I would expect to get uploaded files

I can't get rid of the original /CameraUpload folder

[Dehumanizer77]

The original problem seems to be fixed now, at least with 4.0-beta4 I didn't notice duplicate files anymore.

[vvzinovyev]

The original problem seems to be fixed now, at least with 4.0-beta4 I didn't notice duplicate files anymore.

Cool, installed, let's see!

[mihha]

I installed the latest 4.0 beta version, but this bug still exists

Good thing is that it seems that other issue (uploading files to the default /CameraUpload and custom folder set in the settings) is being fixed

[Dehumanizer77]

strange, so I'm just lucky now

[mihha]

It is getting worse

After some time, I get this

[JuancaG05]

This is a known issue right now, no specific fix for it in the 4.0 version of the app. We'll check it ASAP and will keep you updated in this thread 🚀

[jsiddall]

FWIW this is still happening in version 4.1.1, only some files and usually only one extra copy

[vvzinovyev]

I moved to Nextcloud, and don't have this issue anytime

…

On Tue, 24 Oct 2023, 02:36 Jeff Siddall, ***@***.***> wrote: FWIW this is still happening in version 4.1.1, only some files and usually only one extra copy — Reply to this email directly, view it on GitHub <#3983 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ATBZIJSL5OJYFJP2PUBCT2LYA3IN5AVCNFSM6AAAAAAWDUUNWSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTONZVHE4DAMBYG4> . You are receiving this because you commented.Message ID: ***@***.***>

[mcarbonne]

Almost same issue observed with latest version (4.1.1) and with OCIS backend. Some detailed logs (android app) available: owncloud/ocis#8239

I observed 2 slightly different outcomes:

• one file on OCIS, but corrupted
• two file on OCIS, the first one is partially uploaded (0 < size < real size) and the second one is OK, but with (1) in the name.

[jsiddall]

I updated to the latest Android client 4.2.2 a couple of days back and today opened up the app for the first time since the upgrade. After a while it auto-uploaded all the new photos exactly twice. No errors or failures in any of the uploaded files. This seems to be happening on the client because in the upload list I noticed it uploaded the photos, in date order, once and then immediately uploaded them again in the exact same order. Somehow it seems to be detecting new photos twice.

[jsiddall]

Android client recently updated to 4.3.1. This time I got exactly triplicates of every file!

I happened to see the client uploading and got a screenshot of the client simultaneously uploading the same file twice so the duplicates are being initiated by the client for sure. I don't know how to upload screenshots from Android but if it would be helpful I can figure it out.

[Dehumanizer77]

I did not get any duplicates or triplicates with 4.3.1 so far... But I'll keep an eye on that for a few days or a week if I just have been lucky.

[jsiddall]

Yeah, I should have been more clear: I don't think 4.3.1 in itself is the cause of the triplicates. Just that whatever bug is causing it is still around in 4.3.1.

It is definitely somewhere in the code that finds new images. I don't know about other people's experience, but my client goes dormant after some time and doesn't upload new images until I open it again. Then, some minutes after re-opening, it uploads all the new images, and sometimes more than once.

Guessing that Android is preventing it from running in the background for some reason, but I am not sure how to fix that, or whether it would even prevent this issue.

[JuancaG05]

Hi everyone! 👋

Just as an update: no, we have not been working on this lately, so the bug must be somewhere yet... 😿 We know this is so ugly, but we have a problem and it's that we are not able to reproduce this bug consistently. This happens arbitrarily, only some times and only with some files, so, it's also difficult for us to locate the error somehow. You know logs are welcome (if you get them just ask and we'll provide a secure way of uploading them so that only us are able to see them), or if you find out a way to reproduce it consistently, it would be very useful as well.

I don't know about other people's experience, but my client goes dormant after some time and doesn't upload new images until I open it again. Then, some minutes after re-opening, it uploads all the new images, and sometimes more than once.

Guessing that Android is preventing it from running in the background for some reason, but I am not sure how to fix that, or whether it would even prevent this issue.

About this, as you say, it is likely provoked by the Android Operating System. Android tries to save energy by killing, revoking permissions or even "deactivating" apps that have not been used for a long time (time decided by Android internally, not by apps developers). So, to help here, I would advice you to check your battery saving settings, but if everything looks OK there, just try to open the app more oftenly (once per week should be enough I guess...).

We'll keep updating here in any case, thanks for your patience and help 👍

[vvzinovyev]

After I switched to Nextcloudpi, zero issues with duplicates and overall much better experience :)

[JuancaG05]

Hi @vvzinovyev! Glad to hear that! But this issue is aimed to discuss about the bug in the ownCloud Android app, and you already commented the same some messages above, so please, don't spam the GitHub tickets. Thanks for your collaboration 😃

[vvzinovyev]

Oops, sorry, did not see I'm repeating. Unsubscribing from this conversation )

[jsiddall]

After I switched to Nextcloudpi, zero issues with duplicates and overall much better experience :)

Interesting. Since the client seems to be the thing doing the duplication it is surprising that it would work differently on NextCloud.

Hi everyone! 👋

Just as an update: no, we have not been working on this lately, so the bug must be somewhere yet... 😿 We know this is so ugly, but we have a problem and it's that we are not able to reproduce this bug consistently. This happens arbitrarily, only some times and only with some files, so, it's also difficult for us to locate the error somehow. You know logs are welcome (if you get them just ask and we'll provide a secure way of uploading them so that only us are able to see them), or if you find out a way to reproduce it consistently, it would be very useful as well.

I don't know about other people's experience, but my client goes dormant after some time and doesn't upload new images until I open it again. Then, some minutes after re-opening, it uploads all the new images, and sometimes more than once.
Guessing that Android is preventing it from running in the background for some reason, but I am not sure how to fix that, or whether it would even prevent this issue.

About this, as you say, it is likely provoked by the Android Operating System. Android tries to save energy by killing, revoking permissions or even "deactivating" apps that have not been used for a long time (time decided by Android internally, not by apps developers). So, to help here, I would advice you to check your battery saving settings, but if everything looks OK there, just try to open the app more oftenly (once per week should be enough I guess...).

We'll keep updating here in any case, thanks for your patience and help 👍

Ah, yeah, I think I have the Android power saving mode enabled. Maybe that is making this occur more often for me than others. Still, I don't get duplicates every time so there is an element of unpredictability to it.

I do have logging enabled. There are lots of files. Am I looking for one that has the next more recent date after the problem occurred? The last issue occurred 2024-07-28 about 11:47 PM local time. There is a large log file (3M) dated 2024-07-28_22.54.00 which is earlier than the problem. The next log is dated 2024-07-29 and it is tiny (1K).

Please let me know about which files and where I can provide those.

[jesmrec]

I do have logging enabled. There are lots of files. Am I looking for one that has the next more recent date after the problem occurred? The last issue occurred 2024-07-28 about 11:47 PM local time. There is a large log file (3M) dated 2024-07-28_22.54.00 which is earlier than the problem. The next log is dated 2024-07-29 and it is tiny (1K).

Please let me know about which files and where I can provide those.

It's important that the Log HTTP requests and responses is also enabled. I'll will give you some context about how the feature works, so that, it's easier to understand what's going on:

When pictures/videos auto-uploads are enabled, a background process runs every fifteen minutes (time slot is internally decided by the Android operating system), saving the latest execution timestamp after every run. The background process checks the camera roll to find pictures/videos which capture timestamp is newer than its own latest execution. Then, it sends those pictures/videos to the uploads queue, and finally updates the execution time as reference for the next run.

If you have duplications, it means that the background process is enqueuing pictures/videos that were already enqueued in previous runs. I have some guesses, then:

• The latest execution timestamp is not being correctly updated. Iin that case, it'd be easier to reproduce, it'd be a bug in the logic.
• The pictures/videos' capture date is stored somehow wrongly, leading the background process to kind of confusion when fetching the items to enqueue. Every vendor or camera app running over any OS variant might cause this... but nothing to assure at the moment.

I hope that it helps to understand. We agree that this is an ugly bug, you are totally right. But, as @JuancaG05 stated, we can not fix it without reproducing it correctly.

If you are kind to fetch some logs including the repeated uploads' scenario, you can push them to this link:

https://infinite.owncloud.com/s/IcWNuXBUbQwMUti
Pwd: aa55AA..

Any other further idea or suggestion from anyone is also welcome!

[DerFuz]

How is the upload-mechnism handling network connection problems when a picture is in the upload-queue?

For myself, I experience this problem more often when I am hiking and taking pictures. In the mountains I do not always have a (stable) data connection but the queueing should still take place. Is it maybe requeuing a failed upload and therefore uploading multiple queued files when it's online again?

I can't remember a duplicate when I am home and have a stable WiFi connection, but I will pay more attention to these scenarios going forward.

Just as another input and this scenario should somehow be reproducible.

[jesmrec]

How is the upload-mechnism handling network connection problems when a picture is in the upload-queue?

this should not have nothing to do, but i'll explain a little bit: we handle different statuses for a transfer: enqueued, current, uploaded and failed. A new upload is enqueued, then goes to current (ongoing) and finally uploaded. If something wrong happens, it goes to failed. Here, we have two different scenarios: failed because a lack of connection or connection problems, and other failures (f. ex. server down). In case of failure because lack of connection, failed uploads are automatically retried when connection is back, otherwise they must be retried manually (retry button available) when the blocking issue is fixed.

I said it does not has to do, because the background process that i described above just sends the new pictures/videos to the queue. Transfer's handling it is not its responsibility, that's other process.

Anyway, i will get your idea. Maybe @Aitorbp can check in the code whether the execution date is always updated with no restrictions, after every process runs (it should but sometimes bugs happen).

[DerFuz]

Yesterday it happened to me again. One picture was uploaded totally fine while two hours later three other images were duplicated.
The collected logs for these 4 activities are dropped into the mentioned share.

I tried to interpret the logs + source code (https://github.com/owncloud/android/blob/master/owncloudApp/src/main/java/com/owncloud/android/workers/CameraUploadsWorker.kt), but I have no knowledge of Kotlin and Android programming to give suggestions.

Some things I still wanna point out in the logs:

• The OCTransfer-object of the successful upload (single image) sources the Camera directly via the localpath (localPath=content://com.android.externalstorage.documents/tree/...), while the 3 other images have 2 OCTransfer-objects each (one from camerapath and one from a temp directory inside the app (localPath=/data/user/0/com.owncloud.android/files/owncloud/tmp/...) ← would explain duplicates
• The duplicates are created right after the last image was uploaded successfully (feels like a second run of syncFolder - I got picture and video uploads enabled with copy behavior)
• The FileNotFoundException seems to be the reason for empty duplicates (E: 2024-08-02 17:20:24:252(FileRequestBody.kt:72)java.io.FileNotFoundException: /data/user/0/com.owncloud.android/files/owncloud/tmp/...)
• The upload of the 3 problematic images took quite a long time according to the duration field of the response logs (could be a bad connection - I was inside a big building with thick walls at that time)

One question about updating of the timestamp in

android/owncloudApp/src/main/java/com/owncloud/android/workers/CameraUploadsWorker.kt

Line 167 in 01716a6

updateTimestamp(folderBackUpConfiguration, syncType, currentTimestamp)

The timestamp will be updated after all files have been enqueued. Does the enqueueSingleUpload function just queue the file and return or does it have to wait for a successful upload? As said I have no idea about Android Programming and don't know what the WorkManager does. :)

Anyway, I am open to help troubleshoot this issue but I also understand it's quite difficult if the issue can't be reproduced consistently.

[jesmrec]

thanks a lot @DerFuz !!! i will review your logs and comments, pretty useful.

The timestamp will be updated after all files have been enqueued. Does the enqueueSingleUpload function just queue the file and return or does it have to wait for a successful upload? As said I have no idea about Android Programming and don't know what the WorkManager does. :)

this is a question for @Aitorbp

Anyway, I am open to help troubleshoot this issue but I also understand it's quite difficult if the issue can't be reproduced consistently.

thanks again!!

[jesmrec]

The OCTransfer-object of the successful upload (single image) sources the Camera directly via the localpath (localPath=content://com.android.externalstorage.documents/tree/...), while the 3 other images have 2 OCTransfer-objects each (one from camerapath and one from a temp directory inside the app

that's a good point. Will check if it does mean something bad/good

The duplicates are created right after the last image was uploaded successfully (feels like a second run of syncFolder - I got picture and video uploads enabled with copy behavior)

but there is no logged run in the middle, that is making me freaking out

The FileNotFoundException seems to be the reason for empty duplicates (E: 2024-08-02 17:20:24:252(FileRequestBody.kt:72)java.io.FileNotFoundException: /data/user/0/com.owncloud.android/files/owncloud/tmp/...)

not sure if the error itself affects, because just before the name collision was detected and just after, the PUT request sends the dup file to the server. But, will require attention as well.

The upload of the 3 problematic images took quite a long time according to the duration field of the response logs (could be a bad connection - I was inside a big building with thick walls at that time)

shouldn't be related. Anyway, i will not discard any option.

keep working on it

[jesmrec]

I will comment the log file you sent, just in case anyone else wants to contribute, in order to explain the clear problem. Thanks again for sending it, @DerFuz, because it's not an easy one to reproduce.

---

Starting at this point:

I: 2024-08-02 17:14:15:192(CameraUploadsWorker.kt:254)Last sync PICTURE_UPLOADS: Fri Aug 02 15:56:28 GMT+02:00 2024
I: 2024-08-02 17:14:15:193(CameraUploadsWorker.kt:255)CurrentTimestamp Fri Aug 02 17:10:18 GMT+02:00 2024
I: 2024-08-02 17:14:15:194(CameraUploadsWorker.kt:256)3611 files found in folder: /tree/primary:DCIM/Camera
I: 2024-08-02 17:14:15:194(CameraUploadsWorker.kt:257)3 files are PICTURE_UPLOADS and were taken after last sync

The background process detects that 3 new items were added since the latest sync. So, everything OK ✅ . In fact, the next log lines tell us which those files are:

I: 2024-08-02 17:14:15:285(UploadFileFromContentUriUseCase.kt:62)Plain upload of /tree/primary:DCIM/Camera/document/primary:DCIM/Camera/IMG_20240802_155756.jpg has been enqueued.
I: 2024-08-02 17:14:15:303(UploadFileFromContentUriUseCase.kt:62)Plain upload of /tree/primary:DCIM/Camera/document/primary:DCIM/Camera/IMG_20240802_155757.jpg has been enqueued.
I: 2024-08-02 17:14:15:327(UploadFileFromContentUriUseCase.kt:62)Plain upload of /tree/primary:DCIM/Camera/document/primary:DCIM/Camera/IMG_20240802_155758_1.jpg has been enqueued.

the has been enqueued annotation also remarks that the work is correctly done ✅ . From now on, I will track just one of them, the first one IMG_20240802_155756.jpg

The next step in IMG_20240802_155756.jpg 's travel is creating an OCTransfer object. It contains all the relevant information to perform a transfer

D: 2024-08-02 17:14:15:377(UploadFileFromContentUriWorker.kt:155)Upload info: OCTransfer(id=2471, localPath=content://com.android.externalstorage.documents/tree/primary%3ADCIM%2FCamera/document/primary%3ADCIM%2FCamera%2FIMG_20240802_155756.jpg, remotePath=/CameraUpload/IMG_20240802_155756.jpg, accountName=xxx, fileSize=7444368, status=TRANSFER_QUEUED, localBehaviour=COPY, forceOverwrite=false, transferEndTimestamp=null, lastResult=null, createdBy=ENQUEUED_AS_CAMERA_UPLOAD_PICTURE, transferId=null, spaceId=null)

That's right. Here we will take also the id of the OCTransfer = 2471.

Next: mobile client will transfer the file to the server, but first, it checks if another file with same name and location already exists in the server side. Here is the propfind request

D: 2024-08-02 17:14:16:999(LogInterceptor.kt:67)REQUEST 5d955519-a643-4524-baf0-1894d88b55e9 
{
  "request": {
    "body": "<?xml version='1.0' encoding='UTF-8' ?><propfind xmlns=\"DAV:\" xmlns:CAL=\"urn:ietf:params:xml:ns:caldav\" xmlns:CARD=\"urn:ietf:params:xml:ns:carddav\" xmlns:SABRE=\"http://sabredav.org/ns\" xmlns:OC=\"http://owncloud.org/ns\"><prop><displayname /><getcontenttype /><resourcetype /><getcontentlength /><getlastmodified /><creationdate /><getetag /><OC:permissions /><OC:id /><OC:size /><OC:privatelink /><OC:share-types /></prop></propfind>",
    "headers": {
      "Depth": "0",
      "Authorization": "Basic [redacted]",
      "X-Request-ID": "5d955519-a643-4524-baf0-1894d88b55e9",
      "User-Agent": "Mozilla/5.0 (Android) ownCloud-android/4.3.1",
      "Accept-Encoding": "identity",
      "Accept-Language": "en",
      "Content-Type": "application/xml; charset=utf-8",
      "Content-Length": "432",
      "Host": "xxx",
      "Connection": "Keep-Alive",
      "Cookie": "oc_sessionPassphrase=somePassphrase; ocoybz17zi9o=1ev0ee7pcbrosurr3dbumse1ti; cookie_test=test"
    },
    "info": {
      "id": "5d955519-a643-4524-baf0-1894d88b55e9",
      "method": "PROPFIND",
      "url": "https://xxx/remote.php/dav/files/user/CameraUpload/IMG_20240802_155756.jpg"
    }
  }
}

and the response:

D: 2024-08-02 17:14:17:003(LogInterceptor.kt:133)RESPONSE 5d955519-a643-4524-baf0-1894d88b55e9 
{
  "response": {
    "body": {
      "data": "",
      "length": 0
    },
    "headers": {
      "Date": "Fri, 02 Aug 2024 15:14:16 GMT",
      "Server": "Apache",
      "X-Content-Type-Options": "nosniff",
      "X-XSS-Protection": "0",
      "X-Robots-Tag": "none",
      "X-Frame-Options": "SAMEORIGIN",
      "X-Download-Options": "noopen",
      "X-Permitted-Cross-Domain-Policies": "none",
      "Expires": "Thu, 19 Nov 1981 08:52:00 GMT",
      "Cache-Control": "no-store, no-cache, must-revalidate",
      "Pragma": "no-cache",
      "Content-Security-Policy": "default-src 'self'; script-src 'self' 'unsafe-eval'; style-src 'self' 'unsafe-inline'; frame-src *; img-src * data: blob:; font-src 'self' data:; media-src *; connect-src *",
      "Location": "http://xxx/apps/files/",
      "Content-Length": "0",
      "Content-Type": "text/html; charset=UTF-8",
      "Set-Cookie": "oc_sessionPassphrase=somePassphrase; expires=Fri, 02-Aug-2024 15:34:16 GMT; Max-Age=1200; path=/; HttpOnly; SameSite=Strict",
      "Strict-Transport-Security": "max-age=31536000; preload",
      "Feature-Policy": "sync-xhr 'self'",
      "Keep-Alive": "timeout=5, max=97",
      "Connection": "Keep-Alive"
    },
    "info": {
      "id": "5d955519-a643-4524-baf0-1894d88b55e9",
      "method": "PROPFIND",
      "reply": {
        "cached": false,
        "duration": 752,
        "durationString": "duration(0h, 0min, 0s, 752ms)",
        "status": 404,
        "version": "http/1.1"
      },
      "url": "https://xxx/remote.php/dav/files/yyy/CameraUpload/IMG_20240802_155756.jpg"
    }
  }
}

the "status":404 means that there is no item with same name in same location in the server. So, we can push the file with its own name ✅ . Next line tells explicitly:

D: 2024-08-02 17:14:17:006(CheckPathExistenceRemoteOperation.kt:71)Existence check for https://xxx/remote.php/dav/files/yyy/CameraUpload/IMG_20240802_155756.jpg finished with HTTP status 404(FAIL)

Next: OCTransfer (2471) changes status to TRANSFER_IN_PROGRESS. Things start to move. The original file is copied first in /tmp to help to handle posible errors that could happen during the transfer. ✅

D: 2024-08-02 17:15:10:019(UploadFileFromContentUriWorker.kt:155)Upload info: OCTransfer(id=2471, localPath=/data/user/0/com.owncloud.android/files/owncloud/tmp/yyy@zzz/CameraUpload/IMG_20240802_155756.jpg, remotePath=/CameraUpload/IMG_20240802_155756.jpg, accountName=yyy@xxx, fileSize=7444368, status=TRANSFER_IN_PROGRESS, localBehaviour=COPY, forceOverwrite=false, transferEndTimestamp=null, lastResult=null, createdBy=ENQUEUED_AS_CAMERA_UPLOAD_PICTURE, transferId=null, spaceId=null)

Next: the file content is set as the body of the request that will send to the server:

D: 2024-08-02 17:16:11:862(FileRequestBody.kt:70)File with name IMG_20240802_155756.jpg and size 7444368 written in request body

Next: a PUT operation sends the file:

D: 2024-08-02 17:16:42:930(LogInterceptor.kt:67)REQUEST 2a242b62-3e9e-4639-a70f-22555acaeed9 
{
  "request": {
    "body": "One shot body --   Omitted",
    "headers": {
      "Authorization": "Basic [redacted]",
      "X-OC-Mtime": "1722607076",
      "OC-Total-Length": "7444368",
      "X-Request-ID": "2a242b62-3e9e-4639-a70f-22555acaeed9",
      "User-Agent": "Mozilla/5.0 (Android) ownCloud-android/4.3.1",
      "Accept-Encoding": "identity",
      "Accept-Language": "en",
      "Content-Length": "7444368",
      "Host": "xxx",
      "Connection": "Keep-Alive",
      "Cookie": "oc_sessionPassphrase=somePassphrase; ocoybz17zi9o=1ev0ee7pcbrosurr3dbumse1ti; cookie_test=test"
    },
    "info": {
      "id": "2a242b62-3e9e-4639-a70f-22555acaeed9",
      "method": "PUT",
      "url": "https://xxx/remote.php/dav/files/yyy/CameraUpload/IMG_20240802_155756.jpg"
    }
  }
}

and the response is successful ("status": 201) ✅

D: 2024-08-02 17:16:42:955(LogInterceptor.kt:133)RESPONSE 2a242b62-3e9e-4639-a70f-22555acaeed9 
{
  "response": {
    "body": {
      "data": "",
      "length": 0
    },
    "headers": {
      "Date": "Fri, 02 Aug 2024 15:14:18 GMT",
      "Server": "Apache",
      "X-Content-Type-Options": "nosniff",
      "X-XSS-Protection": "0",
      "X-Robots-Tag": "none",
      "X-Frame-Options": "SAMEORIGIN",
      "X-Download-Options": "noopen",
      "X-Permitted-Cross-Domain-Policies": "none",
      "Expires": "Thu, 19 Nov 1981 08:52:00 GMT",
      "Cache-Control": "no-store, no-cache, must-revalidate",
      "Pragma": "no-cache",
      "Content-Security-Policy": "default-src 'none';",
      "X-OC-MTime": "accepted",
      "OC-FileId": "00018076ocoybz17zi9o",
      "Content-Length": "0",
      "ETag": "\"d4bcf1d9bff859a5fc08bc1c0dba4633\"",
      "OC-ETag": "\"d4bcf1d9bff859a5fc08bc1c0dba4633\"",
      "Content-Type": "text/html; charset=UTF-8",
      "Set-Cookie": "oc_sessionPassphrase=somePassphrase; expires=Fri, 02-Aug-2024 15:34:18 GMT; Max-Age=1200; path=/; HttpOnly; SameSite=Strict",
      "Strict-Transport-Security": "max-age=31536000; preload",
      "Feature-Policy": "sync-xhr 'self'",
      "Keep-Alive": "timeout=5, max=91",
      "Connection": "Keep-Alive"
    },
    "info": {
      "id": "2a242b62-3e9e-4639-a70f-22555acaeed9",
      "method": "PUT",
      "reply": {
        "cached": false,
        "duration": 145229,
        "durationString": "duration(0h, 2min, 145s, -119771ms)",
        "status": 201,
        "version": "http/1.1"
      },
      "url": "https://xxx/remote.php/dav/files/yyy/CameraUpload/IMG_20240802_155756.jpg"
    }
  }
}

so, at this point: file was detected as new, name is collision-free, and file is sent to the server successfully 💯 ✅ :

D: 2024-08-02 17:16:42:966(UploadFileFromFileSystemOperation.kt:130)File uploaded successfully. New etag for file IMG_20240802_155756.jpg is d4bcf1d9bff859a5fc08bc1c0dba4633
I: 2024-08-02 17:16:42:967(UploadFileFromFileSystemOperation.kt:89)Upload of /data/user/0/com.owncloud.android/files/owncloud/tmp/yyy@xxx/CameraUpload/IMG_20240802_155756.jpg to /CameraUpload/IMG_20240802_155756.jpg - HTTP status code: 207

at 2024-08-02 17:16:42:967 everything should be done, but, at 2024-08-02 17:20:22:705 everything starts again:

D: 2024-08-02 17:20:22:705: sent a request to check if the file exists in server
D: 2024-08-02 17:20:22:711: response with 207 because file exist (it was created above)
D: 2024-08-02 17:20:22:714: check existence of file: file exists -> name collision:

D: 2024-08-02 17:20:23:424(UploadFileFromContentUriWorker.kt:248)Name collision detected, let's rename it to /CameraUpload/IMG_20240802_155756 (1).jpg

After reviewing what's going on in the middle, nothing bad appears there. There is no background process execution that scans the camera folder to get new pics... at least, nothing logged.

Next is the following error:

I: 2024-08-02 17:20:24:585(UploadFileFromFileSystemOperation.kt:89)Upload of /data/user/0/com.owncloud.android/files/owncloud/tmp/yyy@xxx/CameraUpload/IMG_20240802_155756.jpg to /CameraUpload/IMG_20240802_155756 (1).jpg - HTTP status code: 207
D: 2024-08-02 17:20:24:586(OwnCloudClient.java:129)Executing in request with id 2a5fd15d-a100-4f83-94ad-3428e53c805c
E: 2024-08-02 17:20:24:252(FileRequestBody.kt:72)java.io.FileNotFoundException: /data/user/0/com.owncloud.android/files/owncloud/tmp/[email protected]/CameraUpload/IMG_20240802_155756.jpg: open failed: ENOENT (No such file or directory)
	at libcore.io.IoBridge.open(IoBridge.java:496)
	at java.io.FileInputStream.<init>(FileInputStream.java:159)
	at okio.Okio__JvmOkioKt.source(JvmOkio.kt:182)
	at okio.Okio.source(Unknown Source:1)
	at com.owncloud.android.lib.common.network.FileRequestBody.writeTo(FileRequestBody.kt:57)
	at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:59)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at com.owncloud.android.lib.common.http.DummyInterceptor.intercept(DummyInterceptor.kt:30)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at com.owncloud.android.lib.common.http.logging.LogInterceptor.intercept(LogInterceptor.kt:56)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
	at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
	at at.bitfire.dav4jvm.DavOCResource$put$2.invoke(DavOCResource.kt:64)
	at at.bitfire.dav4jvm.DavOCResource$put$2.invoke(DavOCResource.kt:12)
	at at.bitfire.dav4jvm.DavResource.followRedirects(DavResource.kt:452)
	at at.bitfire.dav4jvm.DavOCResource.put(DavOCResource.kt:58)
	at com.owncloud.android.lib.common.http.methods.webdav.PutMethod.onDavExecute(PutMethod.kt:44)
	at com.owncloud.android.lib.common.http.methods.webdav.DavMethod.onExecute(DavMethod.kt:62)
	at com.owncloud.android.lib.common.http.methods.HttpBaseMethod.execute(HttpBaseMethod.kt:75)
	at com.owncloud.android.lib.common.OwnCloudClient.saveExecuteHttpMethod(OwnCloudClient.java:138)
	at com.owncloud.android.lib.common.OwnCloudClient.executeHttpMethod(OwnCloudClient.java:107)
	at com.owncloud.android.lib.resources.files.UploadFileFromFileSystemOperation.uploadFile(UploadFileFromFileSystemOperation.kt:122)
	at com.owncloud.android.lib.resources.files.UploadFileFromFileSystemOperation.run(UploadFileFromFileSystemOperation.kt:88)
	at com.owncloud.android.lib.common.operations.RemoteOperation.runOperation(RemoteOperation.java:264)
	at com.owncloud.android.lib.common.operations.RemoteOperation.execute(RemoteOperation.java:229)
	at com.owncloud.android.workers.UploadFileFromContentUriWorker$uploadPlainFile$2.invoke(UploadFileFromContentUriWorker.kt:286)
	at com.owncloud.android.workers.UploadFileFromContentUriWorker$uploadPlainFile$2.invoke(UploadFileFromContentUriWorker.kt:286)
	at com.owncloud.android.data.RemoteOperationHandlerKt.executeRemoteOperation(RemoteOperationHandler.kt:80)
	at com.owncloud.android.workers.UploadFileFromContentUriWorker.uploadPlainFile(UploadFileFromContentUriWorker.kt:286)
	at com.owncloud.android.workers.UploadFileFromContentUriWorker.uploadDocument(UploadFileFromContentUriWorker.kt:269)
	at com.owncloud.android.workers.UploadFileFromContentUriWorker.doWork(UploadFileFromContentUriWorker.kt:121)
	at androidx.work.CoroutineWorker$startWork$1.invokeSuspend(CoroutineWorker.kt:68)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677)
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664)
Caused by: android.system.ErrnoException: open failed: ENOENT (No such file or directory)
	at libcore.io.Linux.open(Native Method)
	at libcore.io.ForwardingOs.open(ForwardingOs.java:167)
	at libcore.io.BlockGuardOs.open(BlockGuardOs.java:252)
	at libcore.io.ForwardingOs.open(ForwardingOs.java:167)
	at android.app.ActivityThread$AndroidOs.open(Unknown Source:15)
	at libcore.io.IoBridge.open(IoBridge.java:482)
	... 46 more

that seems to be related with the origin of the file. That's only a guess, but i think this error does not cause the problem. Just after that, a PUT is sent and...

I: 2024-08-02 17:20:24:585(UploadFileFromFileSystemOperation.kt:89)Upload of /data/user/0/com.owncloud.android/files/owncloud/tmp/yyy@xxx/CameraUpload/IMG_20240802_155756.jpg to /CameraUpload/IMG_20240802_155756 (1).jpg - HTTP status code: 207

so, we have here the duplication. But there is nothing that triggers it. My new guess:

could it be a race condition? kinda concurrency problem. We'll need to take a look, probably with another eyes.

[jsiddall]

In case it helps I also uploaded my log file that had triplicates, and confirmed that you can see the file getting uploaded the third time as ...(2).jpg after collisions were detected on the previous 2 uploads of the same file.

[DerFuz]

@jesmrec Thanks for your thorough analysis. I am happy to end with almost the same conclusion as you.

Next: OCTransfer (2471) changes status to TRANSFER_IN_PROGRESS. Things start to move. The original file is copied first in /tmp to help to handle posible errors that could happen during the transfer. ✅

Why can't I find a second OCTransfer object for 2470 then (with tmp as localPath)?

[jesmrec]

Why can't I find a second OCTransfer object for 2470 then (with tmp as localPath)?

it's weird because the uploaded file was somewhen in /tmp, as any uploaded file. I have no explanation for that at this point.

[JuancaG05]

Hi @DerFuz! Thanks for your collaboration, you did a great job with your findings 😃.

About this point:

The OCTransfer-object of the successful upload (single image) sources the Camera directly via the localpath (localPath=content://com.android.externalstorage.documents/tree/...), while the 3 other images have 2 OCTransfer-objects each (one from camerapath and one from a temp directory inside the app (localPath=/data/user/0/com.owncloud.android/files/owncloud/tmp/...) ← would explain duplicates

Could be a great idea. In the new 4.4.0-beta.1, we made some changes and now the localPath field doesn't change ever, we keep there the original path in the device and in a newly created field, the temporal path. Could you check if the duplicates problem can still be reproduced in this new version? You can find it in the Beta Program in Play Store, or installing the APK uploaded here: https://github.com/owncloud/android/releases/tag/v4.4.0-beta.1

EDIT: It seems that localPath keeps changing yet despite the new field. We'll address this in a new issue. In any case, you can try the beta version and give us your feedback 👍

[jesmrec]

Will check after #4461