Max retries on soft errors reached

[ibahnasy]

I'm getting this error frequently, what could be the cause:

Log file created at Wed May 01 14:18:14 GMT+03:00 2024; PID 3164; UID 10240
2024-05-01 14:18:14 2 [log.Logger] Now logging to file: /data/user/0/at.bitfire.davdroid/files/debug/davx5-log.txt
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting preferred_tasks_provider
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = org.tasks.opentasks
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting preferred_tasks_provider -> org.tasks.opentasks
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_type
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_type = -1
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_type -> -1
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_host
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_host = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: proxy_host = localhost
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_host -> localhost
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_port
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_port = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: proxy_port = 9050
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_port -> 9050
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting distrust_system_certs
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: distrust_system_certs = true
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting distrust_system_certs -> true
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting preferred_theme
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: preferred_theme = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: preferred_theme = null
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting preferred_theme -> no result
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting preferred_tasks_provider
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: preferred_tasks_provider = org.tasks.opentasks
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting preferred_tasks_provider -> org.tasks.opentasks
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_type
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_type = -1
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_type -> -1
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_host
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_host = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: proxy_host = localhost
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_host -> localhost
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting proxy_port
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: proxy_port = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: proxy_port = 9050
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting proxy_port -> 9050
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting distrust_system_certs
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: distrust_system_certs = true
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting distrust_system_certs -> true
2024-05-01 14:18:14 2 [settings.SettingsManager] Looking up setting preferred_theme
2024-05-01 14:18:14 2 [settings.SettingsManager] SharedPreferencesProvider: preferred_theme = null
2024-05-01 14:18:14 2 [settings.SettingsManager] DefaultsProvider: preferred_theme = null
2024-05-01 14:18:14 2 [settings.SettingsManager] Looked up setting preferred_theme -> no result
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 42 [settings.SettingsManager] Looking up setting contact_group_method
2024-05-01 14:18:16 42 [settings.SettingsManager] SharedPreferencesProvider: contact_group_method = null
2024-05-01 14:18:16 42 [settings.SettingsManager] DefaultsProvider: contact_group_method = null
2024-05-01 14:18:16 42 [settings.SettingsManager] Looked up setting contact_group_method -> no result
2024-05-01 14:18:16 42 [settings.SettingsManager] Looking up setting default_alarm
2024-05-01 14:18:16 42 [settings.SettingsManager] SharedPreferencesProvider: default_alarm = null
2024-05-01 14:18:16 42 [settings.SettingsManager] DefaultsProvider: default_alarm = null
2024-05-01 14:18:16 42 [settings.SettingsManager] Looked up setting default_alarm -> no result
2024-05-01 14:18:16 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:16 2 [util.BroadcastReceiverFlowKt] Unregistering broadcast receiver for Action: "android.os.action.POWER_SAVE_WHITELIST_CHANGED"
2024-05-01 14:18:49 42 [syncadapter.BaseSyncWorker] PeriodicSyncWorker called for sync-at.bitfire.davdroid.addressbooks bitfire.at.davdroid/usernam@example.com
2024-05-01 14:18:49 42 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:49 42 [settings.SettingsManager] Looking up setting ignore_vpns
2024-05-01 14:18:49 42 [settings.SettingsManager] SharedPreferencesProvider: ignore_vpns = null
2024-05-01 14:18:49 42 [settings.SettingsManager] DefaultsProvider: ignore_vpns = true
2024-05-01 14:18:49 42 [settings.SettingsManager] Looked up setting ignore_vpns -> true
2024-05-01 14:18:49 42 [network.ConnectionUtils] Looking for validated Internet over this connection.
	PARAMETER #0 = [type: WIFI[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: , failover: false, available: true, roaming: false]
	PARAMETER #1 = [ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED&NOT_VCN_MANAGED LinkUpBandwidth>=12000Kbps LinkDnBandwidth>=30000Kbps TransportInfo: <SSID: <unknown ssid>, BSSID: 02:00:00:00:00:00, MAC: 02:00:00:00:00:00, IP: /192.168.0.178, Security type: 2, Supplicant state: COMPLETED, Wi-Fi standard: 4, RSSI: -65, Link speed: 65Mbps, Tx Link speed: 65Mbps, Max Supported Tx Link speed: 150Mbps, Rx Link speed: 65Mbps, Max Supported Rx Link speed: 150Mbps, Frequency: 2462MHz, Net ID: -1, Metered hint: false, score: 57, isUsable: true, CarrierMerged: false, SubscriptionId: -1, IsPrimary: -1, Trusted: true, Restricted: false, Ephemeral: false, OEM paid: false, OEM private: false, OSU AP: false, FQDN: <none>, Provider friendly name: <none>, Requesting package name: <none><none>MLO Information: , AP MLD Address: <none>, AP MLO Link Id: <none>, AP MLO Affiliated links: <none>> SignalStrength: -65 UnderlyingNetworks: Null]
