sabre-io / dav

sabre/dav is a CalDAV, CardDAV and WebDAV framework for PHP
http://sabre.io
BSD 3-Clause "New" or "Revised" License
1.54k stars 347 forks source link

CardDAV server is broken when using iOS 17.3.1 #1546

Closed ghost closed 8 months ago

ghost commented 8 months ago

After many years of faithful service, my CalDAV/CardDAV server seems broken. I keep getting messages like this in the log:

xx.xx.xx.xx - - [06/Mar/2024:10:18:33 -0800] "REPORT /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 500 345 "-" "iOS/17.3.1 (21D61) dataaccessd/1.0"

(note the HTTP 500 error) and the Contacts on the phone don't sync...even though the phone connects to the contacts account just fine. It seems to work fine on my Mac (Sonoma -- 14.3.1 -- 23D60]. Calendars seem to work just fine on both as well.

I'm using:

FreeBSD 14.0-RELEASE-p5 (uses OpenSSL 3.0.13) php 8.3.3 (with php-fpm...I use a multi-threaded web server)

-  php83-composer-2.7.1
-  php83-ctype-8.3.3
-  php83-curl-8.3.3
-  php83-dom-8.3.3
-  php83-fileinfo-8.3.3
-  php83-filter-8.3.3
-  php83-iconv-8.3.3
-  php83-intl-8.3.3
-  php83-mbstring-8.3.3
-  php83-opcache-8.3.3
-  php83-pcntl-8.3.3
-  php83-pdo-8.3.3
-  php83-pdo_sqlite-8.3.3
-  php83-phar-8.3.3
-  php83-posix-8.3.3 
-  php83-session-8.3.3
-  php83-simplexml-8.3.3
-  php83-sqlite3-8.3.3
-  php83-tokenizer-8.3.3
-  php83-xml-8.3.3
-  php83-xmlreader-8.3.3
-  php83-xmlwriter-8.3.3
-  php83-zip-8.3.3
-  php83-zlib-8.3.3

sabre/dav v4.6.0 sabre/event v5.1.4 sabre/http v5.1.10 sabre/uri v2.3.3 sabre/vobject v4.5.4 sabre/xml v2.2.6 psr-4

I've attached the source of card.php for your reference as well (it's pretty short and simple). The database is SQLite and uses the vanilla schema shipped with the sabre-io examples. The schema is attached as well.

I'm really at a loss about what's causing this or where to look for it. I'm also NOT discounting the fact that this is an iOS bug (it wouldn't be the first time for one of these).

If any of you have any insights, I'd surely appreciate you passing them on to me. Thanks in advance...

card.php.txt db.schema.txt

ghost commented 8 months ago

Here are the values of the various constants used in card.php:

DavAdmin\Constants\Time::ZONE = "America/Los_Angeles";
DavAdmin\Constants\Database::ID = "sqlite:///srv/ical/var/db/davsyncdb.sqlite";
DavAdmin\Constants\Server::REALM = "Shared";
DeepDiver1975 commented 8 months ago

http status code 500 indicates some backend error - please have a look at the web server logs if you see more details.

ghost commented 8 months ago

There are no entries in the web server/php-fpm logs corresponding to this:

stevewi:/var/log/httpd $ grep '06\/Mar\/2024:10:18' httpd-access.log
stevewi:/var/log/httpd $ grep '06\/Mar\/2024:10:18' httpd-error.log
stevewi:/var/log/php-fpm $ grep '06\/Mar\/2024:10:18' php-fpm.log
stevewi:/var/log/httpd $ grep '500' httpd-access.log
stevewi:/var/log/httpd $ grep '500' httpd-error.log
stevewi:/var/log/php-fpm $ grep '500' php-fpm.log

This is another reason this is so puzzling.

DeepDiver1975 commented 8 months ago

Grep for "Exception"

ghost commented 8 months ago
stevewi:/var/log/httpd $ grep 'Exception' httpd-access.log
stevewi:/var/log/httpd $ grep 'Exception' httpd-error.log
stevewi:/var/log/httpd $ grep 'Exception' ical.access.log.2024.03.06
stevewi:/var/log/httpd $ grep 'Exception' ical.error.log.2024.03.06
stevewi:/var/log/php-fpm $ grep 'Exception' php-fpm.log

From php.ini:

display_errors = Off
display_startup_errors = Off
error_reporting = E_ALL
log_errors = On
ghost commented 8 months ago

iOS 17.4 became available today. I just updated my phone. Same results :-(

Just for completeness, here's a complete log of the CardDAV transactions (for the recent update AFTER updating my phone to iOS 17.4...these are the same as for iOS 17.3.1):

50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 207 425 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 401 428 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 207 836 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "REPORT /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 500 345 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/principals/stevewi/ HTTP/1.1" 401 421 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/principals/stevewi/ HTTP/1.1" 207 1026 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/ HTTP/1.1" 401 423 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/ HTTP/1.1" 207 2949 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 401 428 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:25 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 207 425 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:26 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 401 428 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:26 -0800] "PROPFIND /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 207 836 "-" "iOS/17.4 (21E219) dataaccessd/1.0" 50.46.162.188 - - [06/Mar/2024:15:18:26 -0800] "REPORT /i/card.php/addressbooks/stevewi/Test/ HTTP/1.1" 500 345 "-" "iOS/17.4 (21E219) dataaccessd/1.0"

DeepDiver1975 commented 8 months ago

Without any detailed error message it is hard to tell what is causing the issue .....

ghost commented 8 months ago

Until sabre generates an error, it is hard to give you what you want...

This seems to be a php 8.2/8.3 issue...reverting back to php 8.1 seems to make everything work the way it used to. The problem is that php 8.1 is deprecated and will go to EOL on 2024-11-25.

The same problem exists with Baikal. Reverting back to php 8.1 fixes it as well.

It's probably time to dump this system in favor or something considerably less brittle.

DeepDiver1975 commented 8 months ago

Until sabre generates an error, it is hard to give you what you want...

you might have missed to setup the logger properly. Server implements the LoggerAwareInterface https://github.com/sabre-io/dav/blob/da8c1f226f1c053849540a189262274ef6809d1c/lib/DAV/Server.php#L26C25-L26C45

example code: https://github.com/sabre-io/dav/blob/da8c1f226f1c053849540a189262274ef6809d1c/examples/groupwareserver.php#L55-L56 https://github.com/sabre-io/dav/blob/da8c1f226f1c053849540a189262274ef6809d1c/examples/groupwareserver.php#L80-L81

ghost commented 8 months ago

Thanks for the tip but that just made the whole thing even worse. Mac Contacts wouldn't even connect to the address book. No PHP errors and no log either.

To tell you the truth, over the years, sabre has been just a giant PITA for me...brittle and unpredictable. I've moved on. Close this if you like.