Mailing List Archive: Davical Authorization / PATH_INFO issues (401) after server upgrade

Hi

I have been successfully using Davical with a number of Mac Clients (iCal) and iOS devices for years.
Yesterday, I updated my Linux server from Ubuntu 14.04 to 16.04. Since then, I do get the error 401, and

[Tue Aug 02 22:01:08.951619 2016] [:error] [pid 6987] [client 87.152.248.203:50419] davical: LOG: :Server is not supplying PATH_INFO and REQUEST_URI does not include a PHP program. Wildly
guessing "/"!!!

when connecting with any of these devices. However, a

curl -X PROPFIND https://<server>/principals/caldav.php/<user> -u <user>

(or a curl access to one of the calendars)

works just fineâ€¦
This is with davical 1.1.4 and Apache 2.4.18.

I saw that FastCGI may cause problems, but I donâ€™t have it installed. I am a little bit at a loss hereâ€¦ Any help is greatly appreciated.

Best regards,
Jan

Apache2 error log:

[Tue Aug 02 22:07:14.709399 2016] [socache_shmcb:debug] [pid 6989] mod_socache_shmcb.c(491): AH00831: socache_shmcb_store (0x6e -> subcache 14)
[Tue Aug 02 22:07:14.709481 2016] [socache_shmcb:debug] [pid 6989] mod_socache_shmcb.c(845): AH00847: insert happened at idx=0, data=(0:32)
[Tue Aug 02 22:07:14.709494 2016] [socache_shmcb:debug] [pid 6989] mod_socache_shmcb.c(850): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/207
[Tue Aug 02 22:07:14.709544 2016] [socache_shmcb:debug] [pid 6989] mod_socache_shmcb.c(512): AH00834: leaving socache_shmcb_store successfully
[Tue Aug 02 22:07:14.712619 2016] [ssl:debug] [pid 6989] ssl_engine_kernel.c(354): [client 87.152.248.203:50468] AH02034: Initial (No.1) HTTPS request received for child 4 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.712781 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.712800 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.712993 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.713015 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.729827 2016] [ssl:debug] [pid 6989] ssl_engine_kernel.c(354): [client 87.152.248.203:50468] AH02034: Subsequent (No.2) HTTPS request received for child 4 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.729974 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.729989 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.730163 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.730176 2016] [authz_core:debug] [pid 6989] mod_authz_core.c(809): [client 87.152.248.203:50468] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.741076 2016] [ssl:debug] [pid 6989] ssl_engine_io.c(1016): [client 87.152.248.203:50468] AH02001: Connection closed to child 4 with standard shutdown (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.760192 2016] [ssl:debug] [pid 6986] ssl_engine_kernel.c(354): [client 87.152.248.203:50469] AH02034: Initial (No.1) HTTPS request received for child 1 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.760257 2016] [authz_core:debug] [pid 6986] mod_authz_core.c(809): [client 87.152.248.203:50469] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.760263 2016] [authz_core:debug] [pid 6986] mod_authz_core.c(809): [client 87.152.248.203:50469] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.760342 2016] [authz_core:debug] [pid 6986] mod_authz_core.c(809): [client 87.152.248.203:50469] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.760356 2016] [authz_core:debug] [pid 6986] mod_authz_core.c(809): [client 87.152.248.203:50469] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.767567 2016] [ssl:debug] [pid 6986] ssl_engine_io.c(1016): [client 87.152.248.203:50469] AH02001: Connection closed to child 1 with standard shutdown (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.786267 2016] [ssl:debug] [pid 7162] ssl_engine_kernel.c(354): [client 87.152.248.203:50470] AH02034: Initial (No.1) HTTPS request received for child 5 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.786339 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.786346 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.786400 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.786414 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.797435 2016] [ssl:debug] [pid 7162] ssl_engine_kernel.c(354): [client 87.152.248.203:50470] AH02034: Subsequent (No.2) HTTPS request received for child 5 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.797506 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.797511 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.797566 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.797570 2016] [authz_core:debug] [pid 7162] mod_authz_core.c(809): [client 87.152.248.203:50470] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.804854 2016] [ssl:debug] [pid 7162] ssl_engine_io.c(1016): [client 87.152.248.203:50470] AH02001: Connection closed to child 5 with standard shutdown (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.824072 2016] [ssl:debug] [pid 6985] ssl_engine_kernel.c(354): [client 87.152.248.203:50471] AH02034: Initial (No.1) HTTPS request received for child 0 (server cal.aegeon.homeunix.net:443)
[Tue Aug 02 22:07:14.824137 2016] [authz_core:debug] [pid 6985] mod_authz_core.c(809): [client 87.152.248.203:50471] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.824142 2016] [authz_core:debug] [pid 6985] mod_authz_core.c(809): [client 87.152.248.203:50471] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.824195 2016] [authz_core:debug] [pid 6985] mod_authz_core.c(809): [client 87.152.248.203:50471] AH01626: authorization result of Require all granted: granted
[Tue Aug 02 22:07:14.824200 2016] [authz_core:debug] [pid 6985] mod_authz_core.c(809): [client 87.152.248.203:50471] AH01626: authorization result of <RequireAny>: granted
[Tue Aug 02 22:07:14.828492 2016] [:error] [pid 6985] [client 87.152.248.203:50471] davical: LOG: :Server is not supplying PATH_INFO and REQUEST_URI does not include a PHP program. Wildly guessing "/"!!!
[Tue Aug 02 22:07:14.831358 2016] [ssl:debug] [pid 6985] ssl_engine_io.c(1016): [client 87.152.248.203:50471] AH02001: Connection closed to child 0 with standard shutdown (server cal.aegeon.homeunix.net:443)