2024-05-01 14:18:49 42 [network.ConnectionUtils] This connection can be used.
2024-05-01 14:18:49 199 [syncadapter.BaseSyncWorker] Running kotlinx.coroutines.DispatchedCoroutine: account=Account {name=usernam@example.com, type=bitfire.at.davdroid}, authority=at.bitfire.davdroid.addressbooks
2024-05-01 14:18:49 199 [syncadapter.Syncer] at.bitfire.davdroid.addressbooks sync of Account {name=usernam@example.com, type=bitfire.at.davdroid} initiated
	PARAMETER #0 = 
2024-05-01 14:18:49 199 [settings.SettingsManager] Looking up setting force_read_only_addressbooks
2024-05-01 14:18:49 199 [settings.SettingsManager] SharedPreferencesProvider: force_read_only_addressbooks = null
2024-05-01 14:18:49 199 [settings.SettingsManager] DefaultsProvider: force_read_only_addressbooks = false
2024-05-01 14:18:49 199 [settings.SettingsManager] Looked up setting force_read_only_addressbooks -> false
2024-05-01 14:18:49 199 [syncadapter.AddressBookSyncer] Updating local address book https://example.com/remote.php/dav/addressbooks/users/islam.bahnasy/test-1/
	PARAMETER #0 = Collection(id=9, serviceId=1, homeSetId=1, ownerId=2, type=ADDRESS_BOOK, url=https://example.com/remote.php/dav/addressbooks/users/islam.bahnasy/test-1/, privWriteContent=true, privUnbind=true, forceReadOnly=false, displayName=Contacts, description=null, color=null, timezone=null, supportsVEVENT=null, supportsVTODO=null, supportsVJOURNAL=null, source=null, sync=true, pushTopic=null, supportsWebPush=false, pushSubscription=null, pushSubscriptionCreated=null)
