Rod has *lots* of pending uploads

[crspybits]

Rod has 185 pending uploads. How did that happen? I see this in the logs he's sent.

[crspybits]

Just got a fresh set of logs from Rod, this time with a status field from each UploadFileTracker. The UploadObjectTracker's are each in one of two states:

1. All files for the UploadObjectTracker are in an uploading state (i.e., none of the uploads are completed).

2. All files for the UploadObjectTracker are in an notStarted state.

I think I don't have a means of restarting uploads when somehow they are all in an uploading state but somehow the upload has failed. E.g., my UploadFileTrackers don't have some means of timing out.

I also think that I'm limiting the number of UploadObjectTrackers that can have files in an uploading state.

I need to look into the code and confirm both of these.

[crspybits]

Indeed, currently only five UploadObjectTracker's can be pending, in uploading state. See maxConcurrentFileGroupUploads in iOSBasics-- https://github.com/SyncServerII/iOSBasics.git

And that is how many UploadObjectTracker's have UploadFileTracker's in an uploading state in Rod's logs.

[crspybits]

On the first point, I'm looking at triggerUploads() in iOSBasics. There are two parts to that:

    func triggerUploads() throws {
        // Retry any upload objects that are still .uploading, but that have files that are not yet started.
        try triggerRetryFileUploads()
        
        // Trigger other upload objects that are .notStarted -- these will either be completely new uploads or uploads that were already tried before.
        try triggerQueuedUploads()
    }

triggerRetryFileUploads(): Retry uploads if at least one of the component uploads is in a .notStarted state. This will not apply because all of the files in each object are in an uploading state.

triggerQueuedUploads: Trigger new uploads, if the limit hasn't been reached. In Rod's case, the limit has been reached. So this will not apply.

[crspybits]

What happens if the same upload is retried, and it already happened? I.e., our record on the client has a status of uploading but it actually succeeded as a server request but we just didn't get the result of the request. What kind of response will we see on the retry? Need to try this as a test case.

[crspybits]

Upload retry cases:

1. If an upload is retried and it is a duplicate of a file in the current upload batch, you get a UploadFileResponse with a UploadsFinished value of duplicateFileUpload. This is not a failure, but I need to make sure iOSBasics is treating it as a success. The context is: That the upload batch has not yet completed. I believe this will not be useful in the case of batch size of one where the upload completed but the client just didn't get the response. Or if the batch size > 1 but all were completed, and the client just didn't get (say) the last response.

2. If a vN upload is retried, and its batch was entirely completed before hand, this is not a failure. The upload will just be repeated. vN uploads have change resolvers, and these change resolvers can deal with repeats. Some test code would still be good to ensure this behavior is operating as expected.

3. Similarly, what if a v0 upload is retried and its batch was entirely completed beforehand?

[crspybits]

Test to try-- to generate a concrete hypothesis as to why Rod got into this state.

1. Put device (e.g., iPhone) into offline mode. i.e., airplane mode.

2. Enqueue an upload of an object or comment.

3. Wait for a few hours-- for the access token to expire.

4. Restart the server to ensure that its current cache of access tokens/users for authorization is flushed.

5. Bring client device back online and do a sync from the Albums screen.

Expect: That the uploads will not complete. BUT: Will they fail and get retried? Will they only be in an .uploading state?

[crspybits]

While this is anecdotal and just evidence of a single case, I'd like to see if any of the requests in:

All files for the UploadObjectTracker are in an uploading state (i.e., none of the uploads are completed). (see this link above) made any progress on the server (e.g., if the client just didn't get a response).

This is by way of seeing how much effort really ought to be put on different kinds of error handling and recovery in iOSBasics.

2021-08-02 22:37:11.861 [Notice] [main] [SettingsScreenModel.swift:109] addAttachments(vc:) > Pending Uploads: UploadObjectTracker: fileGroupUUID: AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7; v0Upload: Optional(true); batchUUID: A4649560-A20E-4F49-9ABB-CEE3947C04CD:
	UploadFileTracker: fileUUID: 1B680C09-3B8E-486F-83FC-67993532DF17; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 3
	UploadFileTracker: fileUUID: 75C95CC9-BF03-4B1D-AD2D-C5B1BE30AD11; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3
	UploadFileTracker: fileUUID: 218039D4-6668-414D-949C-831AB81F3DC6; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3

Each of these three files appear in the FileIndex on the server, as version 0. It appears this is the case of the successful upload report just not making it to the client. There is no record of these files in the Upload table.

UploadObjectTracker: fileGroupUUID: 5419CF0E-696F-4636-97EB-D758D3088FC6; v0Upload: Optional(true); batchUUID: 01D6D804-4C60-41FB-A8D7-5E01E6ACDE47:
	UploadFileTracker: fileUUID: 8002F0B6-5E66-4332-B83E-28075768B177; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 3
	UploadFileTracker: fileUUID: C0F990AD-8E46-46AE-A97B-3D3270F0EF78; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3
	UploadFileTracker: fileUUID: 85F13EAF-035C-4E94-B571-F65EC9394A71; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3

This is a similar situation. Each of these files appears in the FileIndex. But the comment file is now at version 1-- someone else apparently having added a comment. There is no record of these files in the Upload table.

UploadObjectTracker: fileGroupUUID: BB7BA013-4E00-4A33-8028-9A0F20189880; v0Upload: Optional(false); batchUUID: 3A788599-CF53-4328-912C-700491A37FF9:
	UploadFileTracker: fileUUID: 130E7E3F-AFF9-4548-A52F-FDAB3CD1E296; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 1

This is clearly not a v0 upload. As expected, there are files for this file group in the FileIndex table. There is no record of these files in the Upload table. There are rows for this file group in the DeferredUpload table. And a record for this batchUUID. It is completed.

UploadObjectTracker: fileGroupUUID: 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571; v0Upload: Optional(true); batchUUID: 04353B49-2BFC-43AE-A9BA-E87AEB06D22B:
	UploadFileTracker: fileUUID: 7A57C89F-73E4-4E97-9B2B-DA6CAB954215; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 4
	UploadFileTracker: fileUUID: FAE1DD16-6354-4814-BC6A-0AF8DFD52340; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 4
	UploadFileTracker: fileUUID: 5E0531A2-6E86-435E-859B-D4A13F3C7F54; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 4
	UploadFileTracker: fileUUID: B22449D3-BCAB-4E93-8B4A-74DCFC2E6C34; fileVersion: nil; status: uploading; uploadIndex: 4; uploadCount: 4

Each of these files appears in the FileIndex. Some files have version > 0. There is no record of these files in the Upload table.

UploadObjectTracker: fileGroupUUID: 731B8A15-44D4-4CB7-B6C8-ACFBBE17FD6F; v0Upload: Optional(false); batchUUID: 52B3140A-BAE9-4051-9D02-42C93213CA2E:
	UploadFileTracker: fileUUID: DFA1A574-7D20-40B1-8652-42B0E808FF5C; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 1

This is clearly not a v0 upload. As expected, there are files for this file group in the FileIndex table. There is no record of these files in the Upload table. There is a row for this file group in the DeferredUpload table for this batchUUID. It is completed.

[crspybits]

Some of Rod's pending uploads have missing files:

1. UploadObjectTracker: fileGroupUUID: AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7; v0Upload: Optional(true); batchUUID: A4649560-A20E-4F49-9ABB-CEE3947C04CD:
   UploadFileTracker: fileUUID: 1B680C09-3B8E-486F-83FC-67993532DF17; fileVersion: nil; status: uploaded; uploadIndex: 1; uploadCount: 3; expiry: Optional(2021-08-11 00:17:21 +0000); canReadFile: Optional(true)
   UploadFileTracker: fileUUID: 75C95CC9-BF03-4B1D-AD2D-C5B1BE30AD11; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)
   UploadFileTracker: fileUUID: 218039D4-6668-414D-949C-831AB81F3DC6; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true)

2. UploadObjectTracker: fileGroupUUID: 5419CF0E-696F-4636-97EB-D758D3088FC6; v0Upload: Optional(true); batchUUID: 01D6D804-4C60-41FB-A8D7-5E01E6ACDE47:
   UploadFileTracker: fileUUID: 8002F0B6-5E66-4332-B83E-28075768B177; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true)
   UploadFileTracker: fileUUID: C0F990AD-8E46-46AE-A97B-3D3270F0EF78; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)
   UploadFileTracker: fileUUID: 85F13EAF-035C-4E94-B571-F65EC9394A71; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true)

3. UploadObjectTracker: fileGroupUUID: 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571; v0Upload: Optional(true); batchUUID: 04353B49-2BFC-43AE-A9BA-E87AEB06D22B:
   UploadFileTracker: fileUUID: 7A57C89F-73E4-4E97-9B2B-DA6CAB954215; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true)
   UploadFileTracker: fileUUID: FAE1DD16-6354-4814-BC6A-0AF8DFD52340; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true)
   UploadFileTracker: fileUUID: 5E0531A2-6E86-435E-859B-D4A13F3C7F54; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)
   UploadFileTracker: fileUUID: B22449D3-BCAB-4E93-8B4A-74DCFC2E6C34; fileVersion: nil; status: uploading; uploadIndex: 4; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)

[crspybits]

Specific UploadFileTracker's:

UploadFileTracker: fileUUID: 75C95CC9-BF03-4B1D-AD2D-C5B1BE30AD11; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)

UploadFileTracker: fileUUID: C0F990AD-8E46-46AE-A97B-3D3270F0EF78; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)

