DAVx5 and Baïkal: unexpected end of stream for contacts - cannot sync

[nihili]

I am running Baïkal on my nginx server and DAVx5 on my LieageOS 16 phone.
Davx5 version is 2.4.0.1-ose (280).

I followed the instructions here: https://www.davx5.com/tested-with/baikal

I exported & imported my contacts with the same application, LineageOS default Contacts app.

Initial upload to the server seems to go fine, but every subsequent sync attempt gives this notification:

Addresses (…)
Network or I/O error - unexpected end of stream

It does not seem to affect the calendar.
I can see on Baïkal’s admin interface that all contacts are present, but I have currently no means to look at them other than my phone, so I don’t know if they’re corrupt or something.

I can use both calendar and contacts just fine on my phone.

I have considered that this could be a server problem and have searched extensively for both Baïkal and nginx. Unfortunately I have no idea how DAVx5’s error message translates into Baïkal or nginx. Nothing I found stands out. Following a hunch I have restarted the nginx server with

etag on;
gzip off;

but there’s no change.
Frankly, I am out of my depth here.

I would appreciate if someone could look at the DAVx5 log and maybe clarify (this is the log I get by clicking on the mentioned error notification)?

--- BEGIN DEBUG INFO ---
Account name: Addresses (email@address.co WQ)
Authority: com.android.contacts

EXCEPTION:
java.net.ProtocolException: unexpected end of stream
	at okhttp3.internal.http1.Http1Codec$ChunkedSource.read(Http1Codec.java:455)
	at okio.RealBufferedSource.request(RealBufferedSource.kt:62)
	at okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.java:253)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:250)
	at okhttp3.RealCall.execute(RealCall.java:93)
	at at.bitfire.dav4jvm.DavCollection$reportChanges$4.invoke(DavCollection.kt:88)
	at at.bitfire.dav4jvm.DavCollection$reportChanges$4.invoke(DavCollection.kt:22)
	at at.bitfire.dav4jvm.DavResource.followRedirects(DavResource.kt:378)
	at at.bitfire.dav4jvm.DavCollection.reportChanges(DavCollection.kt:83)
	at at.bitfire.davdroid.syncadapter.SyncManager.listRemoteChanges(SyncManager.kt:543)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1$2.invoke(SyncManager.kt:172)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1$2.invoke(SyncManager.kt:53)
	at at.bitfire.davdroid.syncadapter.SyncManager.syncRemote(SyncManager.kt:455)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:170)
	at at.bitfire.davdroid.syncadapter.SyncManager$performSync$1.invoke(SyncManager.kt:53)
	at at.bitfire.davdroid.syncadapter.SyncManager.unwrapExceptions(SyncManager.kt:835)
	at at.bitfire.davdroid.syncadapter.SyncManager.performSync(SyncManager.kt:112)
	at at.bitfire.davdroid.syncadapter.ContactsSyncAdapterService$ContactsSyncAdapter.sync(ContactsSyncAdapterService.kt:64)
	at at.bitfire.davdroid.syncadapter.SyncAdapterService$SyncAdapter.onPerformSync(SyncAdapterService.kt:73)
	at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:334)

SOFTWARE INFORMATION
* at.bitfire.davdroid 2.4.0.1-ose (280) from com.android.packageinstaller
* com.android.providers.contacts 9 (28)
* com.android.providers.calendar 9 (28)
* com.android.contacts 1.7.31 (10731)
* ws.xsoh.etar 1.0.16 (18) from com.android.packageinstaller

CONNECTIVITY (at the moment)
Active connection: mobile, CONNECTED

CONFIGURATION
Power saving disabled: yes
android.permission.READ_CONTACTS: granted
android.permission.WRITE_CONTACTS: granted
android.permission.READ_CALENDAR: granted
android.permission.WRITE_CALENDAR: granted
org.dmfs.permission.READ_TASKS: denied
org.dmfs.permission.WRITE_TASKS: denied
android.permission.ACCESS_COARSE_LOCATION: denied
System-wide synchronization: automatically
Account: email@address.co
  Address book sync. interval: 240 min
  Calendar     sync. interval: 240 min
  OpenTasks    sync. interval: —
  WiFi only: false
  [CardDAV] Contact group method: GROUP_VCARDS
  [CalDAV] Time range (past days): 90
           Manage calendar colors: true
           Use event colors: false
Address book account: Addresses (email@address.co WQ)
  Main account: Account {name=email@address.co, type=bitfire.at.davdroid}
  URL: https://site.tld:9999/dav.php/addressbooks/username/unique-id-2/
  Sync automatically: true

SQLITE DUMP
android_metadata
	|  locale |
	|  en_GB |
----------
services
	|  _id | accountName | service | principal |
	|  3 | email@address.co | carddav | https://site.tld:9999/dav.php/principals/username/ |
	|  4 | email@address.co | caldav | https://site.tld:9999/dav.php/principals/username/ |
----------
sqlite_sequence
	|  name | seq |
	|  services | 4 |
	|  homesets | 13 |
	|  collections | 18 |
----------
homesets
	|  _id | serviceID | url |
	|  11 | 4 | https://site.tld:9999/dav.php/calendars/username/ |
	|  13 | 3 | https://site.tld:9999/dav.php/addressbooks/username/ |