2024-05-01 14:18:49 199 [syncadapter.AddressBookSyncer] Synchronizing address book Account {name=Contacts (usernam@example.com Uw), type=at.bitfire.davdroid.address_book}
2024-05-01 14:18:49 199 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:49 199 [settings.SettingsManager] Looking up setting contact_group_method
2024-05-01 14:18:49 199 [settings.SettingsManager] SharedPreferencesProvider: contact_group_method = null
2024-05-01 14:18:49 199 [settings.SettingsManager] DefaultsProvider: contact_group_method = null
2024-05-01 14:18:49 199 [settings.SettingsManager] Looked up setting contact_group_method -> no result
2024-05-01 14:18:49 199 [syncadapter.AddressBookSyncer] Synchronizing address book: https://example.com/remote.php/dav/addressbooks/users/islam.bahnasy/test-1/
2024-05-01 14:18:49 199 [syncadapter.AddressBookSyncer] Taking settings from: Account {name=usernam@example.com, type=bitfire.at.davdroid}
2024-05-01 14:18:49 199 [settings.AccountSettings] Account usernam@example.com has version 15, current version: 15
2024-05-01 14:18:49 199 [settings.SettingsManager] Looking up setting proxy_type
2024-05-01 14:18:49 199 [settings.SettingsManager] SharedPreferencesProvider: proxy_type = -1
2024-05-01 14:18:49 199 [settings.SettingsManager] Looked up setting proxy_type -> -1
2024-05-01 14:18:49 199 [settings.SettingsManager] Looking up setting distrust_system_certs
2024-05-01 14:18:49 199 [settings.SettingsManager] SharedPreferencesProvider: distrust_system_certs = true
2024-05-01 14:18:49 199 [settings.SettingsManager] Looked up setting distrust_system_certs -> true
2024-05-01 14:18:49 199 [settings.SettingsManager] Looking up setting contact_group_method
2024-05-01 14:18:49 199 [settings.SettingsManager] SharedPreferencesProvider: contact_group_method = null
2024-05-01 14:18:49 199 [settings.SettingsManager] DefaultsProvider: contact_group_method = null
2024-05-01 14:18:49 199 [settings.SettingsManager] Looked up setting contact_group_method -> no result
2024-05-01 14:18:49 199 [syncadapter.SyncManager] Preparing synchronization
2024-05-01 14:18:49 199 [syncadapter.ContactsSyncManager] Contact group strategy: CategoriesStrategy
2024-05-01 14:18:49 199 [syncadapter.SyncManager] Querying server capabilities
2024-05-01 14:19:05 199 [syncadapter.SyncManager] I/O error
EXCEPTION java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(SocketInputStream.java:191)
	at java.net.SocketInputStream.read(SocketInputStream.java:143)
	at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(ConscryptEngineSocket.java:25)
	at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(ConscryptEngineSocket.java:173)
	at org.conscrypt.ConscryptEngineSocket$SSLInputStream.access$100(ConscryptEngineSocket.java:1)
	at org.conscrypt.ConscryptEngineSocket.doHandshake(ConscryptEngineSocket.java:97)
	at org.conscrypt.ConscryptEngineSocket.startHandshake(ConscryptEngineSocket.java:37)
	at okhttp3.internal.connection.RealConnection.establishProtocol(RealConnection.kt:106)
	at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:174)
	at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:721)
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:62)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:122)
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:1010)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:122)
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:232)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:122)
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:148)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:122)
	at at.bitfire.davdroid.network.HttpClient$UserAgentInterceptor.intercept(HttpClient.kt:79)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:122)
	at okhttp3.internal.connection.RealCall.execute(RealCall.kt:141)
	at at.bitfire.dav4jvm.DavResource$propfind$2.invoke(DavResource.kt:8)
	at at.bitfire.dav4jvm.DavResource$propfind$2.invoke(DavResource.kt:1)
	at at.bitfire.dav4jvm.DavResource.followRedirects$build(DavResource.kt:14)
	at at.bitfire.dav4jvm.DavResource.propfind(DavResource.kt:72)
	at at.bitfire.davdroid.syncadapter.ContactsSyncManager$queryCapabilities$1.invoke(ContactsSyncManager.kt:3)
	at at.bitfire.davdroid.syncadapter.ContactsSyncManager$queryCapabilities$1.invoke(ContactsSyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.remoteExceptionContext(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.remoteExceptionContext(SyncManager.kt:5)
	at at.bitfire.davdroid.syncadapter.ContactsSyncManager.queryCapabilities(ContactsSyncManager.kt:6)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:8)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.unwrapExceptions(SyncManager.kt:2)
	at at.bitfire.davdroid.syncadapter.SyncManager.performSync(SyncManager.kt:20)
	at at.bitfire.davdroid.syncadapter.AddressBookSyncer.syncAddresBook(AddressBookSyncer.kt:221)
	at at.bitfire.davdroid.syncadapter.AddressBookSyncer.sync(AddressBookSyncer.kt:152)
	at at.bitfire.davdroid.syncadapter.Syncer.onPerformSync(Syncer.kt:118)
	at at.bitfire.davdroid.syncadapter.BaseSyncWorker$doSyncWork$2$1$1.invoke(BaseSyncWorker.kt:4)
	at at.bitfire.davdroid.syncadapter.BaseSyncWorker$doSyncWork$2$1$1.invoke(BaseSyncWorker.kt:1)
	at kotlinx.coroutines.InterruptibleKt$runInterruptible$2.invokeSuspend(Interruptible.kt:59)
	at kotlinx.coroutines.InterruptibleKt$runInterruptible$2.invoke(Interruptible.kt:13)
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:16)
	at kotlinx.coroutines.BuildersKt.withContext(Unknown Source:41)
	at kotlinx.coroutines.InterruptibleKt.runInterruptible$default(Interruptible.kt:9)
	at at.bitfire.davdroid.syncadapter.BaseSyncWorker$doSyncWork$2.invokeSuspend(BaseSyncWorker.kt:482)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:9)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:111)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
	at java.lang.Thread.run(Thread.java:1012)

