ServerUploader issue #2: failedToGetDeferredUploads

[crspybits]

In the server log, I'm getting: failedToGetDeferredUploads.

I started noticing this after running some iOSBasics tests, and one of them was consistently failing.

Here are the basics in the server log:

[2020-11-27T06:29:03.295Z] [DEBUG] [PeriodicUploader.swift:31 schedule()] PeriodicUploader: About to run Uploader
[2020-11-27T06:29:03.817Z] [DEBUG] [DebugAlloc.swift:22 create()] [CREATE: Uploader] Created: 8142; destroyed: 8140
[2020-11-27T06:29:03.952Z] [DEBUG] [Uploader.swift:102 deinit] Uploader: deinit
[2020-11-27T06:29:03.958Z] [DEBUG] [DebugAlloc.swift:27 destroy()] [DESTROY: Uploader] Created: 8142; destroyed: 8141
[2020-11-27T06:29:03.965Z] [INFO] [Database.swift:94 close()] CLOSING DB CONNECTION: opened: 9203; closed: 9203
[2020-11-27T06:29:03.983Z] [DEBUG] [Uploader.swift:138 run()] Attempting to get lock...
[2020-11-27T06:29:05.852Z] [INFO] [Database.swift:57 init(showStartupInfo:)] DB CONNECTION STATS: opened: 9204; closed: 9203
[2020-11-27T06:29:05.915Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: SELECT GET_LOCK('Uploader', 0)
[2020-11-27T06:29:06.464Z] [DEBUG] [Uploader.swift:144 run()] Got lock!
[2020-11-27T06:29:06.467Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: select * from DeferredUpload where status IN ('pendingDeletion')
[2020-11-27T06:29:06.670Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: SET TRANSACTION ISOLATION LEVEL READ COMMITTED;
[2020-11-27T06:29:06.698Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: START TRANSACTION;
[2020-11-27T06:29:06.702Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: select * from Upload where deferredUploadId = 251
[2020-11-27T06:29:06.706Z] [DEBUG] [Repository.swift:109 lookup(key:modelInit:)] No object found!
[2020-11-27T06:29:06.709Z] [ERROR] [Uploader.swift:404 prune()] Could not lookup: deferredUploadId(251)
[2020-11-27T06:29:06.711Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: ROLLBACK;
[2020-11-27T06:29:06.714Z] [ERROR] [Uploader.swift:154 run()] Failed pruning file uploads.
[2020-11-27T06:29:06.715Z] [DEBUG] [Database.swift:281 query(_:)] DB QUERY: SELECT RELEASE_LOCK('Uploader')
[2020-11-27T06:29:06.719Z] [ERROR] [PeriodicUploader.swift:38 schedule()] failedToGetDeferredUploads

[crspybits]

I believe the issue here stems, at least in part, from the user deletion process. In each client test case, the test user is removed and then added again. On the server, when a user is removed Upload records are removed, but currently, DeferredUpload records are not removed.

The problem in the Uploader (see above) occurs because an Upload record with a specific deferredUploadId could not be found. This can occur because the Uploader fetches (in its correct operation) DeferredUpload records with status = pendingDeletion across users-- even users that have been deleted. It then tries to lookup Upload records for those DeferredUpload's. However, for deleted users, those Upload records have been deleted.

[crspybits]

I'm putting in a fix for this bug and #8 by deleting DeferredUpload records for the user when the user is deleted. I'm going to leave both of these open for a while because this issue is hard to reproduce and I want to try to make sure it's solved.