----------
collections
	|  _id | serviceID | type | url | privWriteContent | privUnbind | forceReadOnly | displayName | description | color | timezone | supportsVEVENT | supportsVTODO | source | sync |
	|  16 | 4 | CALENDAR | https://site.tld:9999/dav.php/calendars/username/unique-id-1/ | 1 | 1 | 0 | Calendar | <null> | -7617718 | <null> | 1 | 1 | <null> | 1 |
	|  18 | 3 | ADDRESS_BOOK | https://site.tld:9999/dav.php/addressbooks/username/unique-id-2/ | 1 | 1 | 0 | Addresses | <null> | <null> | <null> | 0 | 0 | <null> | 1 |
----------

SYSTEM INFORMATION
Android version: 9 (lineage_oneplus3-userdebug 9 PQ2A.190405.003 570750a839)
Device: OnePlus ONEPLUS A3003 (OnePlus3)

--- END DEBUG INFO ---

(i removed some sensitive data)

Thanks.

[rfc2822]

Hello,

Unexpected end of stream sounds like the server interrupts the connection before DAVx⁵ gets the data. Maybe a firewall problem? Do you use HTTP/2? Are there entries in the Web server (error) log?

[nihili]

Thanks for a quick response!

Maybe a firewall problem?

I have now explicitly punched another hole for incoming connections on the specified port, no difference.
The router is letting the port through correctly afaics.

Also, calendar sync works!

Do you use HTTP/2?

Sorry, what is that?

Are there entries in the Web server (error) log?

Good point.

/var/log/nginx/access.log after a single failed contacts sync:

IP.IP.IP.IP - username [27/Apr/2019:10:48:44 +0300] "PROPFIND /dav.php/addressbooks/username/unique-id-1/ HTTP/1.1" 207 1645 "-" "DAVx5/2.4.0.1-ose (2019/04/05; dav4jvm; okhttp/3.12.1) Android/9"
IP.IP.IP.IP - username [27/Apr/2019:10:48:44 +0300] "PROPFIND /dav.php/calendars/username/unique-id-2/ HTTP/1.1" 207 1480 "-" "DAVx5/2.4.0.1-ose (2019/04/05; dav4jvm; okhttp/3.12.1) Android/9"
IP.IP.IP.IP - username [27/Apr/2019:10:48:44 +0300] "REPORT /dav.php/addressbooks/username/unique-id-1/ HTTP/1.1" 207 16071 "-" "DAVx5/2.4.0.1-ose (2019/04/05; dav4jvm; okhttp/3.12.1) Android/9"
IP.IP.IP.IP - username [27/Apr/2019:10:48:45 +0300] "REPORT /dav.php/calendars/username/unique-id-2/ HTTP/1.1" 207 12869 "-" "DAVx5/2.4.0.1-ose (2019/04/05; dav4jvm; okhttp/3.12.1) Android/9"

/var/log/nginx/error.log after a single failed contacts sync:

2019/04/27 10:48:44 [crit] 31778#31778: *3998 open() "/var/lib/nginx/fastcgi/4/02/0000000024" failed (13: Permission denied) while reading upstream, client: IP.IP.IP.IP, server: , request: "REPORT /dav.php/addressbooks/username/unique-id-1/ HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.0-fpm.sock:", host: "site.tld:port"

I see “permission denied”, but frankly I don’t understand where it comes from. Permission on the phone or on the server?

I do run a firewall on my phone - NetGuard. Needless to say, DAVx5 is allowed to access the internet.
I made another test with the firewall disabled completely, and the error message is the same on both server and phone.

Again: Calendar sync works both ways!

[rfc2822]

@nihili said in DAVx5 and Baïkal: unexpected end of stream for contacts - cannot sync:

2019/04/27 10:48:44 [crit] 31778#31778: *3998 open() “/var/lib/nginx/fastcgi/4/02/0000000024” failed (13: Permission denied) while reading upstream, client: IP.IP.IP.IP, server: , request: “REPORT /dav.php/addressbooks/username/unique-id-1/ HTTP/1.1”, upstream: “fastcgi://unix:/var/run/php/php7.0-fpm.sock:”, host: “site.tld:port”

You can see that nginx can’t read from the upstream server so the connection is reset. You will have to investigate why this error message occurs and fix it on the server. Then everything should work.

[nihili]

@rfc2822 said in DAVx5 and Baïkal: unexpected end of stream for contacts - cannot sync:

You can see that nginx can’t read from the upstream server so the connection is reset.

Sorry but what is the upstream server in this case? the IP.IP.IP.IP mentioned in the log (that’s my phone)?

what weirds me out is that it does work for the calendar.

Thanks for your help so far - and for the app of course!

[rfc2822]

@nihili As far as I understand your configuration, upstream means your CalDAV/CardDAV server (impersonated by a PHP process in this case). So I’d look in the PHP and CalDAV/CardDAV server logs.

[nihili]

Thanks for the explanation. I guess it was a problem with Baïkal after all.

I have “fixed” it by switching to DAViCal.
Very intimidating documentation & UI, but almost nothing needed to be configured and it Just Worked.

So,

• DAViCal is the server
• DAVx5 syncs everything on Android
• on the desktop I use vdirsyncer & khal for the calendar only (vdirsyncer still refuses to sync my contacts), and SoGo connector for contacts on thunderbird.

It’s been a long day.