MyExpenses
MyExpenses copied to clipboard
mtotschnig
WebDav backend locked with only one installation
I have recently started using MyExpenses and setup webdav synchronization as a form of backups to my server. I started getting notifications with the following:
Starting synchronization for account <account-name>. Remote backend is locked or cannot be locked
Since I have only one installation, I am not sure why it would be locked. Any thoughts on how to recover? Thank you.
My Expenses always tries to "lock" the backend during synchronization, since it does not know if there are other devices syncing with the same backend. The error then means, that either a previous synchronization failed to unlock the backend, or that another problem is encountered during locking. Could you
- report, here or to [email protected], which WebDAV server you are using
- in the Settings switch on Advanced -> Debug -> Write debugging information into system log. Then during sync the error should be traced into a file at path Android/data/org.totschnig.myexpenses/files/log/SyncAdapter-latest.log
I am using NextCloud as the WebDAV server. Here are the logs:
2019-09-24 11:43:14,216 INFO [SyncAdapterThread-1] onPerformSync Bundle[{ignore_settings=true, uuid=e88f4c42-5432-465a-1234-f7d0144f378a, force=true, expedited=true}]
2019-09-24 11:43:15,371 INFO [SyncAdapterThread-1] Starting synchronization for account MyBank Checking.
2019-09-24 11:43:17,008 WARN [SyncAdapterThread-1] java.io.InterruptedIOException: interrupted
at l.t.e(Timeout.java:5)
at l.l$a.a(Okio.java:2)
at l.a$a.a(AsyncTimeout.java:6)
at l.m.flush(RealBufferedSink.java:3)
at k.i0.i.j.s(Http2Writer.java:6)
at k.i0.i.g.a(Http2Connection.java:51)
at k.i0.i.g.u(Http2Connection.java:1)
at k.i0.f.c.a(RealConnection.java:83)
at k.i0.f.c.a(RealConnection.java:76)
at k.i0.f.c.a(RealConnection.java:15)
at k.i0.f.g.a(StreamAllocation.java:57)
at k.i0.f.g.a(StreamAllocation.java:13)
at k.i0.f.g.a(StreamAllocation.java:6)
at k.i0.f.a.intercept(ConnectInterceptor.java:5)
at k.i0.g.g.a(RealInterceptorChain.java:11)
at k.i0.g.g.a(RealInterceptorChain.java:2)
at k.i0.e.a.intercept(CacheInterceptor.java:22)
at k.i0.g.g.a(RealInterceptorChain.java:11)
at k.i0.g.g.a(RealInterceptorChain.java:2)
at k.i0.g.a.intercept(BridgeInterceptor.java:22)
at k.i0.g.g.a(RealInterceptorChain.java:11)
at k.i0.g.j.intercept(RetryAndFollowUpInterceptor.java:9)
at k.i0.g.g.a(RealInterceptorChain.java:11)
at k.i0.g.g.a(RealInterceptorChain.java:2)
at k.a0.a(RealCall.java:19)
at k.a0.l(RealCall.java:9)
at at.bitfire.dav4android.LockableDavResource.mkColWithLock(LockableDavResource.java:6)
at org.totschnig.myexpenses.sync.l1.f.b(WebDavClient.java:2)
at org.totschnig.myexpenses.sync.j1.a(WebDavBackendProvider.java:6)
at org.totschnig.myexpenses.sync.g1.onPerformSync(SyncAdapter.java:60)
at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)
2019-09-24 11:43:17,009 INFO [SyncAdapterThread-1] Error while setting up remote account.
2019-09-24 11:53:21,378 INFO [SyncAdapterThread-2] onPerformSync Bundle[{ignore_settings=true, uuid=e88f4c42-5432-465a-1234-f7d0144f378a, force=true, expedited=true}]
2019-09-24 11:53:22,261 INFO [SyncAdapterThread-2] Starting synchronization for account MyBank Checking.
2019-09-24 11:53:24,303 INFO [SyncAdapterThread-2] ExistingLockTocken: null
2019-09-24 11:53:24,976 WARN [SyncAdapterThread-2] java.io.IOException: at.bitfire.dav4android.exception.NotFoundException: 404
at org.totschnig.myexpenses.sync.j1.h(WebDavBackendProvider.java:3)
at org.totschnig.myexpenses.sync.b1.c(AbstractSyncBackendProvider.java:13)
at org.totschnig.myexpenses.sync.j1.c(WebDavBackendProvider.java:3)
at org.totschnig.myexpenses.sync.g1.onPerformSync(SyncAdapter.java:61)
at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)
Caused by: at.bitfire.dav4android.exception.NotFoundException: 404
at at.bitfire.dav4android.DavResource.checkStatus(DavResource.java:9)
at at.bitfire.dav4android.DavResource.checkStatus(DavResource.java:1)
at at.bitfire.dav4android.DavResource.put(DavResource.java:9)
at org.totschnig.myexpenses.sync.j1.h(WebDavBackendProvider.java:2)
... 4 more
2019-09-24 11:53:24,977 INFO [SyncAdapterThread-2] Remote backend is locked or cannot be locked.
What I read from this log is that at 11:43 the attempt to create a folder for the account failed with a timeout. Then at 11:53, it seemed to create the folder, but then was not able to create the lock token, indicating that the folder would not exist, so I am puzzled how to interpret the situation. Could you verify if a folder (its name would be a UUID) has been created on your server. Would it be possible for you to grant me access to a testing account on your server? Unfortunately I do not have access to a WebDAV server at the moment.
I succeeded setting up a Docker NextCloud instance (16.0.4) and could verify that it works with current MyExpenses. I am still wondering what happened in your case.
That folder does exist, as well as two more for my other accounts.
In it there is a IMPORTANT_INFORMATION.txt and metadata.json containing some basic information about the account. There are not any files that would seem to contain transaction information.
I also have MyExpenses configured to copy backup zips to webdav. That is working successfully.
I would say this issue is low priority since the full backups through webdav are functional, and I don't have another device I want to use this on right now. So it's up to you how we proceed. Happy to continue debugging with you if you would like to.
Hello, I encounter a similar issue but as I would like to sync two devices — to share the view on common expenses — this is blocking.
This is my configuration and setup:
- Fresh new install of My Expenses 3.3.7 (revision 515) from F-Droid on two devices with a pro license,
- Encrypted Nextcloud 23.0.2 (hosted at Zaclys),
- 3 repositories created: 2 for different accounts synchronization and 1 for backup synchronization.
I created 2 accounts on my device A, added operations to them and configured the 2 synchronizations. On the device B I removed the default account and configured the 2 synchronizations.
What I got:
- On device A, I get the same error as mentioned in the first message. This error applies for each account meant to be synced.
- On Nextcloud, the repositories contain each a new repository with a 'random' name with letters, figures and dashes, containing two files : IMPORTANT_INFORMATION.txt and metadata.json
- On device B, the accounts are created through the synchronization, but remain empty.
I checked the debugging option but my repository Android/data remains empty :-( Here is the detail of a message visible in the notification (in French in my case), in reversed the order as the notification is filled bottom-up: Démarrage de la synchronisation pour le compte Cartes. Le serveur à distance est verrouillé ou ne peut pas être verrouillé. Démarrage de la synchronisation pour le compte Cartes. Erreur lors de la configuration du compte distant Démarrage de la synchronisation pour le compte Cartes. Erreur lors de la synchronisation des modifications avec le serveur. Erreur lors de la suppression du verruoillage du serveur à distance. Démarrage de la synchronisation pour le compte Cartes. Thanks in advance!
Thank you for the report. Unfortunately WebDAV sync is completely broken in version 3.3.7. I already pushed a fix with tag 3.3.7.1 and hope that FDroid will pick it up, and that it gets through review on Play ASAP.
I'm getting this same "Remote backend is locked or cannot be locked" message with Nextcloud as the backend. I have 3 accounts and only one of them is having this problem. The other two can sync without any problem.
When I check the WebDAV folder, I can see the three folders and I can identify which one is causing trouble by peeking at the metadata.json file. I see 4 json files in there (_1 through _4). I have 6 tranactions and the other device only sees 4.
I don't see any lock files, which leads me to believe the issue is "cannot be locked" (as opposed to "is already locked". I tried uploading a file to the account folder to verify I still have permission to upload to that folder. It uploaded just fine and I have since moved the test file out of that directory.
The lock error comes up very quickly after the notification that it is starting synchronization for account. This makes me wonder if Nextcloud were slow, could it be that My Expenses is giving up too quickly? It doesn't make sense that one Nextcloud folder would be slow when the others are fast, but I'm running out of ideas.
My environment:
- My Expenses 3.4.0
- Nextcloud 24
If I delete the UUID folder and synchronize, might that get me out of this situation? It's all test data right now, so I am not worried about data loss, but I don't want to make the situation any worse. If it makes any difference, I did use 3.3.7 and run into this problem. I thought it was fixed in 3.3.7.1, but it's possible I was seeing another account succeed and mentally declaring victory. So I suppose it is possible the old version may have messed up the data in some way.
Debug logs:
2022-06-01 15:34:11,782 INFO [DefaultDispatcher-worker-6] Query for URL: content://org.totschnig.myexpenses/accounts/2
2022-06-01 15:34:11,786 INFO [DefaultDispatcher-worker-1] Query for URL: content://org.totschnig.myexpenses/accounts/3
2022-06-01 15:34:11,788 INFO [DefaultDispatcher-worker-6] Query for URL: content://org.totschnig.myexpenses/accounts/1
2022-06-01 15:34:11,853 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=2
2022-06-01 15:34:11,855 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:34:11,855 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:34:11,855 INFO [ModernAsyncTask #13] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=2§ions=1
2022-06-01 15:34:11,855 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=3
2022-06-01 15:34:11,860 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:34:11,865 INFO [ModernAsyncTask #23] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=1§ions=1
2022-06-01 15:34:11,866 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:34:11,867 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=3§ions=1
2022-06-01 15:34:11,867 INFO [ModernAsyncTask #23] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=1
2022-06-01 15:34:11,868 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:34:11,874 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:34:15,762 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:34:15,768 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:34:15,782 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:34:16,312 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:34:16,319 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:34:16,328 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:34:16,340 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:34:26,905 INFO [RxCachedThreadScheduler-63] Query for URL: content://org.totschnig.myexpenses/stale_images
2022-06-01 15:34:26,907 INFO [RxCachedThreadScheduler-62] Query for URL: content://org.totschnig.myexpenses/currencies
2022-06-01 15:37:10,194 INFO [DefaultDispatcher-worker-4] Query for URL: content://org.totschnig.myexpenses/accounts/2
2022-06-01 15:37:10,196 INFO [DefaultDispatcher-worker-2] Query for URL: content://org.totschnig.myexpenses/accounts/1
2022-06-01 15:37:10,197 INFO [DefaultDispatcher-worker-6] Query for URL: content://org.totschnig.myexpenses/accounts/3
2022-06-01 15:37:10,194 INFO [DefaultDispatcher-worker-4] Query for URL: content://org.totschnig.myexpenses/accounts/2
2022-06-01 15:37:10,196 INFO [DefaultDispatcher-worker-2] Query for URL: content://org.totschnig.myexpenses/accounts/1
2022-06-01 15:37:10,197 INFO [DefaultDispatcher-worker-6] Query for URL: content://org.totschnig.myexpenses/accounts/3
2022-06-01 15:37:10,249 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=2
2022-06-01 15:37:10,249 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=2
2022-06-01 15:37:10,250 INFO [ModernAsyncTask #13] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,250 INFO [ModernAsyncTask #13] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=2§ions=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,253 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=2§ions=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=1
2022-06-01 15:37:10,251 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,253 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,255 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,255 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,261 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=1§ions=1
2022-06-01 15:37:10,261 INFO [ModernAsyncTask #2] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=1§ions=1
2022-06-01 15:37:10,264 INFO [ModernAsyncTask #13] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=3
2022-06-01 15:37:10,264 INFO [ModernAsyncTask #13] Query for URL: content://org.totschnig.myexpenses/transactions/groups/NONE?account_id=3
2022-06-01 15:37:10,266 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,266 INFO [ModernAsyncTask #21] Query for URL: content://org.totschnig.myexpenses/transactions?extended=1&shortenComment=1
2022-06-01 15:37:10,268 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,268 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=3§ions=1
2022-06-01 15:37:10,268 INFO [ModernAsyncTask #1] Query for URL: content://org.totschnig.myexpenses/transactions
2022-06-01 15:37:10,268 INFO [ModernAsyncTask #4] Query for URL: content://org.totschnig.myexpenses/transactions/groups/MONTH?account_id=3§ions=1
2022-06-01 15:37:12,794 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:12,794 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:12,800 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:12,800 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:12,818 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:12,818 INFO [Binder:24851_E] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:13,564 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:13,564 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/settings
2022-06-01 15:37:13,573 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:13,573 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:13,579 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:13,579 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:13,586 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:13,586 INFO [Binder:24851_D] Query for URL: content://org.totschnig.myexpenses/accounts
2022-06-01 15:37:20,391 INFO [RxCachedThreadScheduler-62] Query for URL: content://org.totschnig.myexpenses/stale_images
2022-06-01 15:37:20,391 INFO [RxCachedThreadScheduler-62] Query for URL: content://org.totschnig.myexpenses/stale_images
2022-06-01 15:37:20,414 INFO [RxCachedThreadScheduler-63] Query for URL: content://org.totschnig.myexpenses/currencies
2022-06-01 15:37:20,414 INFO [RxCachedThreadScheduler-63] Query for URL: content://org.totschnig.myexpenses/currencies
Looks like I forgot to post back after I worked around this last time. I just deleted the lock file on the server side (Nextcloud) and it started syncing just fine again.
However, a few months later and the problem is back, except this time there is no lock file. The error message is not specific about whether it it already locked or if it wasn't locked but a new lock couldn't be taken for some reason. In my case, it's presumably the latter.
I will dig into this further when I am at a computer, but from browsing the code on my phone, it looks like this is the core of what's failing. I'll also check the Nextcloud logs. If necessary, I can try adding some extra logging and compile my own APK.
Since it took a couple months to reappear, I'm guessing this is going to be a tricky one to track down and difficult to know if a change is a complete fix. Here's to hoping that I am wrong about this.
Ugh, the .lock file was in Nextcloud, but I had my client configured to hide hidden files. So it only appeared to not have a .lock file. Manually deleting the lock on the back end did work around the issue. I will continue to hunt for the root cause and report back any findings.
I have reproduced the problem and the logs from Nextcloud say there was no problem writing the .lock file, while MyExpenses says "Remote backend is locked or cannot be locked". The .lock file had a UUID in it. I did not find anything of interest in TransactionProvider-latest.log (obtained from Settings -> Advanced -> Debug -> Share log files).
It looks like the problem is on the MyExpenses side. Any suggestions on how I can debug this further?
Logs
Nextcloud logs:
172.16.4.70 - anon [08/Aug/2022:13:34:41 -0500] "HEAD /remote.php/dav/files/anon/Teamsters/Money/Teamsters-Expenses/ENCRYPTION_TOKEN HTTP/1.1" 404 6155 "-" "okhttp/4.9.3"
172.16.4.70 - anon [08/Aug/2022:13:34:44 -0500] "HEAD /remote.php/dav/files/anon/Teamsters/Money/Teamsters-Expenses/9012b08b-3b39-4b7e-9caf-741eb47ce090/ HTTP/1.1" 200 1502 "-" "okhttp/4.9.3"
172.16.4.70 - anon [08/Aug/2022:13:34:50 -0500] "HEAD /remote.php/dav/files/anon/Teamsters/Money/Teamsters-Expenses/9012b08b-3b39-4b7e-9caf-741eb47ce090/metadata.json HTTP/1.1" 200 1789 "-" "okhttp/4.9.3"
172.16.4.70 - anon [08/Aug/2022:13:34:54 -0500] "HEAD /remote.php/dav/files/anon/Teamsters/Money/Teamsters-Expenses/9012b08b-3b39-4b7e-9caf-741eb47ce090/.lock HTTP/1.1" 404 1407 "-" "okhttp/4.9.3"
172.16.4.70 - anon [08/Aug/2022:13:34:55 -0500] "PUT /remote.php/dav/files/anon/Teamsters/Money/Teamsters-Expenses/9012b08b-3b39-4b7e-9caf-741eb47ce090/.lock HTTP/1.1" 201 1613 "-" "okhttp/4.9.3"
@anon8675309 Thank you for your efforts in providing all this information. When the notification "Remote backend is locked or cannot be locked" appears, it would be interesting to check the content of the SyncAdapter-latest.log file, because the error that triggers this notification should be logged into that file.
I believe I have the log message (full stacktrace below).
The punchline seems to be "Caused by: java.net.SocketTimeoutException: Read timed out". The time between when it first attempted to sync and when the "locked or cannot be locked" message was only a few seconds. Looking at the log messages, apparently it was 10 seconds. It felt much shorter, but then again I wasn't counting.
In any case, it was not like a webpage timeout where it takes about 60 seconds. ~~Is there any way I can change that timeout to be larger to see if it would help with this locking problem?~~
I found Settings -> WebDAV -> WebDAV Timeout (in seconds) and changed it to 60. After that I was not able to immediately reproduce the issue. If I don't post back in this thread within the next week or two, it is safe to assume that this has resolved my issue.
2022-08-14 15:59:33,522 INFO [SyncAdapterThread-1] ExistingLockToken: null
2022-08-14 15:59:43,574 WARN [SyncAdapterThread-1] java.net.SocketTimeoutException: timeout
at eg.a0.j(JvmOkio.kt:1)
at eg.d.K0(AsyncTimeout.kt:8)
at eg.v.a(RealBufferedSource.kt:6)
at eg.v.N(RealBufferedSource.kt:1)
at wf.b.c(Http1ExchangeCodec.kt:3)
at uf.c.c(Exchange.kt:1)
at vf.b.intercept(CallServerInterceptor.kt:31)
at vf.f.a(RealInterceptorChain.kt:16)
at at.bitfire.dav4android.BasicDigestAuthHandler.intercept(BasicDigestAuthHandler.java:4)
at vf.f.a(RealInterceptorChain.kt:16)
at uf.a.intercept(ConnectInterceptor.kt:31)
at vf.f.a(RealInterceptorChain.kt:16)
at sf.a.intercept(CacheInterceptor.kt:174)
at vf.f.a(RealInterceptorChain.kt:16)
at vf.a.intercept(BridgeInterceptor.kt:26)
at vf.f.a(RealInterceptorChain.kt:16)
at vf.h.intercept(RetryAndFollowUpInterceptor.kt:35)
at vf.f.a(RealInterceptorChain.kt:16)
at uf.e.h(RealCall.kt:25)
at uf.e.e(RealCall.kt:12)
at at.bitfire.dav4android.DavResource.put(DavResource.java:7)
at dj.c.T(WebDavBackendProvider.kt:3)
at fi.a.b(AbstractSyncBackendProvider.kt:16)
at dj.c.b(WebDavBackendProvider.kt:2)
at fi.d.onPerformSync(SyncAdapter.kt:106)
at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:354)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:119)
at java.net.SocketInputStream.read(SocketInputStream.java:176)
at java.net.SocketInputStream.read(SocketInputStream.java:144)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(ConscryptEngineSocket.java:945)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(ConscryptEngineSocket.java:909)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(ConscryptEngineSocket.java:824)
at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(ConscryptEngineSocket.java:797)
at eg.p.K0(JvmOkio.kt:5)
at eg.d.K0(AsyncTimeout.kt:3)
... 24 more
2022-08-14 15:59:43,577 INFO [SyncAdapterThread-1] Remote backend is locked or cannot be locked.
Changing the timeout did solve the problem for me, as my issue was that the server (Nextcloud) was slower than desired.
Increasing the timeout may solve the problem for @tgrosinger and @Coqorico if they are having the same problem (unable to take out a lock because it times out before the lock is established).
I'm back with the ability to reproduce this issue almost every time I attempt to sync, even with the timeout set to 60 seconds. I can see the .lock file gets created just find on the back end, but the app says "Remote backend is locked or cannot be locked."
I'd love to share the SyncAdapter-latest.log file, but when I go to Settings -> Debug -> Share log files, The only one there is TransactionProvider-latest.log. Is there a setting I can change to get it to output the SyncAdapter log?
What I really want to see is the INFO level messages about whether to override the lock, but I don't know how to change the log level.
@anon8675309 This is strange, because the logging for tag TransactionProvider is set up together with tag SyncAdapter in method setupLogging in MyApplication class. Maybe there is some new condition on your device that has an effect on how the SyncAdapter can log, since it is running in a separate process. Which Android version is your device running on?
It has been several months since I have seen this problem on my systems. I've made performance improvements to the WebDAV server and increased the timeout on the client side. I'll leave it up to others to determine if the ticket should be closed or not, but no need to keep it open on my behalf.