2024-05-01 14:19:05 199 [syncadapter.AddressBookSyncer] Contacts sync complete
2024-05-01 14:19:05 199 [syncadapter.AddressBookSyncer] Address book sync complete
2024-05-01 14:19:05 199 [syncadapter.Syncer] at.bitfire.davdroid.addressbooks sync of Account {name=usernam@example.com, type=bitfire.at.davdroid} finished
	PARAMETER #0 = 
2024-05-01 14:19:05 199 [syncadapter.BaseSyncWorker] Soft error while syncing: result=SyncResult: stats [ numIoExceptions: 1], stats= stats [ numIoExceptions: 1]
2024-05-01 14:19:05 199 [syncadapter.BaseSyncWorker] Max retries on soft errors reached (5 of 5). Treating as failed
2024-05-01 14:19:05 42 [syncadapter.BaseSyncWorker] PeriodicSyncWorker finished for sync-at.bitfire.davdroid.addressbooks bitfire.at.davdroid/usernam@example.com

[rfc2822]

Looks like a very unstable connection, maybe combined with many syncs (low sync interval).

Do you use WiFi or mobile connection? Are there many interruptions?

[ibahnasy]

It happens on both (wifi and 4G) and my wifi connection is very stable.
The sync interval is 15 minutes for contacts and calendar.

I only have this limitation in the firewall:

iptables -A INPUT -m conntrack --ctstate NEW -m limit --limit 150/second --limit-burst 150 -p tcp --dport 80 -j ACCEPT
iptables -A INPUT -m conntrack --ctstate NEW -m limit --limit 150/second --limit-burst 150 -p tcp --dport 443 -j ACCEPT

Which allows up to 150 new connections per second so I don't think it could affect DavX sync, right?

[rfc2822]

Can you try without the rules?

[ibahnasy]

I raised the limit to 200 and the error didn't appear again.
I'm wondering how many requests does DavX5 needs to sync?

[rfc2822]

Not that much, but I don't know about the details of your firewall. Davx5 sync is fast and can maybe make a few requests within a very short time so that it extrapolates to 150/s?

Do you have HTTP/2? This should reduce connections

[ibahnasy]

I'm already using HTTP/2.

Actually even during times when there is no errors, the sync takes some seconds, it's not very fast, although my server specs is not bad and there is no load on it.

[oDD-1]

Unfortunately I'm experiencing the same error message as of this week, but I have not changed anything. Could there be another reason?

[rfc2822]

It appears when DAVx5 can't connect to the server for a few times. Maybe there is a problem with your connection or your server. Does it sync when you force a sync in DAVx5? You can also enable Verbose logs in DAVx5 settings to see more information.

[ibahnasy]

After keeping the phone turned off for a while then started it again, I get this error in the attached files.
debug-info.txt
logcat.txt

[devvv4ever]

I think this is a different error then the one from the thread topic. "Software caused connection abort" seems like a crash of a network component. It usually does not have anything to do with DAVx5 itself. I also see that you activated the "Distrust System Certificates" option in the settings. Is this by intention? If not please deactivate it again and try to sync again. It could have to do with your problem.