On 22/11/2018 23:25, Florian Schlichting wrote: > Hi Daniel, > > On Thu, Nov 22, 2018 at 12:35:59PM +0100, Daniel Pocock wrote: >> Warning: CalDAV: No response status doing webdav sync for calendar foo >> Warning: CalDAV: Error doing webdav sync: undefined >> Warning: There has been an error reading data for calendar: foo. >> However, this error is believed to be minor, so the program will attempt >> to continue. Error code: DAV_REPORT_ERROR. Description: There has been >> an error reading data for calendar: >> https://foo.example.org/davical/caldav.php/foo/home/. It has been >> disabled until it is safe to use it. >> Warning: There has been an error reading data for calendar: foo. >> However, this error is believed to be minor, so the program will attempt >> to continue. Error code: READ_FAILED. Description: > > I don't remember ever seeing this from Thunderbird for calendars on a > DAViCal server. > On DAVdroid, this is the error: 12-03 10:36:59.599 2613 471 W davdroid: [syncadapter.SyncManager] I/O exception during sync, trying again later 12-03 10:36:59.599 2613 471 W davdroid: EXCEPTION java.io.IOException: unexpected end of stream on Connection{dav.example.org:443, proxy=DIRECT hostAddress=dav.example.org/10.1.2.3:443 cipherSuite=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 protocol=http/1.1} >> Simply logging into the web server and doing >> >> systemctl restart apache2 >> >> resolves the issue and all the clients work again for another week or so. >> >> Has anybody else observed this? >> >> Where should I look for additional logging or clues next time this >> happens? Should I enable any extra logging options in DAViCal, Apache >> or PostgreSQL? > > Well I'd start with the Apache logs: when TB says "no response status", > what does Apache think happened with the request, which status did it > log, anything in the error log? > > A default install of the davical package pulls in mod_php, which AFAIK > doesn't keep state between requests; do you use a different PHP > interpreter, or something like a Zend server or memcached? Nothing in > the way davical processes or responds to a request should change from a > webserver restart, really... > > If you still think davical may be at fault and want to dig deeper, have > a look at https://wiki.davical.org/index.php/Debugging - I'd recommend > setting $c->dbg["ALL"] = 1; and perhaps limiting things to a single > remote IP. The result is fairly verbose but should show you what the > requests and responses look like, and will provide enough detail to pin > down where things go south on the server side. There is nothing in Apache access.log or error.log for this particular virtual host. I press sync once in DAVdroid and this appears 3 times in the main error.log: [Mon Dec 03 09:42:19.538805 2018] [core:notice] [pid 13779] AH00052: child pid 5106 exit signal Segmentation fault (11) [Mon Dec 03 09:42:19.538919 2018] [core:notice] [pid 13779] AH00052: child pid 5113 exit signal Segmentation fault (11) [Mon Dec 03 09:42:19.538945 2018] [core:notice] [pid 13779] AH00052: child pid 5115 exit signal Segmentation fault (11) Nothing from journalctl I made a capture with tcpdump as well, I notice the server has sent "New Session Ticket" and the client has sent three "Application Data" packets and then the server closes the connection I did apt install systemd-coredump and used prlimit to set core size unlimited for the running process but I can't find any core dumps yet, maybe the apache2 needs to be restarted, but then the problem will not happen again for another week. I also tried connecting to the main process with gdb /usr/sbin/apache2 13779 but that doesn't show any output when the seg fault happens. Then I tried guessing which child process would crash next and connected to it with gdb, looks like an issue in pdo_pgsql.so with PHP 7, stack is below. Should the bug be reassigned to the php-pgsql package? As we have a reproducible stack trace I feel it is now an RC issue too. Is there any other data I should gather before restarting the Apache process again? I can leave it like this for a couple of hours maximum. Thread 1 "apache2" received signal SIGSEGV, Segmentation fault. 0x00007fa662662ed4 in ERR_clear_error () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 (gdb) bt #0 0x00007fa662662ed4 in ERR_clear_error () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #1 0x00007fa66267dfe9 in ?? () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #2 0x00007fa66bdf5739 in __pthread_once_slow (once_control=0x7fa6629a72d4, init_routine=0x7fa66267dfe0) at pthread_once.c:116 #3 0x00007fa6626d3f59 in CRYPTO_THREAD_run_once () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #4 0x00007fa66267e75b in OPENSSL_init_crypto () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #5 0x00007fa6625faffe in ?? () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #6 0x00007fa66267e080 in ?? () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #7 0x00007fa66bdf5739 in __pthread_once_slow (once_control=0x7fa6629a7308, init_routine=0x7fa66267e070) at pthread_once.c:116 #8 0x00007fa6626d3f59 in CRYPTO_THREAD_run_once () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #9 0x00007fa66267e6a3 in OPENSSL_init_crypto () from target:/usr/lib/x86_64-linux-gnu/libcrypto.so.1.1 #10 0x00007fa6629d5bd4 in OPENSSL_init_ssl () from target:/usr/lib/x86_64-linux-gnu/libssl.so.1.1 #11 0x00007fa6580fc25c in ?? () from target:/usr/lib/x86_64-linux-gnu/libpq.so.5 #12 0x00007fa6580e7aa3 in PQconnectPoll () from target:/usr/lib/x86_64-linux-gnu/libpq.so.5 #13 0x00007fa6580e864e in ?? () from target:/usr/lib/x86_64-linux-gnu/libpq.so.5 #14 0x00007fa6580e8fc7 in PQconnectdb () from target:/usr/lib/x86_64-linux-gnu/libpq.so.5 #15 0x00007fa65830e7e6 in ?? () from target:/usr/lib/php/20151012/pdo_pgsql.so #16 0x00007fa65c56d5cc in ?? () from target:/usr/lib/php/20151012/pdo.so #17 0x00007fa661fb580e in ?? () from target:/usr/lib/apache2/modules/libphp7.0.so #18 0x00007fa661f7006b in execute_ex () from target:/usr/lib/apache2/modules/libphp7.0.so #19 0x00007fa661fc48a7 in zend_execute () from target:/usr/lib/apache2/modules/libphp7.0.so #20 0x00007fa661f2f263 in zend_execute_scripts () from target:/usr/lib/apache2/modules/libphp7.0.so #21 0x00007fa661ecdee0 in php_execute_script () from target:/usr/lib/apache2/modules/libphp7.0.so #22 0x00007fa661fc620a in ?? () from target:/usr/lib/apache2/modules/libphp7.0.so #23 0x0000557938cf2c40 in ap_run_handler () #24 0x0000557938cf31d6 in ap_invoke_handler () #25 0x0000557938d0ae13 in ap_process_async_request () #26 0x0000557938d0af20 in ap_process_request () #27 0x0000557938d06fdd in ?? () #28 0x0000557938cfcab0 in ap_run_process_connection () #29 0x00007fa662d8e6bf in ?? () from target:/usr/lib/apache2/modules/mod_mpm_prefork.so #30 0x00007fa662d8e944 in ?? () from target:/usr/lib/apache2/modules/mod_mpm_prefork.so ---Type <return> to continue, or q <return> to quit--- #31 0x00007fa662d8f80d in ?? () from target:/usr/lib/apache2/modules/mod_mpm_prefork.so #32 0x0000557938cd600e in ap_run_mpm () #33 0x0000557938ccec4d in main ()