Apache2 access log:
87.152.248.203 - - [02/Aug/2016:22:08:06 +0200] "PROPFIND /principals/caldav.php/jan/ HTTP/1.1" 401 524
87.152.248.203 - jan [02/Aug/2016:22:08:06 +0200] "PROPFIND /principals/caldav.php/jan/ HTTP/1.1" 500 485
87.152.248.203 - jan [02/Aug/2016:22:08:06 +0200] "PROPFIND /principals/caldav.php/jan/ HTTP/1.1" 500 622
87.152.248.203 - - [02/Aug/2016:22:08:06 +0200] "PROPFIND / HTTP/1.1" 401 509
87.152.248.203 - jan [02/Aug/2016:22:08:06 +0200] "PROPFIND / HTTP/1.1" 500 534
87.152.248.203 - jan [02/Aug/2016:22:08:06 +0200] "PROPFIND /principals/ HTTP/1.1" 500 671

------------------------------------------------------------------------------
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general

Hi

I am still trying to find what is wrong. I found out that I was running three versions of postgresql (9.1, 9.3, 9.5). Completely purged the install and reinstalled (only) 9.5.

I also stumbled across the Administration->Setup. I kind of missed this while walking through the log filesâ€¦

There I found this:
DAViCal DB Schema version Want: 1.2.12, Currently: 1.3.2 Explanation on DAViCal Wiki <http://wiki.davical.org/w/Setup_Failure_Codes/DAViCal%20DB%20Schema%20version%20>
Seems like I got a future version of the DB schema? How can this happen?

Anyhow, after installing the latest git sources for awl and davical (and installing php-xml) it just started working again while I was typing this mailâ€¦
(I still do get the DB Schema mismatch thoughâ€¦)

Regards,
Jan

> On 05 Aug 2016, at 22:00, Jan Norden <jan@makro-kosmos.de> wrote:
>
> Hi
>
> I still havenâ€™t found anything. I updated to the latest davical version from GitLab, I got the same resultsâ€¦
>
> BTW, my apache configuration follows the Wiki:
>
> <IfModule mod_ssl.c>
> <VirtualHost *:443>
> ServerAdmin [xxx]
> DocumentRoot /usr/share/davical/htdocs
> DirectoryIndex index.php index.html
> ServerName cal.aegeon.homeunix.net
> Alias /images/ /usr/share/davical/htdocs/images/
> AcceptPathInfo On
> <Directory /usr/share/davical/htdocs/>
> AllowOverride None
> Require all granted
> </Directory>
> # php_value include_path /usr/share/awl/inc
> php_value magic_quotes_gpc Off
> php_value register_globals Off
> php_value error_reporting "E_ALL"
> # & ~E_NOTICE"
> php_value default_charset "utf-8"
>
> SSLCertificateFile /etc/letsencrypt/live/[xxx]/cert.pem
> SSLCertificateKeyFile /etc/letsencrypt/live/[xxx]/privkey.pem
> Include /etc/letsencrypt/options-ssl-apache.conf
>
>
> ErrorLog ${APACHE_LOG_DIR}/cal_error.log
> CustomLog ${APACHE_LOG_DIR}/cal.log common
>
> SSLCertificateChainFile /etc/letsencrypt/live/[xxx]/chain.pem
> </VirtualHost>
> </IfModule>
>
> Best regards,
> Jan
>
>
> ------------------------------------------------------------------------------
> _______________________________________________
> Davical-general mailing list
> Davical-general@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/davical-general