UploadFileTracker: fileUUID: 5E0531A2-6E86-435E-859B-D4A13F3C7F54; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)

UploadFileTracker: fileUUID: B22449D3-BCAB-4E93-8B4A-74DCFC2E6C34; fileVersion: nil; status: uploading; uploadIndex: 4; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false)

Each of these are from v0 uploads.

[crspybits]

fileUUID: 75C95CC9-BF03-4B1D-AD2D-C5B1BE30AD11 is in the FileIndex. It is an image.

fileUUID: C0F990AD-8E46-46AE-A97B-3D3270F0EF78 is in the FileIndex. It is an image.

fileUUID: 5E0531A2-6E86-435E-859B-D4A13F3C7F54 is in the FileIndex. It is an url.

fileUUID: B22449D3-BCAB-4E93-8B4A-74DCFC2E6C34 is in the FileIndex. It is an image.

[crspybits]

File group AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7: Not marked as deleted in FileGroup table on server.

File group 5419CF0E-696F-4636-97EB-D758D3088FC6: Not marked as deleted in FileGroup table on server.

File group 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571: Not marked as deleted in FileGroup table on server.

[crspybits]

Both images and urls are marked as immutable when uploaded. i.e., a copy is not made when uploaded, the actual user file is uploaded.

[crspybits]

File group AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7: sharing group: 60A52DB4-39A8-486A-976C-A1DE0C922919; sharing group not deleted; name: "🎲♦� ♠� ��♣�🎲 random"

File group 5419CF0E-696F-4636-97EB-D758D3088FC6: sharing group: 15BB1FAE-D5E5-4694-AE36-04D003802E18; sharing group not deleted; name: "� chicken is the question "

File group 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571: sharing group: 60A52DB4-39A8-486A-976C-A1DE0C922919; sharing group not deleted; name: "🎲♦� ♠� ��♣�🎲 random"

[crspybits]

Most recent debugging info:

File group AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7:
UploadObjectTracker: fileGroupUUID: AA5AFBA2-C366-4F83-B881-FFEF6C8DCEA7; v0Upload: Optional(true); batchUUID: A4649560-A20E-4F49-9ABB-CEE3947C04CD; deletedLocally: Optional(false); deletedOnServer: Optional(false)
UploadFileTracker: fileUUID: 1B680C09-3B8E-486F-83FC-67993532DF17; fileVersion: nil; status: uploaded; uploadIndex: 1; uploadCount: 3; expiry: Optional(2021-08-11 00:17:21 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: 75C95CC9-BF03-4B1D-AD2D-C5B1BE30AD11; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false); mimeType: jpeg; uploadCopy: false; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: 218039D4-6668-414D-949C-831AB81F3DC6; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil

File group 5419CF0E-696F-4636-97EB-D758D3088FC6:
UploadObjectTracker: fileGroupUUID: 5419CF0E-696F-4636-97EB-D758D3088FC6; v0Upload: Optional(true); batchUUID: 01D6D804-4C60-41FB-A8D7-5E01E6ACDE47; deletedLocally: Optional(false); deletedOnServer: Optional(false)
UploadFileTracker: fileUUID: 8002F0B6-5E66-4332-B83E-28075768B177; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: C0F990AD-8E46-46AE-A97B-3D3270F0EF78; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false); mimeType: jpeg; uploadCopy: false; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: 85F13EAF-035C-4E94-B571-F65EC9394A71; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 3; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil

File group 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571:
UploadObjectTracker: fileGroupUUID: 3C66CDD4-DCBF-478B-BDA2-94BAC12F0571; v0Upload: Optional(true); batchUUID: 04353B49-2BFC-43AE-A9BA-E87AEB06D22B; deletedLocally: Optional(false); deletedOnServer: Optional(false)
UploadFileTracker: fileUUID: 7A57C89F-73E4-4E97-9B2B-DA6CAB954215; fileVersion: nil; status: uploading; uploadIndex: 1; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: FAE1DD16-6354-4814-BC6A-0AF8DFD52340; fileVersion: nil; status: uploading; uploadIndex: 2; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(true); mimeType: text; uploadCopy: true; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: 5E0531A2-6E86-435E-859B-D4A13F3C7F54; fileVersion: nil; status: uploading; uploadIndex: 3; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false); mimeType: url; uploadCopy: false; deletedLocally: nil; deletedOnServer: nil
UploadFileTracker: fileUUID: B22449D3-BCAB-4E93-8B4A-74DCFC2E6C34; fileVersion: nil; status: uploading; uploadIndex: 4; uploadCount: 4; expiry: Optional(2021-08-11 04:17:00 +0000); canReadFile: Optional(false); mimeType: jpeg; uploadCopy: false; deletedLocally: nil; deletedOnServer: nil