Advanced
Mailing List Archive

Mailing List Archive

  1. Home >
  2. DAViCal>
  3. General
Failures upgrading ubuntu 15.10 -> 16.04 php7 ?
davical at antoin
Apr 24, 2016, 2:49 PM
Post #1 of 16 (4927 views)
Permalink
Hi all,

This is my first message to this list.
I’m not a postgresql or php expert, but I do know my way around.

I have recently upgraded my ubuntu server from 15.10 to 16.04, and everything works, except davical ;-(.

Since I’ve upgraded, my clients get errors, don’t connect, or don’t update.
I first thought it was the davical database, since it had problems with the update-davical-database script.
It had multiple version entires in the awl_db_revision table, but SELECT check_db_revision(1,2,11); failed anyway, saying the Database has not been upgraded to 1.2.11.
I fixed that, but didn’t help.

So I created a brand new DB with new users with the create-database.sh script running as postgres, and tested again, but still the same errors on the clients.
I restored a dump from my current database from 2 months ago, and still the same errors.
I can access my DB and users with the davical administration webinterface, so the DB looks ok, but clients fail.
Most android clients (davdroid, caldav-sync) don’t give errors, but fail to update.
All my IOS/OSX clients give me this error: '500' 'CalDAVAccountRefreshQueueableOperation'.

I was wondering if the upgrade from php5.6 to 7.0 had anything to do with it.
PHP5.6 is no longer in ubuntu 16:04, so mod_php5 is disabled in apache2, and mod_php7.0 is enabled.

I’ve upgraded the logging with $c->dbg = array( 'statistics' => 1, 'request' => 1, 'response' => 1 ); in my site config, and this is what I get. I see no real errors:

[Sun Apr 24 22:18:39.231962 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: :***************** Request Header ****************
[Sun Apr 24 22:18:39.232107 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: :PROPFIND /cal/caldav.php/test/
[Sun Apr 24 22:18:39.232161 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Host: bla.foo.bar
[Sun Apr 24 22:18:39.232211 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Content-Type: text/xml
[Sun Apr 24 22:18:39.232270 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Depth: 0
[Sun Apr 24 22:18:39.232338 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Brief: t
[Sun Apr 24 22:18:39.232397 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Accept: */*
[Sun Apr 24 22:18:39.232462 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Connection: keep-alive
[Sun Apr 24 22:18:39.232516 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Prefer: return-minimal
[Sun Apr 24 22:18:39.232591 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Sun Apr 24 22:18:39.232652 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Content-Length: 743
[Sun Apr 24 22:18:39.232714 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Accept-Language: nl-nl
[Sun Apr 24 22:18:39.232770 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Sun Apr 24 22:18:39.232839 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: :******************** Request ********************
[Sun Apr 24 22:18:39.232935 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Sun Apr 24 22:18:39.232990 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Sun Apr 24 22:18:39.233041 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:prop>
[Sun Apr 24 22:18:39.233105 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.233170 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.233225 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:current-user-principal/>
[Sun Apr 24 22:18:39.233295 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:displayname/>
[Sun Apr 24 22:18:39.233343 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.233391 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.233445 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.233493 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:principal-collection-set/>
[Sun Apr 24 22:18:39.233549 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:principal-URL/>
[Sun Apr 24 22:18:39.233595 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:resource-id/>
[Sun Apr 24 22:18:39.233654 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.233769 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.233816 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> <A:supported-report-set/>
[Sun Apr 24 22:18:39.233862 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--> </A:prop>
[Sun Apr 24 22:18:39.233915 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:--></A:propfind>
[Sun Apr 24 22:18:39.233960 2016] [:error] [pid 9809] [client 192.168.0.1:50868] davical: LOG: request:-->
[Sun Apr 24 22:18:39.321577 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: :***************** Request Header ****************
[Sun Apr 24 22:18:39.321698 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: :PROPFIND /cal/caldav.php/test/
[Sun Apr 24 22:18:39.321749 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Host: bla.foo.bar
[Sun Apr 24 22:18:39.321799 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Accept: */*
[Sun Apr 24 22:18:39.321845 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Brief: t
[Sun Apr 24 22:18:39.321894 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
[Sun Apr 24 22:18:39.321940 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Accept-Language: nl-nl
[Sun Apr 24 22:18:39.321985 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Sun Apr 24 22:18:39.322030 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Content-Type: text/xml
[Sun Apr 24 22:18:39.322076 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Content-Length: 743
[Sun Apr 24 22:18:39.322121 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Depth: 0
[Sun Apr 24 22:18:39.322166 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Connection: keep-alive
[Sun Apr 24 22:18:39.322225 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Sun Apr 24 22:18:39.322271 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: headers:-->Prefer: return-minimal
[Sun Apr 24 22:18:39.322325 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: :******************** Request ********************
[Sun Apr 24 22:18:39.322547 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Sun Apr 24 22:18:39.322637 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Sun Apr 24 22:18:39.322693 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:prop>
[Sun Apr 24 22:18:39.322741 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.322793 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.322847 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:current-user-principal/>
[Sun Apr 24 22:18:39.322901 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:displayname/>
[Sun Apr 24 22:18:39.322949 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.323008 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.323193 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
[Sun Apr 24 22:18:39.323243 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:principal-collection-set/>
[Sun Apr 24 22:18:39.323289 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:principal-URL/>
[Sun Apr 24 22:18:39.323341 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:resource-id/>
[Sun Apr 24 22:18:39.323387 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.323442 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Sun Apr 24 22:18:39.323488 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> <A:supported-report-set/>
[Sun Apr 24 22:18:39.323533 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--> </A:prop>
[Sun Apr 24 22:18:39.323586 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:--></A:propfind>
[Sun Apr 24 22:18:39.323633 2016] [:error] [pid 9993] [client 192.168.0.1:50869] davical: LOG: request:-->
[Sun Apr 24 22:18:39.547326 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: :***************** Request Header ****************
[Sun Apr 24 22:18:39.547451 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: :PROPFIND /cal/caldav.php/test/
[Sun Apr 24 22:18:39.547503 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Host: bla.foo.bar
[Sun Apr 24 22:18:39.547551 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Accept: */*
[Sun Apr 24 22:18:39.547595 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Brief: t
[Sun Apr 24 22:18:39.547643 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
[Sun Apr 24 22:18:39.547697 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Accept-Language: nl-nl
[Sun Apr 24 22:18:39.547742 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Sun Apr 24 22:18:39.547789 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Content-Type: text/xml
[Sun Apr 24 22:18:39.547867 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Content-Length: 170
[Sun Apr 24 22:18:39.547924 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Depth: 0
[Sun Apr 24 22:18:39.547977 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Connection: keep-alive
[Sun Apr 24 22:18:39.548035 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Sun Apr 24 22:18:39.548086 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: headers:-->Prefer: return-minimal
[Sun Apr 24 22:18:39.548131 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: :******************** Request ********************
[Sun Apr 24 22:18:39.548193 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Sun Apr 24 22:18:39.548246 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Sun Apr 24 22:18:39.548291 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--> <A:prop>
[Sun Apr 24 22:18:39.548336 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--> <A:current-user-principal/>
[Sun Apr 24 22:18:39.548390 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--> <A:principal-collection-set/>
[Sun Apr 24 22:18:39.548485 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--> </A:prop>
[Sun Apr 24 22:18:39.548531 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:--></A:propfind>
[Sun Apr 24 22:18:39.548582 2016] [:error] [pid 15586] [client 192.168.0.1:50870] davical: LOG: request:-->

This is what my site config looks like:

<?php
// $c->domain_name = „bla.foo.bar";
// $c->sysabbr = 'rscds';
$c->admin_email = 'netmaster@foo.bar';
$c->system_name = "bla CalDAV Store";
// $c->collections_always_exist = true;
// $c->enable_row_linking = true;
$c->default_locale = "nl_NL";
$c->pg_connect[] = 'dbname=davical port=5432 user=davical_app';
$c->dbg = array( 'statistics' => 1, 'request' => 1, 'response' => 1 );
?>

and this is my apache2 davical site:

<VirtualHost 192.168.0.2:80>
DocumentRoot /usr/share/davical/htdocs
DirectoryIndex index.php index.html
ServerName bla.foo.bar
ServerAlias calendar.bla.foo.bar
Alias /images/ /usr/share/davical/htdocs/images/
<Directory /usr/share/davical/htdocs/>
AllowOverride None
Order allow,deny
Allow from all
</Directory>
php_value include_path /usr/share/awl/inc
php_value magic_quotes_gpc 0
php_value register_globals 0
php_value open_basedir 1
php_value error_reporting "E_ALL & ~E_NOTICE"
php_value default_charset "utf-8"
</VirtualHost>

my databases:
postgres@foo:~$ pg_lsclusters
Ver Cluster Port Status Owner Data directory Log file
8.4 main 5434 down postgres /var/lib/postgresql/8.4/main /var/log/postgresql/postgresql-8.4-main.log
9.4 main 5432 online postgres /var/lib/postgresql/9.4/main /var/log/postgresql/postgresql-9.4-main.log
9.5 main 5433 online postgres /var/lib/postgresql/9.5/main /var/log/postgresql/postgresql-9.5-main.log

(I have my original davical database in 9.4, and created a new one in 9.5 changing the port numbers and restarting postresql)

Where does this go wrong?
Any help would be appreciated.
I think the issue is somewhere in the php7 upgrade, but I don’t know where…
If you need more info, please ask..

Antoin









------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 25, 2016, 8:15 AM
Post #2 of 16 (4896 views)
Permalink
Ok, so I still get these '500’ server errors when invoking 'CalDAVAccountRefreshQueueableOperation’ in iCal, and no responses in other clients.
I’ve tracked it down that it has to be a php7 or apache config thing, as I only see responses in the debug log when I type in a caldav url in a browser doing a GET request for a calendar.
So my question is: Why don’t I get responses to PROPFIND or other requests?

So I tried this again, this time with full debug logging:

[Mon Apr 25 17:00:18.697045 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
[Mon Apr 25 17:00:18.697240 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
[Mon Apr 25 17:00:18.697365 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: caldav:Version (1.1.4) == 1001.4
[Mon Apr 25 17:00:18.697772 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
[Mon Apr 25 17:00:18.711231 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,003685 to find 1 rows.
[Mon Apr 25 17:00:18.711816 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
[Mon Apr 25 17:00:18.711984 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: "0" => "UTC"
[Mon Apr 25 17:00:18.713420 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,001189 to find 0 rows.
[Mon Apr 25 17:00:18.714164 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :***************** Request Header ****************
[Mon Apr 25 17:00:18.714282 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
[Mon Apr 25 17:00:18.714350 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Host: bla.foo.bar
[Mon Apr 25 17:00:18.714710 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Type: text/xml
[Mon Apr 25 17:00:18.714913 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Depth: 0
[Mon Apr 25 17:00:18.714994 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Brief: t
[Mon Apr 25 17:00:18.715066 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept: */*
[Mon Apr 25 17:00:18.715134 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Connection: keep-alive
[Mon Apr 25 17:00:18.715203 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Prefer: return-minimal
[Mon Apr 25 17:00:18.715272 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Mon Apr 25 17:00:18.715340 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Length: 743
[Mon Apr 25 17:00:18.715410 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Language: nl-nl
[Mon Apr 25 17:00:18.715476 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Mon Apr 25 17:00:18.715542 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :******************** Request ********************
[Mon Apr 25 17:00:18.715647 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Mon Apr 25 17:00:18.715721 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Mon Apr 25 17:00:18.715789 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:prop>
[Mon Apr 25 17:00:18.715853 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.715921 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.716049 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:current-user-principal/>
[Mon Apr 25 17:00:18.716115 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:displayname/>
[Mon Apr 25 17:00:18.716178 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.716241 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.716306 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.716371 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-collection-set/>
[Mon Apr 25 17:00:18.716431 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-URL/>
[Mon Apr 25 17:00:18.716597 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:resource-id/>
[Mon Apr 25 17:00:18.716676 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.716741 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.716806 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:supported-report-set/>
[Mon Apr 25 17:00:18.716868 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> </A:prop>
[Mon Apr 25 17:00:18.716934 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--></A:propfind>
[Mon Apr 25 17:00:18.716997 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:-->
[Mon Apr 25 17:00:18.717166 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::AuthFailedResponse Requesting authentication in the 'bla CalDAV Store' realm
[Mon Apr 25 17:00:18.717298 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::Session: User is not authorised: 192.168.0.1
[Mon Apr 25 17:00:18.851119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
[Mon Apr 25 17:00:18.851300 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
[Mon Apr 25 17:00:18.851415 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Version (1.1.4) == 1001.4
[Mon Apr 25 17:00:18.851687 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
[Mon Apr 25 17:00:18.864895 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,003775 to find 1 rows.
[Mon Apr 25 17:00:18.865461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
[Mon Apr 25 17:00:18.865595 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: "0" => "UTC"
[Mon Apr 25 17:00:18.867140 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,001321 to find 0 rows.
[Mon Apr 25 17:00:18.867736 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :***************** Request Header ****************
[Mon Apr 25 17:00:18.867854 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
[Mon Apr 25 17:00:18.867918 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Host: bla.foo.bar
[Mon Apr 25 17:00:18.868028 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept: */*
[Mon Apr 25 17:00:18.868093 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Brief: t
[Mon Apr 25 17:00:18.868167 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
[Mon Apr 25 17:00:18.868243 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Language: nl-nl
[Mon Apr 25 17:00:18.868311 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Mon Apr 25 17:00:18.868385 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Type: text/xml
[Mon Apr 25 17:00:18.868461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Length: 743
[Mon Apr 25 17:00:18.868533 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Depth: 0
[Mon Apr 25 17:00:18.868604 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Connection: keep-alive
[Mon Apr 25 17:00:18.868676 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Mon Apr 25 17:00:18.868750 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Prefer: return-minimal
[Mon Apr 25 17:00:18.868818 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :******************** Request ********************
[Mon Apr 25 17:00:18.868929 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Mon Apr 25 17:00:18.869009 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Mon Apr 25 17:00:18.869077 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:prop>
[Mon Apr 25 17:00:18.869147 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.869222 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.869293 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:current-user-principal/>
[Mon Apr 25 17:00:18.869365 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:displayname/>
[Mon Apr 25 17:00:18.869437 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.869501 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.869561 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
[Mon Apr 25 17:00:18.869630 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-collection-set/>
[Mon Apr 25 17:00:18.869705 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-URL/>
[Mon Apr 25 17:00:18.869777 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:resource-id/>
[Mon Apr 25 17:00:18.869849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.869922 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
[Mon Apr 25 17:00:18.869993 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:supported-report-set/>
[Mon Apr 25 17:00:18.870110 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> </A:prop>
[Mon Apr 25 17:00:18.870184 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--></A:propfind>
[Mon Apr 25 17:00:18.870253 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:-->
[Mon Apr 25 17:00:18.870528 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Cache:Using NoCache dummy interface
[Mon Apr 25 17:00:18.870744 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:18.870866 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:18.880880 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,009780 to find 1 rows.
[Mon Apr 25 17:00:18.881685 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
[Mon Apr 25 17:00:18.881826 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
[Mon Apr 25 17:00:18.884669 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002616 to find 0 rows.
[Mon Apr 25 17:00:18.885438 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
[Mon Apr 25 17:00:18.885712 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:18.885849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
[Mon Apr 25 17:00:18.885950 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
[Mon Apr 25 17:00:18.886047 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:18.893312 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,006948 to find 1 rows.
[Mon Apr 25 17:00:18.894007 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
[Mon Apr 25 17:00:18.894137 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
[Mon Apr 25 17:00:18.897982 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: Took: 0,003630 to find 1 rows.
[Mon Apr 25 17:00:18.898202 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
[Mon Apr 25 17:00:18.898340 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
[Mon Apr 25 17:00:18.898698 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:18.898859 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
[Mon Apr 25 17:00:18.898966 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
[Mon Apr 25 17:00:18.899066 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:18.902278 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,002899 to find 1 rows.
[Mon Apr 25 17:00:18.903119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
[Mon Apr 25 17:00:18.903245 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
[Mon Apr 25 17:00:18.903336 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
[Mon Apr 25 17:00:18.912907 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009329 to find 0 rows.
[Mon Apr 25 17:00:18.913051 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
[Mon Apr 25 17:00:18.913547 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
[Mon Apr 25 17:00:19.035250 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
[Mon Apr 25 17:00:19.035441 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
[Mon Apr 25 17:00:19.035558 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Version (1.1.4) == 1001.4
[Mon Apr 25 17:00:19.035902 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
[Mon Apr 25 17:00:19.048977 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,003744 to find 1 rows.
[Mon Apr 25 17:00:19.049762 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
[Mon Apr 25 17:00:19.049895 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: "0" => "UTC"
[Mon Apr 25 17:00:19.051412 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,001303 to find 0 rows.
[Mon Apr 25 17:00:19.051990 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :***************** Request Header ****************
[Mon Apr 25 17:00:19.052115 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
[Mon Apr 25 17:00:19.052180 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Host: bla.foo.bar
[Mon Apr 25 17:00:19.052252 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept: */*
[Mon Apr 25 17:00:19.052315 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Brief: t
[Mon Apr 25 17:00:19.052393 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
[Mon Apr 25 17:00:19.052469 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Language: nl-nl
[Mon Apr 25 17:00:19.052543 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
[Mon Apr 25 17:00:19.052618 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Type: text/xml
[Mon Apr 25 17:00:19.052692 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Length: 170
[Mon Apr 25 17:00:19.052764 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Depth: 0
[Mon Apr 25 17:00:19.052837 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Connection: keep-alive
[Mon Apr 25 17:00:19.052968 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
[Mon Apr 25 17:00:19.053042 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Prefer: return-minimal
[Mon Apr 25 17:00:19.053116 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :******************** Request ********************
[Mon Apr 25 17:00:19.053215 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
[Mon Apr 25 17:00:19.053295 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
[Mon Apr 25 17:00:19.053370 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:prop>
[Mon Apr 25 17:00:19.053429 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:current-user-principal/>
[Mon Apr 25 17:00:19.053490 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:principal-collection-set/>
[Mon Apr 25 17:00:19.053565 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> </A:prop>
[Mon Apr 25 17:00:19.053638 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--></A:propfind>
[Mon Apr 25 17:00:19.053703 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:-->
[Mon Apr 25 17:00:19.053873 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Cache:Using NoCache dummy interface
[Mon Apr 25 17:00:19.054056 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:19.054174 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:19.064259 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,009842 to find 1 rows.
[Mon Apr 25 17:00:19.065063 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
[Mon Apr 25 17:00:19.065209 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
[Mon Apr 25 17:00:19.068012 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002565 to find 0 rows.
[Mon Apr 25 17:00:19.068725 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
[Mon Apr 25 17:00:19.069004 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:19.069142 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
[Mon Apr 25 17:00:19.069241 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
[Mon Apr 25 17:00:19.069339 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:19.076562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,006915 to find 1 rows.
[Mon Apr 25 17:00:19.077251 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
[Mon Apr 25 17:00:19.077384 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
[Mon Apr 25 17:00:19.081189 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: Took: 0,003595 to find 1 rows.
[Mon Apr 25 17:00:19.081462 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
[Mon Apr 25 17:00:19.081605 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
[Mon Apr 25 17:00:19.081855 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
[Mon Apr 25 17:00:19.081998 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
[Mon Apr 25 17:00:19.082101 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
[Mon Apr 25 17:00:19.082200 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
[Mon Apr 25 17:00:19.085530 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,002912 to find 1 rows.
[Mon Apr 25 17:00:19.086256 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
[Mon Apr 25 17:00:19.086374 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
[Mon Apr 25 17:00:19.086562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
[Mon Apr 25 17:00:19.096117 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009290 to find 0 rows.
[Mon Apr 25 17:00:19.096260 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
[Mon Apr 25 17:00:19.096761 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Full permissions for user accessing their own hierarchy

And there the logging stops. No response.
Any idea where I should start searching?


Op 24 apr. 2016, om 23:49 heeft Antoin Verschuren <davical@antoin.nl> het volgende geschreven:

> Hi all,
>
> This is my first message to this list.
> I’m not a postgresql or php expert, but I do know my way around.
>
> I have recently upgraded my ubuntu server from 15.10 to 16.04, and everything works, except davical ;-(.
>
> Since I’ve upgraded, my clients get errors, don’t connect, or don’t update.
> I first thought it was the davical database, since it had problems with the update-davical-database script.
> It had multiple version entires in the awl_db_revision table, but SELECT check_db_revision(1,2,11); failed anyway, saying the Database has not been upgraded to 1.2.11.
> I fixed that, but didn’t help.
>
> So I created a brand new DB with new users with the create-database.sh script running as postgres, and tested again, but still the same errors on the clients.
> I restored a dump from my current database from 2 months ago, and still the same errors.
> I can access my DB and users with the davical administration webinterface, so the DB looks ok, but clients fail.
> Most android clients (davdroid, caldav-sync) don’t give errors, but fail to update.
> All my IOS/OSX clients give me this error: '500' 'CalDAVAccountRefreshQueueableOperation'.
>
> I was wondering if the upgrade from php5.6 to 7.0 had anything to do with it.
> PHP5.6 is no longer in ubuntu 16:04, so mod_php5 is disabled in apache2, and mod_php7.0 is enabled.
>
>
> ------------------------------------------------------------------------------
> Find and fix application performance issues faster with Applications Manager
> Applications Manager provides deep performance insights into multiple tiers of
> your business applications. It resolves application problems quickly and
> reduces your MTTR. Get your free trial!
> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
> _______________________________________________
> Davical-general mailing list
> Davical-general@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/davical-general


------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
ingo at envirology
Apr 25, 2016, 1:59 PM
Post #3 of 16 (4895 views)
Permalink
Hi,

PHP7 breaks a whole lot of things. From what I can see nothing too
mayor, but still annoyingly enough.

Start here: http://php.net/manual/en/migration70.php

Have a look in your apache error log for fatal PHP errors to start.

I do not know DaviCal's internals, but if it catches exceptions, you may
not even find any fatal php errors due to this:

"Many fatal and recoverable fatal errors have been converted to
exceptions in PHP 7. These error exceptions inherit from the Error
class, which itself implements the Throwable interface (the new base
interface all exceptions inherit).
This means that custom error handlers may no longer be triggered because
exceptions may be thrown instead (causing new fatal errors for uncaught
Error exceptions)."

Cheers,
Ingo

On 26-Apr-16 3:15, Antoin Verschuren wrote:
> Ok, so I still get these '500’ server errors when invoking 'CalDAVAccountRefreshQueueableOperation’ in iCal, and no responses in other clients.
> I’ve tracked it down that it has to be a php7 or apache config thing, as I only see responses in the debug log when I type in a caldav url in a browser doing a GET request for a calendar.
> So my question is: Why don’t I get responses to PROPFIND or other requests?
>
> So I tried this again, this time with full debug logging:
>
> [Mon Apr 25 17:00:18.697045 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
> [Mon Apr 25 17:00:18.697240 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
> [Mon Apr 25 17:00:18.697365 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: caldav:Version (1.1.4) == 1001.4
> [Mon Apr 25 17:00:18.697772 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
> [Mon Apr 25 17:00:18.711231 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,003685 to find 1 rows.
> [Mon Apr 25 17:00:18.711816 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
> [Mon Apr 25 17:00:18.711984 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: "0" => "UTC"
> [Mon Apr 25 17:00:18.713420 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,001189 to find 0 rows.
> [Mon Apr 25 17:00:18.714164 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :***************** Request Header ****************
> [Mon Apr 25 17:00:18.714282 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
> [Mon Apr 25 17:00:18.714350 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Host: bla.foo.bar
> [Mon Apr 25 17:00:18.714710 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Type: text/xml
> [Mon Apr 25 17:00:18.714913 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Depth: 0
> [Mon Apr 25 17:00:18.714994 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Brief: t
> [Mon Apr 25 17:00:18.715066 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept: */*
> [Mon Apr 25 17:00:18.715134 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Connection: keep-alive
> [Mon Apr 25 17:00:18.715203 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Prefer: return-minimal
> [Mon Apr 25 17:00:18.715272 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
> [Mon Apr 25 17:00:18.715340 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Length: 743
> [Mon Apr 25 17:00:18.715410 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Language: nl-nl
> [Mon Apr 25 17:00:18.715476 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
> [Mon Apr 25 17:00:18.715542 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :******************** Request ********************
> [Mon Apr 25 17:00:18.715647 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
> [Mon Apr 25 17:00:18.715721 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
> [Mon Apr 25 17:00:18.715789 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:prop>
> [Mon Apr 25 17:00:18.715853 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.715921 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.716049 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:current-user-principal/>
> [Mon Apr 25 17:00:18.716115 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:displayname/>
> [Mon Apr 25 17:00:18.716178 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.716241 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.716306 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.716371 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-collection-set/>
> [Mon Apr 25 17:00:18.716431 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-URL/>
> [Mon Apr 25 17:00:18.716597 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:resource-id/>
> [Mon Apr 25 17:00:18.716676 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.716741 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.716806 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:supported-report-set/>
> [Mon Apr 25 17:00:18.716868 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> </A:prop>
> [Mon Apr 25 17:00:18.716934 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--></A:propfind>
> [Mon Apr 25 17:00:18.716997 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:-->
> [Mon Apr 25 17:00:18.717166 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::AuthFailedResponse Requesting authentication in the 'bla CalDAV Store' realm
> [Mon Apr 25 17:00:18.717298 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::Session: User is not authorised: 192.168.0.1
> [Mon Apr 25 17:00:18.851119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
> [Mon Apr 25 17:00:18.851300 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
> [Mon Apr 25 17:00:18.851415 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Version (1.1.4) == 1001.4
> [Mon Apr 25 17:00:18.851687 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
> [Mon Apr 25 17:00:18.864895 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,003775 to find 1 rows.
> [Mon Apr 25 17:00:18.865461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
> [Mon Apr 25 17:00:18.865595 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: "0" => "UTC"
> [Mon Apr 25 17:00:18.867140 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,001321 to find 0 rows.
> [Mon Apr 25 17:00:18.867736 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :***************** Request Header ****************
> [Mon Apr 25 17:00:18.867854 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
> [Mon Apr 25 17:00:18.867918 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Host: bla.foo.bar
> [Mon Apr 25 17:00:18.868028 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept: */*
> [Mon Apr 25 17:00:18.868093 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Brief: t
> [Mon Apr 25 17:00:18.868167 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
> [Mon Apr 25 17:00:18.868243 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Language: nl-nl
> [Mon Apr 25 17:00:18.868311 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
> [Mon Apr 25 17:00:18.868385 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Type: text/xml
> [Mon Apr 25 17:00:18.868461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Length: 743
> [Mon Apr 25 17:00:18.868533 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Depth: 0
> [Mon Apr 25 17:00:18.868604 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Connection: keep-alive
> [Mon Apr 25 17:00:18.868676 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
> [Mon Apr 25 17:00:18.868750 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Prefer: return-minimal
> [Mon Apr 25 17:00:18.868818 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :******************** Request ********************
> [Mon Apr 25 17:00:18.868929 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
> [Mon Apr 25 17:00:18.869009 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
> [Mon Apr 25 17:00:18.869077 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:prop>
> [Mon Apr 25 17:00:18.869147 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.869222 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.869293 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:current-user-principal/>
> [Mon Apr 25 17:00:18.869365 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:displayname/>
> [Mon Apr 25 17:00:18.869437 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.869501 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.869561 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
> [Mon Apr 25 17:00:18.869630 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-collection-set/>
> [Mon Apr 25 17:00:18.869705 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-URL/>
> [Mon Apr 25 17:00:18.869777 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:resource-id/>
> [Mon Apr 25 17:00:18.869849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.869922 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
> [Mon Apr 25 17:00:18.869993 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:supported-report-set/>
> [Mon Apr 25 17:00:18.870110 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> </A:prop>
> [Mon Apr 25 17:00:18.870184 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--></A:propfind>
> [Mon Apr 25 17:00:18.870253 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:-->
> [Mon Apr 25 17:00:18.870528 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Cache:Using NoCache dummy interface
> [Mon Apr 25 17:00:18.870744 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:18.870866 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:18.880880 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,009780 to find 1 rows.
> [Mon Apr 25 17:00:18.881685 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
> [Mon Apr 25 17:00:18.881826 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
> [Mon Apr 25 17:00:18.884669 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002616 to find 0 rows.
> [Mon Apr 25 17:00:18.885438 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
> [Mon Apr 25 17:00:18.885712 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:18.885849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
> [Mon Apr 25 17:00:18.885950 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
> [Mon Apr 25 17:00:18.886047 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:18.893312 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,006948 to find 1 rows.
> [Mon Apr 25 17:00:18.894007 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
> [Mon Apr 25 17:00:18.894137 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
> [Mon Apr 25 17:00:18.897982 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: Took: 0,003630 to find 1 rows.
> [Mon Apr 25 17:00:18.898202 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
> [Mon Apr 25 17:00:18.898340 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
> [Mon Apr 25 17:00:18.898698 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:18.898859 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
> [Mon Apr 25 17:00:18.898966 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
> [Mon Apr 25 17:00:18.899066 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:18.902278 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,002899 to find 1 rows.
> [Mon Apr 25 17:00:18.903119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
> [Mon Apr 25 17:00:18.903245 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
> [Mon Apr 25 17:00:18.903336 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
> [Mon Apr 25 17:00:18.912907 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009329 to find 0 rows.
> [Mon Apr 25 17:00:18.913051 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
> [Mon Apr 25 17:00:18.913547 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
> [Mon Apr 25 17:00:19.035250 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
> [Mon Apr 25 17:00:19.035441 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
> [Mon Apr 25 17:00:19.035558 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Version (1.1.4) == 1001.4
> [Mon Apr 25 17:00:19.035902 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
> [Mon Apr 25 17:00:19.048977 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,003744 to find 1 rows.
> [Mon Apr 25 17:00:19.049762 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
> [Mon Apr 25 17:00:19.049895 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: "0" => "UTC"
> [Mon Apr 25 17:00:19.051412 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,001303 to find 0 rows.
> [Mon Apr 25 17:00:19.051990 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :***************** Request Header ****************
> [Mon Apr 25 17:00:19.052115 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
> [Mon Apr 25 17:00:19.052180 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Host: bla.foo.bar
> [Mon Apr 25 17:00:19.052252 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept: */*
> [Mon Apr 25 17:00:19.052315 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Brief: t
> [Mon Apr 25 17:00:19.052393 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
> [Mon Apr 25 17:00:19.052469 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Language: nl-nl
> [Mon Apr 25 17:00:19.052543 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
> [Mon Apr 25 17:00:19.052618 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Type: text/xml
> [Mon Apr 25 17:00:19.052692 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Length: 170
> [Mon Apr 25 17:00:19.052764 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Depth: 0
> [Mon Apr 25 17:00:19.052837 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Connection: keep-alive
> [Mon Apr 25 17:00:19.052968 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
> [Mon Apr 25 17:00:19.053042 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Prefer: return-minimal
> [Mon Apr 25 17:00:19.053116 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :******************** Request ********************
> [Mon Apr 25 17:00:19.053215 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
> [Mon Apr 25 17:00:19.053295 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
> [Mon Apr 25 17:00:19.053370 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:prop>
> [Mon Apr 25 17:00:19.053429 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:current-user-principal/>
> [Mon Apr 25 17:00:19.053490 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:principal-collection-set/>
> [Mon Apr 25 17:00:19.053565 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> </A:prop>
> [Mon Apr 25 17:00:19.053638 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--></A:propfind>
> [Mon Apr 25 17:00:19.053703 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:-->
> [Mon Apr 25 17:00:19.053873 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Cache:Using NoCache dummy interface
> [Mon Apr 25 17:00:19.054056 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:19.054174 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:19.064259 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,009842 to find 1 rows.
> [Mon Apr 25 17:00:19.065063 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
> [Mon Apr 25 17:00:19.065209 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
> [Mon Apr 25 17:00:19.068012 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002565 to find 0 rows.
> [Mon Apr 25 17:00:19.068725 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
> [Mon Apr 25 17:00:19.069004 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:19.069142 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
> [Mon Apr 25 17:00:19.069241 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
> [Mon Apr 25 17:00:19.069339 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:19.076562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,006915 to find 1 rows.
> [Mon Apr 25 17:00:19.077251 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
> [Mon Apr 25 17:00:19.077384 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
> [Mon Apr 25 17:00:19.081189 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: Took: 0,003595 to find 1 rows.
> [Mon Apr 25 17:00:19.081462 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
> [Mon Apr 25 17:00:19.081605 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
> [Mon Apr 25 17:00:19.081855 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
> [Mon Apr 25 17:00:19.081998 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
> [Mon Apr 25 17:00:19.082101 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
> [Mon Apr 25 17:00:19.082200 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
> [Mon Apr 25 17:00:19.085530 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,002912 to find 1 rows.
> [Mon Apr 25 17:00:19.086256 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
> [Mon Apr 25 17:00:19.086374 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
> [Mon Apr 25 17:00:19.086562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
> [Mon Apr 25 17:00:19.096117 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009290 to find 0 rows.
> [Mon Apr 25 17:00:19.096260 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
> [Mon Apr 25 17:00:19.096761 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
>
> And there the logging stops. No response.
> Any idea where I should start searching?
>
>
> Op 24 apr. 2016, om 23:49 heeft Antoin Verschuren <davical@antoin.nl> het volgende geschreven:
>
>> Hi all,
>>
>> This is my first message to this list.
>> I’m not a postgresql or php expert, but I do know my way around.
>>
>> I have recently upgraded my ubuntu server from 15.10 to 16.04, and everything works, except davical ;-(.
>>
>> Since I’ve upgraded, my clients get errors, don’t connect, or don’t update.
>> I first thought it was the davical database, since it had problems with the update-davical-database script.
>> It had multiple version entires in the awl_db_revision table, but SELECT check_db_revision(1,2,11); failed anyway, saying the Database has not been upgraded to 1.2.11.
>> I fixed that, but didn’t help.
>>
>> So I created a brand new DB with new users with the create-database.sh script running as postgres, and tested again, but still the same errors on the clients.
>> I restored a dump from my current database from 2 months ago, and still the same errors.
>> I can access my DB and users with the davical administration webinterface, so the DB looks ok, but clients fail.
>> Most android clients (davdroid, caldav-sync) don’t give errors, but fail to update.
>> All my IOS/OSX clients give me this error: '500' 'CalDAVAccountRefreshQueueableOperation'.
>>
>> I was wondering if the upgrade from php5.6 to 7.0 had anything to do with it.
>> PHP5.6 is no longer in ubuntu 16:04, so mod_php5 is disabled in apache2, and mod_php7.0 is enabled.
>>
>>
>> ------------------------------------------------------------------------------
>> Find and fix application performance issues faster with Applications Manager
>> Applications Manager provides deep performance insights into multiple tiers of
>> your business applications. It resolves application problems quickly and
>> reduces your MTTR. Get your free trial!
>> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
>> _______________________________________________
>> Davical-general mailing list
>> Davical-general@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/davical-general
>
>
> ------------------------------------------------------------------------------
> Find and fix application performance issues faster with Applications Manager
> Applications Manager provides deep performance insights into multiple tiers of
> your business applications. It resolves application problems quickly and
> reduces your MTTR. Get your free trial!
> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
> _______________________________________________
> Davical-general mailing list
> Davical-general@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/davical-general
>

--
Please consider the environment before printing this e-mail

Ingo Ratsdorf
B.E. Arch. / reg. Architect NZIA / Building Biologist IBN BBE / GSNZAP

*envirology* Ltd.*
*Envirology - a term combined from Environment
and the greek "logos" (word, reason, plan)

35 Taylor Road, Waimauku, 0882 Auckland
ph: (027) 8010652

info@envirology.co.nz <mailto:info@envirology.co.nz>
www.envirology.co.nz <http://www.envirology.co.nz/>
LinkedIn profile <http://www.linkedin.com/in/ingoratsdorf>

NOTE: This email message and any attachments contain information that
may be confidential and may be LEGALLY PRIVILEGED. If you are not the
intended recipient, any use, disclosure or copying of this message or
attachments is strictly prohibited. If you have received this email
message in error please notify us immediately and erase all copies of
the message and attachments. We do not accept responsibility for any
viruses or similar carried with our email, or any effects our email may
have on the recipient computer system or network. Any views expressed in
this email may be those of the individual sender and may not necessarily
reflect the views of Envirology Ltd.


------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 25, 2016, 4:10 PM
Post #4 of 16 (4892 views)
Permalink
Op 25 apr. 2016, om 22:59 heeft Ingo Ratsdorf <ingo@envirology.co.nz> het volgende geschreven:

> http://php.net/manual/en/migration70.php

Been there :-)

With help from fsfs on the irc channel, I got a bit further.
It breaks on the xml_parser in CalDAVRequest.php around line 566.

Doesn’t matter which client, iCal or CalDAV-sync, it comes as far as the xml_parser and then exits.

And you’re right, I turned on all php logging in my php.ini, but not a single log line :-(

So, what’s next, a tcpdump won’t help I guess if the xml_parser just dies..
Is there anything else I can put debugging placeholders or see the code that crashes the xml_parser?
Is there a way I can change the xml_parser error handling (like in issue #9) to see if that helps?

grtz,

Antoin


- --
Antoin Verschuren

Tweevoren 6, 5672 SB Nuenen, NL
M: +31 6 37682392







------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
michael at linuxfox
Apr 25, 2016, 8:50 PM
Post #5 of 16 (4894 views)
Permalink
Am 26.04.16 um 01:10 schrieb Antoin Verschuren:

> So, what’s next, a tcpdump won’t help I guess if the xml_parser just dies..
> Is there anything else I can put debugging placeholders or see the code that crashes the xml_parser?
> Is there a way I can change the xml_parser error handling (like in issue #9) to see if that helps?

try:

ps -C apache2 o pid= | sed 's/^/-p /' | xargs strace -o strace.log

--
Gruß Michael

Wenn du verstehst, was du tust, wirst du nichts lernen

Attached Files:

Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
vvh at aplusv
Apr 25, 2016, 9:09 PM
Post #6 of 16 (4880 views)
Permalink
I have had succes in the past to debug a script of my own with
https://packagist.org/packages/squizlabs/php_codesniffer

This helped me migrate from php 5.2 to 5.6 in one go...

Hth,
Vincent

Verzonden vanaf mijn Sony Xperiaâ„¢-smartphone

---- Antoin Verschuren schreef ----

>Op 25 apr. 2016, om 22:59 heeft Ingo Ratsdorf <ingo@envirology.co.nz> het volgende geschreven:
>
>> http://php.net/manual/en/migration70.php
>
>Been there :-)
>
>With help from fsfs on the irc channel, I got a bit further.
>It breaks on the xml_parser in CalDAVRequest.php around line 566.
>
>Doesn’t matter which client, iCal or CalDAV-sync, it comes as far as the xml_parser and then exits.
>
>And you’re right, I turned on all php logging in my php.ini, but not a single log line :-(
>
>So, what’s next, a tcpdump won’t help I guess if the xml_parser just dies..
>Is there anything else I can put debugging placeholders or see the code that crashes the xml_parser?
>Is there a way I can change the xml_parser error handling (like in issue #9) to see if that helps?
>
>grtz,
>
>Antoin
>
>
>- --
>Antoin Verschuren
>
>Tweevoren 6, 5672 SB Nuenen, NL
>M: +31 6 37682392
>
>
>
>
>
>
>
>------------------------------------------------------------------------------
>Find and fix application performance issues faster with Applications Manager
>Applications Manager provides deep performance insights into multiple tiers of
>your business applications. It resolves application problems quickly and
>reduces your MTTR. Get your free trial!
>https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
>_______________________________________________
>Davical-general mailing list
>Davical-general@lists.sourceforge.net
>https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
arne at drlinux
Apr 26, 2016, 12:36 AM
Post #7 of 16 (4892 views)
Permalink
Den 26. april 2016 01:10, skrev Antoin Verschuren:
> Op 25 apr. 2016, om 22:59 heeft Ingo Ratsdorf <ingo@envirology.co.nz> het volgende geschreven:
>

[snip]

>
> And you’re right, I turned on all php logging in my php.ini, but not a single log line :-(
>

[snip]

I just want to follow up on this, as I have the same problem with an
installation on a PHP 5.5 server. The script dies with a http status
500, but not a single line is to be found in the Apache error log. This
makes it very hard to debug.


For other applications logging work as normal, so I wonder if Davical
somehow "suppress" regular logging?

Regards,

Arne

--
Arne K. Haaje

------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
informatica at actiu
Apr 26, 2016, 2:06 AM
Post #8 of 16 (4889 views)
Permalink
I cannot understand why this LTS release of Ubuntu they have changed
PHP5 by PHP7 instead of maintaining PHP5 as an alternative.
PHP7 is so young to be the only option for production environments.


On 25/04/16 22:59, Ingo Ratsdorf wrote:
> Hi,
>
> PHP7 breaks a whole lot of things. From what I can see nothing too
> mayor, but still annoyingly enough.
>
> Start here: http://php.net/manual/en/migration70.php
>
> Have a look in your apache error log for fatal PHP errors to start.
>
> I do not know DaviCal's internals, but if it catches exceptions, you may
> not even find any fatal php errors due to this:
>
> "Many fatal and recoverable fatal errors have been converted to
> exceptions in PHP 7. These error exceptions inherit from the Error
> class, which itself implements the Throwable interface (the new base
> interface all exceptions inherit).
> This means that custom error handlers may no longer be triggered because
> exceptions may be thrown instead (causing new fatal errors for uncaught
> Error exceptions)."
>
> Cheers,
> Ingo
>
> On 26-Apr-16 3:15, Antoin Verschuren wrote:
>> Ok, so I still get these '500’ server errors when invoking 'CalDAVAccountRefreshQueueableOperation’ in iCal, and no responses in other clients.
>> I’ve tracked it down that it has to be a php7 or apache config thing, as I only see responses in the debug log when I type in a caldav url in a browser doing a GET request for a calendar.
>> So my question is: Why don’t I get responses to PROPFIND or other requests?
>>
>> So I tried this again, this time with full debug logging:
>>
>> [Mon Apr 25 17:00:18.697045 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
>> [Mon Apr 25 17:00:18.697240 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
>> [Mon Apr 25 17:00:18.697365 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: caldav:Version (1.1.4) == 1001.4
>> [Mon Apr 25 17:00:18.697772 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
>> [Mon Apr 25 17:00:18.711231 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,003685 to find 1 rows.
>> [Mon Apr 25 17:00:18.711816 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
>> [Mon Apr 25 17:00:18.711984 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: "0" => "UTC"
>> [Mon Apr 25 17:00:18.713420 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: always: Query: DBGQ: Took: 0,001189 to find 0 rows.
>> [Mon Apr 25 17:00:18.714164 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :***************** Request Header ****************
>> [Mon Apr 25 17:00:18.714282 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
>> [Mon Apr 25 17:00:18.714350 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Host: bla.foo.bar
>> [Mon Apr 25 17:00:18.714710 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Type: text/xml
>> [Mon Apr 25 17:00:18.714913 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Depth: 0
>> [Mon Apr 25 17:00:18.714994 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Brief: t
>> [Mon Apr 25 17:00:18.715066 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept: */*
>> [Mon Apr 25 17:00:18.715134 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Connection: keep-alive
>> [Mon Apr 25 17:00:18.715203 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Prefer: return-minimal
>> [Mon Apr 25 17:00:18.715272 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
>> [Mon Apr 25 17:00:18.715340 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Content-Length: 743
>> [Mon Apr 25 17:00:18.715410 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Language: nl-nl
>> [Mon Apr 25 17:00:18.715476 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
>> [Mon Apr 25 17:00:18.715542 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: :******************** Request ********************
>> [Mon Apr 25 17:00:18.715647 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
>> [Mon Apr 25 17:00:18.715721 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
>> [Mon Apr 25 17:00:18.715789 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:prop>
>> [Mon Apr 25 17:00:18.715853 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.715921 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.716049 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:current-user-principal/>
>> [Mon Apr 25 17:00:18.716115 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:displayname/>
>> [Mon Apr 25 17:00:18.716178 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.716241 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.716306 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.716371 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-collection-set/>
>> [Mon Apr 25 17:00:18.716431 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:principal-URL/>
>> [Mon Apr 25 17:00:18.716597 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:resource-id/>
>> [Mon Apr 25 17:00:18.716676 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.716741 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.716806 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> <A:supported-report-set/>
>> [Mon Apr 25 17:00:18.716868 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--> </A:prop>
>> [Mon Apr 25 17:00:18.716934 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:--></A:propfind>
>> [Mon Apr 25 17:00:18.716997 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: LOG: request:-->
>> [Mon Apr 25 17:00:18.717166 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::AuthFailedResponse Requesting authentication in the 'bla CalDAV Store' realm
>> [Mon Apr 25 17:00:18.717298 2016] [:error] [pid 10820] [client 192.168.0.1:54524] davical: ALL: HTTPAuth::Session: User is not authorised: 192.168.0.1
>> [Mon Apr 25 17:00:18.851119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
>> [Mon Apr 25 17:00:18.851300 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
>> [Mon Apr 25 17:00:18.851415 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Version (1.1.4) == 1001.4
>> [Mon Apr 25 17:00:18.851687 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
>> [Mon Apr 25 17:00:18.864895 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,003775 to find 1 rows.
>> [Mon Apr 25 17:00:18.865461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
>> [Mon Apr 25 17:00:18.865595 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: "0" => "UTC"
>> [Mon Apr 25 17:00:18.867140 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: always: Query: DBGQ: Took: 0,001321 to find 0 rows.
>> [Mon Apr 25 17:00:18.867736 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :***************** Request Header ****************
>> [Mon Apr 25 17:00:18.867854 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
>> [Mon Apr 25 17:00:18.867918 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Host: bla.foo.bar
>> [Mon Apr 25 17:00:18.868028 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept: */*
>> [Mon Apr 25 17:00:18.868093 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Brief: t
>> [Mon Apr 25 17:00:18.868167 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
>> [Mon Apr 25 17:00:18.868243 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Language: nl-nl
>> [Mon Apr 25 17:00:18.868311 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
>> [Mon Apr 25 17:00:18.868385 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Type: text/xml
>> [Mon Apr 25 17:00:18.868461 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Content-Length: 743
>> [Mon Apr 25 17:00:18.868533 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Depth: 0
>> [Mon Apr 25 17:00:18.868604 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Connection: keep-alive
>> [Mon Apr 25 17:00:18.868676 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
>> [Mon Apr 25 17:00:18.868750 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: headers:-->Prefer: return-minimal
>> [Mon Apr 25 17:00:18.868818 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: :******************** Request ********************
>> [Mon Apr 25 17:00:18.868929 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
>> [Mon Apr 25 17:00:18.869009 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
>> [Mon Apr 25 17:00:18.869077 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:prop>
>> [Mon Apr 25 17:00:18.869147 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-home-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.869222 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:calendar-user-address-set xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.869293 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:current-user-principal/>
>> [Mon Apr 25 17:00:18.869365 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:displayname/>
>> [Mon Apr 25 17:00:18.869437 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:dropbox-home-URL xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.869501 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:email-address-set xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.869561 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <C:notification-URL xmlns:C="http://calendarserver.org/ns/"/>
>> [Mon Apr 25 17:00:18.869630 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-collection-set/>
>> [Mon Apr 25 17:00:18.869705 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:principal-URL/>
>> [Mon Apr 25 17:00:18.869777 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:resource-id/>
>> [Mon Apr 25 17:00:18.869849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-inbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.869922 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <B:schedule-outbox-URL xmlns:B="urn:ietf:params:xml:ns:caldav"/>
>> [Mon Apr 25 17:00:18.869993 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> <A:supported-report-set/>
>> [Mon Apr 25 17:00:18.870110 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--> </A:prop>
>> [Mon Apr 25 17:00:18.870184 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:--></A:propfind>
>> [Mon Apr 25 17:00:18.870253 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: request:-->
>> [Mon Apr 25 17:00:18.870528 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Cache:Using NoCache dummy interface
>> [Mon Apr 25 17:00:18.870744 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:18.870866 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:18.880880 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,009780 to find 1 rows.
>> [Mon Apr 25 17:00:18.881685 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
>> [Mon Apr 25 17:00:18.881826 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
>> [Mon Apr 25 17:00:18.884669 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002616 to find 0 rows.
>> [Mon Apr 25 17:00:18.885438 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
>> [Mon Apr 25 17:00:18.885712 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:18.885849 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
>> [Mon Apr 25 17:00:18.885950 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
>> [Mon Apr 25 17:00:18.886047 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:18.893312 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,006948 to find 1 rows.
>> [Mon Apr 25 17:00:18.894007 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
>> [Mon Apr 25 17:00:18.894137 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
>> [Mon Apr 25 17:00:18.897982 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: caldav: Query: DBGQ: Took: 0,003630 to find 1 rows.
>> [Mon Apr 25 17:00:18.898202 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
>> [Mon Apr 25 17:00:18.898340 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: Principal:Path split into at least /// test /// calendar ///
>> [Mon Apr 25 17:00:18.898698 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:18.898859 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
>> [Mon Apr 25 17:00:18.898966 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
>> [Mon Apr 25 17:00:18.899066 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:18.902278 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: Principal: Query: DBGQ: Took: 0,002899 to find 1 rows.
>> [Mon Apr 25 17:00:18.903119 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
>> [Mon Apr 25 17:00:18.903245 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
>> [Mon Apr 25 17:00:18.903336 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
>> [Mon Apr 25 17:00:18.912907 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009329 to find 0 rows.
>> [Mon Apr 25 17:00:18.913051 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
>> [Mon Apr 25 17:00:18.913547 2016] [:error] [pid 10872] [client 192.168.0.1:54525] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
>> [Mon Apr 25 17:00:19.035250 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Set locale to =nl_NL.UTF-8=
>> [Mon Apr 25 17:00:19.035441 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: I18N:Bound domain =davical= to location =../locale= using character set =UTF-8=
>> [Mon Apr 25 17:00:19.035558 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Version (1.1.4) == 1001.4
>> [Mon Apr 25 17:00:19.035902 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SELECT schema_major, schema_minor, schema_patch FROM awl_db_revision ORDER BY schema_id DESC LIMIT 1;
>> [Mon Apr 25 17:00:19.048977 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,003744 to find 1 rows.
>> [Mon Apr 25 17:00:19.049762 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: SET TIMEZONE TO ?
>> [Mon Apr 25 17:00:19.049895 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: "0" => "UTC"
>> [Mon Apr 25 17:00:19.051412 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: always: Query: DBGQ: Took: 0,001303 to find 0 rows.
>> [Mon Apr 25 17:00:19.051990 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :***************** Request Header ****************
>> [Mon Apr 25 17:00:19.052115 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :PROPFIND /cal/caldav.php/test/calendar/
>> [Mon Apr 25 17:00:19.052180 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Host: bla.foo.bar
>> [Mon Apr 25 17:00:19.052252 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept: */*
>> [Mon Apr 25 17:00:19.052315 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Brief: t
>> [Mon Apr 25 17:00:19.052393 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Authorization: Delicious tasty password eaten by debugging monster!
>> [Mon Apr 25 17:00:19.052469 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Language: nl-nl
>> [Mon Apr 25 17:00:19.052543 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Accept-Encoding: gzip, deflate
>> [Mon Apr 25 17:00:19.052618 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Type: text/xml
>> [Mon Apr 25 17:00:19.052692 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Content-Length: 170
>> [Mon Apr 25 17:00:19.052764 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Depth: 0
>> [Mon Apr 25 17:00:19.052837 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Connection: keep-alive
>> [Mon Apr 25 17:00:19.052968 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->User-Agent: Mac_OS_X/10.9.5 (13F1712) CalendarAgent/176.2
>> [Mon Apr 25 17:00:19.053042 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: headers:-->Prefer: return-minimal
>> [Mon Apr 25 17:00:19.053116 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: :******************** Request ********************
>> [Mon Apr 25 17:00:19.053215 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><?xml version="1.0" encoding="UTF-8"?>
>> [Mon Apr 25 17:00:19.053295 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--><A:propfind xmlns:A="DAV:">
>> [Mon Apr 25 17:00:19.053370 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:prop>
>> [Mon Apr 25 17:00:19.053429 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:current-user-principal/>
>> [Mon Apr 25 17:00:19.053490 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> <A:principal-collection-set/>
>> [Mon Apr 25 17:00:19.053565 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--> </A:prop>
>> [Mon Apr 25 17:00:19.053638 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:--></A:propfind>
>> [Mon Apr 25 17:00:19.053703 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: request:-->
>> [Mon Apr 25 17:00:19.053873 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Cache:Using NoCache dummy interface
>> [Mon Apr 25 17:00:19.054056 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, 0::BIT(24) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:19.054174 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:19.064259 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,009842 to find 1 rows.
>> [Mon Apr 25 17:00:19.065063 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: SELECT role_name FROM role_member m join roles r ON r.role_no = m.role_no WHERE user_no = :user_no
>> [Mon Apr 25 17:00:19.065209 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: ":user_no" => "1007"
>> [Mon Apr 25 17:00:19.068012 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: BasicAuth: Query: DBGQ: Took: 0,002565 to find 0 rows.
>> [Mon Apr 25 17:00:19.068725 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
>> [Mon Apr 25 17:00:19.069004 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:19.069142 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
>> [Mon Apr 25 17:00:19.069241 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
>> [Mon Apr 25 17:00:19.069339 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:19.076562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,006915 to find 1 rows.
>> [Mon Apr 25 17:00:19.077251 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: SELECT * FROM collection WHERE dav_name = :exact_name ORDER BY LENGTH(dav_name) DESC LIMIT 1
>> [Mon Apr 25 17:00:19.077384 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: ":exact_name" => "/test/calendar/"
>> [Mon Apr 25 17:00:19.081189 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: caldav: Query: DBGQ: Took: 0,003595 to find 1 rows.
>> [Mon Apr 25 17:00:19.081462 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav: Collection '/test/calendar/' is 6395, type calendar
>> [Mon Apr 25 17:00:19.081605 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: Principal:Path split into at least /// test /// calendar ///
>> [Mon Apr 25 17:00:19.081855 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: SELECT *, pprivs(:session_principal::int8,principal_id,:scan_depth::int) AS privileges FROM dav_principal WHERE lower(username)=lower(text(:param))
>> [Mon Apr 25 17:00:19.081998 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":session_principal" => "6394"
>> [Mon Apr 25 17:00:19.082101 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":scan_depth" => "2"
>> [Mon Apr 25 17:00:19.082200 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: ":param" => "test"
>> [Mon Apr 25 17:00:19.085530 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: Principal: Query: DBGQ: Took: 0,002912 to find 1 rows.
>> [Mon Apr 25 17:00:19.086256 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: SELECT usr.username FROM group_member JOIN principal ON (principal_id=group_id) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id UNION SELECT usr.username FROM group_member LEFT JOIN grants ON (to_principal=group_id)
>> [Mon Apr 25 17:00:19.086374 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: JOIN principal ON (principal_id=by_principal) JOIN usr USING(user_no) WHERE usr.active=true AND member_id = :member_id and by_principal != member_id ORDER BY 1
>> [Mon Apr 25 17:00:19.086562 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: ":member_id" => "6394"
>> [Mon Apr 25 17:00:19.096117 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: LOG: DAVPrincipal: Query: DBGQ: Took: 0,009290 to find 0 rows.
>> [Mon Apr 25 17:00:19.096260 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: principal: User: test (1007) URL: /cal/caldav.php/test/, By Email: 0
>> [Mon Apr 25 17:00:19.096761 2016] [:error] [pid 11498] [client 192.168.0.1:54526] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
>>
>> And there the logging stops. No response.
>> Any idea where I should start searching?
>>
>>
>> Op 24 apr. 2016, om 23:49 heeft Antoin Verschuren <davical@antoin.nl> het volgende geschreven:
>>
>>> Hi all,
>>>
>>> This is my first message to this list.
>>> I’m not a postgresql or php expert, but I do know my way around.
>>>
>>> I have recently upgraded my ubuntu server from 15.10 to 16.04, and everything works, except davical ;-(.
>>>
>>> Since I’ve upgraded, my clients get errors, don’t connect, or don’t update.
>>> I first thought it was the davical database, since it had problems with the update-davical-database script.
>>> It had multiple version entires in the awl_db_revision table, but SELECT check_db_revision(1,2,11); failed anyway, saying the Database has not been upgraded to 1.2.11.
>>> I fixed that, but didn’t help.
>>>
>>> So I created a brand new DB with new users with the create-database.sh script running as postgres, and tested again, but still the same errors on the clients.
>>> I restored a dump from my current database from 2 months ago, and still the same errors.
>>> I can access my DB and users with the davical administration webinterface, so the DB looks ok, but clients fail.
>>> Most android clients (davdroid, caldav-sync) don’t give errors, but fail to update.
>>> All my IOS/OSX clients give me this error: '500' 'CalDAVAccountRefreshQueueableOperation'.
>>>
>>> I was wondering if the upgrade from php5.6 to 7.0 had anything to do with it.
>>> PHP5.6 is no longer in ubuntu 16:04, so mod_php5 is disabled in apache2, and mod_php7.0 is enabled.
>>>
>>>
>>> ------------------------------------------------------------------------------
>>> Find and fix application performance issues faster with Applications Manager
>>> Applications Manager provides deep performance insights into multiple tiers of
>>> your business applications. It resolves application problems quickly and
>>> reduces your MTTR. Get your free trial!
>>> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
>>> _______________________________________________
>>> Davical-general mailing list
>>> Davical-general@lists.sourceforge.net
>>> https://lists.sourceforge.net/lists/listinfo/davical-general
>>
>>
>> ------------------------------------------------------------------------------
>> Find and fix application performance issues faster with Applications Manager
>> Applications Manager provides deep performance insights into multiple tiers of
>> your business applications. It resolves application problems quickly and
>> reduces your MTTR. Get your free trial!
>> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
>> _______________________________________________
>> Davical-general mailing list
>> Davical-general@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/davical-general
>>
>

------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
fsfs at debian
Apr 26, 2016, 2:53 AM
Post #9 of 16 (4888 views)
Permalink
On Tue, Apr 26, 2016 at 09:36:29AM +0200, Arne K. Haaje wrote:
> I just want to follow up on this, as I have the same problem with an
> installation on a PHP 5.5 server. The script dies with a http status
> 500, but not a single line is to be found in the Apache error log. This
> makes it very hard to debug.
>
>
> For other applications logging work as normal, so I wonder if Davical
> somehow "suppress" regular logging?

no, but there is an early_exception_handler() in htdocs/always.php,
which outputs stuff with echo, catches exceptions and is set with
set_exception_handler(). It might be worth examining whether that is run
and where the output ends up.

I also noticed that Tim Gouma wrote an email to this list on 2016-04-05
(see https://sourceforge.net/p/davical/mailman/message/34993914/), where
he sees a 403 CalDAVAccountRefreshQueueableOperation error on the OS X
Calendar app using plain Jessie (DAViCal 1.1.3.1-1, no PHP 7), so the OS
X part of the problem may be unrelated to the PHP version.

Florian

------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 26, 2016, 5:02 AM
Post #10 of 16 (4887 views)
Permalink
Op 26 apr. 2016, om 11:53 heeft Florian Schlichting <fsfs@debian.org> het volgende geschreven:

> no, but there is an early_exception_handler() in htdocs/always.php,
> which outputs stuff with echo, catches exceptions and is set with
> set_exception_handler(). It might be worth examining whether that is run
> and where the output ends up.

I only see it in the beginning of caldav.php: require_once('./always.php’);
The good question is, where should it show up?

> I also noticed that Tim Gouma wrote an email to this list on 2016-04-05
> (see https://sourceforge.net/p/davical/mailman/message/34993914/), where
> he sees a 403 CalDAVAccountRefreshQueueableOperation error on the OS X
> Calendar app using plain Jessie (DAViCal 1.1.3.1-1, no PHP 7), so the OS
> X part of the problem may be unrelated to the PHP version.

No, it’s not an OS X issue. It’s more like issue #9.
It also occurs exactly the same with my iPad (IOS), Android phone (caldav-sync), and android tab (davdroid).
I can try with lightning on ubuntu as well, but I expect the same error.

The logging always ends just before the xml_parser is called.

I made these debugging markers in /usr/share/davical/inc/CalDAVRequest.php:

dbg_error_log( "LOG ", "******************** CalDAVRequest.php line 550 ********************" );

/**
* If the content we are receiving is XML then we parse it here. RFC2518 says we
* should reasonably expect to see either text/xml or application/xml
*/
if ( isset($this->content_type) && preg_match( '#(application|text)/xml#', $this->content_type ) ) {
dbg_error_log( "LOG ", "******************** CalDAVRequest.php line 555 ********************" );
if ( !isset($this->raw_post) || $this->raw_post == '' ) {
$this->XMLResponse( 400, new XMLElement( 'error', new XMLElement('missing-xml'), array( 'xmlns' => 'DAV:') ) );
dbg_error_log( "LOG ", "******************** CalDAVRequest.php line 560 ********************" );
}
dbg_error_log( "LOG ", "******************** CalDAVRequest.php line 562 ********************" );

$xml_parser = xml_parser_create_ns('UTF-8');
$this->xml_tags = array();

dbg_error_log( "LOG ", "******************** CalDAVRequest.php line 564 ********************" );


And these are always the last log lines with any client:


[Tue Apr 26 13:43:39.845077 2016] [:error] [pid 21053] [client 192.168.0.1:57927] davical: ALL: caldav:Full permissions for user accessing their own hierarchy
[Tue Apr 26 13:43:39.845300 2016] [:error] [pid 21053] [client 192.168.0.1:57927] davical: LOG: :******************** CalDAVRequest.php line 550 ********************
[Tue Apr 26 13:43:39.845387 2016] [:error] [pid 21053] [client 192.168.0.1:57927] davical: LOG: :******************** CalDAVRequest.php line 555 ********************
[Tue Apr 26 13:43:39.845458 2016] [:error] [pid 21053] [client 192.168.0.1:57927] davical: LOG: :******************** CalDAVRequest.php line 562 ********************


So it never reaches line 564, meaning the xml_parser is the culprit.


I have also tried with a complete new database set up in postgresql 9.5 (the default in Xenial) with only one test user added.
So you can probably reproduce this setting up a fresh Xenial install, using apache2 (2.4.18) with mod_php7.0 enabled, postgresql 9.5.2 and php7.0.4.

Should I report an issue for this? (I don’t have a gitlab account yet).

grtz,

Antoin.






- --
Antoin Verschuren

Tweevoren 6, 5672 SB Nuenen, NL
M: +31 6 37682392







------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 26, 2016, 6:20 AM
Post #11 of 16 (4888 views)
Permalink
Op 26 apr. 2016, om 05:50 heeft Michael Grundmann <michael@linuxfox.de> het volgende geschreven:

> ps -C apache2 o pid= | sed 's/^/-p /' | xargs strace

Did that, but I can’t find anything relevant in there.
If you can spot something, this is a tail of the capture:

[pid 20036] connect(18, {sa_family=AF_LOCAL, sun_path="/var/run/postgresql/.s.PGSQL.5432"}, 110) = 0
[pid 20036] getsockopt(18, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
[pid 20036] getsockname(18, {sa_family=AF_LOCAL, NULL}, [2]) = 0
[pid 20036] poll([{fd=18, events=POLLOUT|POLLERR}], 1, 30000) = 1 ([{fd=18, revents=POLLOUT}])
[pid 20036] sendto(18, "\0\0\0+\0\3\0\0user\0davical_app\0databas"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, 30000) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "R\0\0\0\10\0\0\0\0S\0\0\0\26application_name\0\0"..., 16384, 0, NULL, NULL) = 328
[pid 20036] sendto(18, "P\0\0\0)pdo_stmt_00000001\0SELECT ve"..., 47, MSG_NOSIGNAL, NULL, 0) = 47
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000001\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\0 \0\1version\0\0\0\0\0\0\0\0\0\0\31\377\377"..., 16384, 0, NULL, NULL) = 178
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 635747}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0~pdo_stmt_00000002\0SELECT sc"..., 132, MSG_NOSIGNAL, NULL, 0) = 132
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000002\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\0c\0\3schema_major\0\0\0@g\0\2\0"..., 16384, 0, NULL, NULL) = 148
[pid 20036] gettimeofday({1461675776, 641196}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 641649}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.641649 2016"..., 148) = 148
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 643698}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.643698 2016"..., 135) = 135
[pid 20036] gettimeofday({1461675776, 644417}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.644417 2016"..., 131) = 131
[pid 20036] gettimeofday({1461675776, 644967}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0.pdo_stmt_00000003\0SET TIMEZ"..., 52, MSG_NOSIGNAL, NULL, 0) = 52
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000003\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4n\0\0\0\4S\0\0\0\21TimeZone\0UTC\0C\0\0\0"..., 16384, 0, NULL, NULL) = 43
[pid 20036] gettimeofday({1461675776, 647548}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 647823}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.647823 2016"..., 148) = 148
[pid 20036] gettimeofday({1461675776, 648523}, NULL) = 0
[pid 20036] poll([{fd=17, events=POLLIN}], 1, 10000) = 1 ([{fd=17, revents=POLLIN}])
[pid 20036] read(17, "\27\3\3\0\360\361\265=\\\357\332\353\264\2,m|\205\320\236\270\207\207o\237\321\364P\35?w "..., 8000) = 245
[pid 20036] gettimeofday({1461675776, 649336}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 649738}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.649738 2016"..., 147) = 147
[pid 20036] gettimeofday({1461675776, 650259}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.650259 2016"..., 130) = 130
[pid 20036] gettimeofday({1461675776, 650896}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.650896 2016"..., 132) = 132
[pid 20036] gettimeofday({1461675776, 651388}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.651388 2016"..., 119) = 119
[pid 20036] gettimeofday({1461675776, 651847}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.651847 2016"..., 116) = 116
[pid 20036] gettimeofday({1461675776, 652307}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.652307 2016"..., 175) = 175
[pid 20036] gettimeofday({1461675776, 652767}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.652767 2016"..., 130) = 130
[pid 20036] gettimeofday({1461675776, 653252}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.653252 2016"..., 138) = 138
[pid 20036] gettimeofday({1461675776, 653741}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.653741 2016"..., 130) = 130
[pid 20036] gettimeofday({1461675776, 654228}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.654228 2016"..., 127) = 127
[pid 20036] gettimeofday({1461675776, 654786}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.654786 2016"..., 116) = 116
[pid 20036] gettimeofday({1461675776, 655266}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.655266 2016"..., 130) = 130
[pid 20036] gettimeofday({1461675776, 655729}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.655729 2016"..., 165) = 165
[pid 20036] gettimeofday({1461675776, 656188}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.656188 2016"..., 130) = 130
[pid 20036] gettimeofday({1461675776, 656646}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.656646 2016"..., 147) = 147
[pid 20036] gettimeofday({1461675776, 657133}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.657133 2016"..., 146) = 146
[pid 20036] gettimeofday({1461675776, 657587}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.657587 2016"..., 135) = 135
[pid 20036] gettimeofday({1461675776, 658040}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.658040 2016"..., 118) = 118
[pid 20036] gettimeofday({1461675776, 658580}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.658580 2016"..., 139) = 139
[pid 20036] gettimeofday({1461675776, 659079}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.659079 2016"..., 141) = 141
[pid 20036] gettimeofday({1461675776, 659580}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.659580 2016"..., 119) = 119
[pid 20036] gettimeofday({1461675776, 660054}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.660054 2016"..., 121) = 121
[pid 20036] gettimeofday({1461675776, 660526}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.660526 2016"..., 108) = 108
[pid 20036] gettimeofday({1461675776, 661066}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.661066 2016"..., 132) = 132
[pid 20036] gettimeofday({1461675776, 661600}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.661600 2016"..., 216) = 216
[pid 20036] gettimeofday({1461675776, 662089}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.662089 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 662683}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0zpdo_stmt_00000004\0SELECT *,"..., 128, MSG_NOSIGNAL, NULL, 0) = 128
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000004\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\2\205\0\26user_no\0\0\0C\261\0\1\0\0\0\24\0\10"..., 16384, 0, NULL, NULL) = 1044
[pid 20036] gettimeofday({1461675776, 674001}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 674368}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.674368 2016"..., 151) = 151
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 676802}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.676802 2016"..., 220) = 220
[pid 20036] gettimeofday({1461675776, 677618}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.677618 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 678488}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0xpdo_stmt_00000005\0SELECT ro"..., 126, MSG_NOSIGNAL, NULL, 0) = 126
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000005\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\0\"\0\1role_name\0\0\0@\350\0\2\0\0\0\31"..., 16384, 0, NULL, NULL) = 60
[pid 20036] gettimeofday({1461675776, 683121}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 683620}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.683620 2016"..., 151) = 151
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 686122}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.686122 2016"..., 129) = 129
[pid 20036] gettimeofday({1461675776, 687035}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.687035 2016"..., 153) = 153
[pid 20036] gettimeofday({1461675776, 688116}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.688116 2016"..., 152) = 152
[pid 20036] gettimeofday({1461675776, 689377}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.689377 2016"..., 268) = 268
[pid 20036] gettimeofday({1461675776, 690224}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.690224 2016"..., 152) = 152
[pid 20036] gettimeofday({1461675776, 691092}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.691092 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 691838}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.691838 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 692765}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0\226pdo_stmt_00000006\0SELECT *,"..., 156, MSG_NOSIGNAL, NULL, 0) = 156
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000006\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\2\205\0\26user_no\0\0\0C\261\0\1\0\0\0\24\0\10"..., 16384, 0, NULL, NULL) = 1044
[pid 20036] gettimeofday({1461675776, 701808}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 702170}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.702170 2016"..., 151) = 151
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 704251}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.704251 2016"..., 210) = 210
[pid 20036] gettimeofday({1461675776, 705055}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.705055 2016"..., 146) = 146
[pid 20036] gettimeofday({1461675776, 705765}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0tpdo_stmt_00000007\0SELECT * "..., 122, MSG_NOSIGNAL, NULL, 0) = 122
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000007\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\2\30\0\21user_no\0\0\0@\212\0\1\0\0\0\27\0\4"..., 16384, 0, NULL, NULL) = 562
[pid 20036] gettimeofday({1461675776, 711533}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 711925}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.711925 2016"..., 148) = 148
[pid 20036] gettimeofday({1461675776, 712729}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.712729 2016"..., 148) = 148
[pid 20036] gettimeofday({1461675776, 713422}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.713422 2016"..., 152) = 152
[pid 20036] gettimeofday({1461675776, 714108}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.714108 2016"..., 268) = 268
[pid 20036] gettimeofday({1461675776, 714795}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.714795 2016"..., 152) = 152
[pid 20036] gettimeofday({1461675776, 715445}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.715445 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 716080}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.716080 2016"..., 142) = 142
[pid 20036] gettimeofday({1461675776, 716791}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\0\226pdo_stmt_00000008\0SELECT *,"..., 156, MSG_NOSIGNAL, NULL, 0) = 156
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000008\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\2\205\0\26user_no\0\0\0C\261\0\1\0\0\0\24\0\10"..., 16384, 0, NULL, NULL) = 1044
[pid 20036] gettimeofday({1461675776, 721723}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 722150}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.722150 2016"..., 151) = 151
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 724273}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.724273 2016"..., 364) = 364
[pid 20036] gettimeofday({1461675776, 725033}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.725033 2016"..., 284) = 284
[pid 20036] gettimeofday({1461675776, 725708}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.725708 2016"..., 147) = 147
[pid 20036] gettimeofday({1461675776, 726479}, NULL) = 0
[pid 20036] sendto(18, "P\0\0\1\235pdo_stmt_00000009\0SELECT us"..., 419, MSG_NOSIGNAL, NULL, 0) = 419
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "1\0\0\0\4Z\0\0\0\5I", 16384, 0, NULL, NULL) = 11
[pid 20036] sendto(18, "B\0\0\0\37\0pdo_stmt_00000009\0\0\0\0\0\0\1\0\0"..., 54, MSG_NOSIGNAL, NULL, 0) = 54
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "2\0\0\0\4T\0\0\0!\0\1username\0\0\0\0\0\0\0\0\0\0\31\377"..., 16384, 0, NULL, NULL) = 59
[pid 20036] gettimeofday({1461675776, 737871}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 738205}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.738205 2016"..., 154) = 154
[pid 20036] gettimeofday({1461675776, 739021}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.739021 2016"..., 169) = 169
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] gettimeofday({1461675776, 740911}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.740911 2016"..., 159) = 159
[pid 20036] gettimeofday({1461675776, 741622}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.741622 2016"..., 166) = 166
[pid 20036] gettimeofday({1461675776, 742194}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.742194 2016"..., 166) = 166
[pid 20036] gettimeofday({1461675776, 742884}, NULL) = 0
[pid 20036] write(2, "[Tue Apr 26 15:02:56.742884 2016"..., 166) = 166
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] chdir("/") = 0
[pid 20036] sendto(18, "Q\0\0\0!DEALLOCATE pdo_stmt_0000000"..., 34, MSG_NOSIGNAL, NULL, 0) = 34
[pid 20036] poll([{fd=18, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=18, revents=POLLIN}])
[pid 20036] recvfrom(18, "C\0\0\0\17DEALLOCATE\0Z\0\0\0\5I", 16384, 0, NULL, NULL) = 22
[pid 20036] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
[pid 20036] sendto(18, "X\0\0\0\4", 5, MSG_NOSIGNAL, NULL, 0) = 5
[pid 20036] close(18) = 0
[pid 20036] fcntl(15, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
[pid 20036] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 747731}, NULL) = 0
[pid 20036] writev(17, [{"\27\3\3\1\0\4s\6\363$R\207\234\265\320A/%\256\233\37\267p\277\206\313\264\223\6\364\370d"..., 261}, {"\27\3\3\1@\314\343u\362{\367\335;\2158\367\316`\25\323\263\330\360\3620\370\1\27d\373'\363"..., 325}], 2) = 586
[pid 20036] gettimeofday({1461675776, 748242}, NULL) = 0
[pid 20036] write(11, "192.168.0.1 - antoin [26/Apr/201"..., 154) = 154
[pid 20036] times({tms_utime=737, tms_stime=44, tms_cutime=0, tms_cstime=0}) = 1741801748
[pid 20036] gettimeofday({1461675776, 749065}, NULL) = 0
[pid 20036] gettimeofday({1461675776, 749312}, NULL) = 0
[pid 20036] writev(17, [{"\25\3\3\0P\203\241\214Sba\212e\347\372i\275\27p\17\232\211\22\301\32L0\271\336&\255|"..., 85}], 1) = 85
[pid 20036] shutdown(17, SHUT_WR) = 0
[pid 20036] poll([{fd=17, events=POLLIN}], 1, 2000) = 1 ([{fd=17, revents=POLLIN}])
[pid 20036] read(17, "\25\3\3\0P\204\370\255+\250$\360\316\324Q\22\244\37Q\327><\224\177\34J\206\355\222JO\216"..., 512) = 85
[pid 20036] gettimeofday({1461675776, 761379}, NULL) = 0
[pid 20036] poll([{fd=17, events=POLLIN}], 1, 2000) = 1 ([{fd=17, revents=POLLIN|POLLHUP}])
[pid 20036] read(17, "", 512) = 0
[pid 20036] close(17) = 0
[pid 20036] read(7, 0x7ffde03b057f, 1) = -1 EAGAIN (Resource temporarily unavailable)
[pid 20036] gettimeofday({1461675776, 762634}, NULL) = 0
[pid 20036] fcntl(9, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0} <unfinished ...>
[pid 21053] <... epoll_wait resumed> [{EPOLLIN, {u32=1465680400, u64=139824126001680}}], 2, 10000) = 1
[pid 21053] accept4(6, {sa_family=AF_INET6, sin6_port=htons(58227), inet_pton(AF_INET6, "::ffff:192.168.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC) = 17
[pid 21053] fcntl(9, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
[pid 20034] <... fcntl resumed> ) = 0
[pid 21053] gettimeofday( <unfinished ...>
[pid 20034] epoll_wait(16, <unfinished ...>
[pid 21053] <... gettimeofday resumed> {1461675776, 788939}, NULL) = 0
[pid 21053] getsockname(17, {sa_family=AF_INET6, sin6_port=htons(443), inet_pton(AF_INET6, "::ffff:192.168.0.2", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
[pid 21053] open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 18
[pid 21053] read(18, "\26\235Z8\351\t\225\306\27\31z\343z\20\225\335\243\2279\265e\370;W\376\211\254!1\273j\227"..., 512) = 512
[pid 21053] close(18) = 0
[pid 21053] fcntl(17, F_GETFL) = 0x2 (flags O_RDWR)
[pid 21053] fcntl(17, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 21053] read(17, "\26\3\1\0\324\1\0\0\320\3\3W\37f\375\0250\277\361\1\231zn\276\2017\2118l]\f{"..., 8000) = 217
[pid 21053] fcntl(13, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
[pid 21053] gettimeofday({1461675776, 791576}, NULL) = 0
[pid 21053] fcntl(13, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
[pid 21053] writev(17, [{"\26\3\3\0Q\2\0\0M\3\3\334&\337;x\367\212\246<U\365\231FBx}#C\10\242\234"..., 193}], 1) = 193
[pid 21053] read(17, 0x7f2b575b9048, 8000) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 300000) = 1 ([{fd=17, revents=POLLIN}])
[pid 21053] read(17, "\24\3\3\0\1\1", 8000) = 6
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 300000) = 1 ([{fd=17, revents=POLLIN}])
[pid 21053] read(17, "\26\3\3\0`\221\20j\244\00596b \267\223\231\333\6WH\2339?\351\233\362\223q#\35\225"..., 8000) = 474
[pid 21053] gettimeofday({1461675776, 806194}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 806677}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 806963}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 807337}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 807637}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 807831}, NULL) = 0
[pid 21053] stat("/var/www/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] stat("/var/www/index.html", {st_mode=S_IFREG|0644, st_size=1408, ...}) = 0
[pid 21053] gettimeofday({1461675776, 808788}, NULL) = 0
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 10000) = 1 ([{fd=17, revents=POLLIN}])
[pid 21053] read(17, "\27\3\3\0\360\365\330s\203oBB\321\6\243\32\354\17\r\324}_\235\363R$\20/\34\322\320~"..., 8000) = 245
[pid 21053] gettimeofday({1461675776, 809426}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 809961}, NULL) = 0
[pid 21053] read(17, 0x7f2b5759c048, 8000) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21053] gettimeofday({1461675776, 810380}, NULL) = 0
[pid 21053] writev(17, [{"\27\3\3\1P\224}\3604&\246\5H03\21\36\337y\317\333\222\266\234\230\322\206\350=\3176^"..., 341}, {"\27\3\3\1\2205f\203\363\213\365\22\27Z\370\232\252\324\272\216\352\1J5=\272t\237lc\310A"..., 405}], 2) = 746
[pid 21053] gettimeofday({1461675776, 810900}, NULL) = 0
[pid 21053] write(11, "192.168.0.1 - - [26/Apr/2016:15:"..., 127) = 127
[pid 21053] times({tms_utime=700, tms_stime=49, tms_cutime=0, tms_cstime=0}) = 1741801754
[pid 21053] gettimeofday({1461675776, 811560}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 811741}, NULL) = 0
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 5000) = 1 ([{fd=17, revents=POLLIN}])
[pid 21053] read(17, "\27\3\3\1pR\232f&bX\354\364wu}\254s`\30o\275\t\266\204\34b\245\30}C\346"..., 8000) = 373
[pid 21053] gettimeofday({1461675776, 846502}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 846799}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 847168}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 847464}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 847687}, NULL) = 0
[pid 21053] stat("/var/www/principals/", 0x7ffde03b0200) = -1 ENOENT (No such file or directory)
[pid 21053] lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] lstat("/var/www/principals", 0x7ffde03b0200) = -1 ENOENT (No such file or directory)
[pid 21053] open("/var/www/", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 18
[pid 21053] fstat(18, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] getdents(18, /* 9 entries */, 32768) = 256
[pid 21053] getdents(18, /* 0 entries */, 32768) = 0
[pid 21053] close(18) = 0
[pid 21053] gettimeofday({1461675776, 850223}, NULL) = 0
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 10000) = 1 ([{fd=17, revents=POLLIN}])
[pid 21053] read(17, "\27\3\3\0\360-\362\\`{`\203\\!\255\2\25\2020\2\32\304\347W\363\27O~\236\"q\300"..., 8000) = 245
[pid 21053] gettimeofday({1461675776, 850925}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 851451}, NULL) = 0
[pid 21053] read(17, 0x7f2b575b7048, 8000) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21053] gettimeofday({1461675776, 851863}, NULL) = 0
[pid 21053] writev(17, [{"\27\3\3\1@8h\3605c\261\357\340dB\342\347\177\212_\346\366\217\302\270\220\16x\337Jp\374"..., 325}, {"\27\3\3\1\220\357S\217m\310Vo\320\345\244\4\10\247t\315\370?R\345q\5<\217/\232j\37"..., 405}], 2) = 730
[pid 21053] gettimeofday({1461675776, 852328}, NULL) = 0
[pid 21053] write(11, "192.168.0.1 - - [26/Apr/2016:15:"..., 138) = 138
[pid 21053] times({tms_utime=700, tms_stime=49, tms_cutime=0, tms_cstime=0}) = 1741801758
[pid 21053] gettimeofday({1461675776, 852961}, NULL) = 0
[pid 21053] gettimeofday({1461675776, 853136}, NULL) = 0
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 5000 <unfinished ...>
[pid 14466] <... select resumed> ) = 0 (Timeout)
[pid 14466] wait4(-1, 0x7ffde03b061c, WNOHANG|WSTOPPED, NULL) = 0
[pid 14466] select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 14466] wait4(-1, 0x7ffde03b061c, WNOHANG|WSTOPPED, NULL) = 0
[pid 14466] select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 14466] wait4(-1, 0x7ffde03b061c, WNOHANG|WSTOPPED, NULL) = 0
[pid 14466] select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 14466] wait4(-1, 0x7ffde03b061c, WNOHANG|WSTOPPED, NULL) = 0
[pid 14466] select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 14466] wait4(-1, 0x7ffde03b061c, WNOHANG|WSTOPPED, NULL) = 0
[pid 14466] select(0, NULL, NULL, NULL, {1, 0} <unfinished ...>
[pid 21053] <... poll resumed> ) = 0 (Timeout)
[pid 21053] gettimeofday({1461675781, 858687}, NULL) = 0
[pid 21053] gettimeofday({1461675781, 858954}, NULL) = 0
[pid 21053] gettimeofday({1461675781, 859179}, NULL) = 0
[pid 21053] gettimeofday({1461675781, 859373}, NULL) = 0
[pid 21053] writev(17, [{"\25\3\3\0PSvGQb\261\366e2\321\302\25\360Iz\350\0327:\274_\346\205\201\302[\36"..., 85}], 1) = 85
[pid 21053] shutdown(17, SHUT_WR) = 0
[pid 21053] poll([{fd=17, events=POLLIN}], 1, 2000^Cstrace: Process 14466 detached
strace: Process 20034 detached
strace: Process 20035 detached
strace: Process 20036 detached

strace: Process 20037 detached
strace: Process 20038 detached
strace: Process 21053 detached
<detached ...>
strace: Process 24076 detached
strace: Process 24085 detached

Antoin









------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
michael at linuxfox
Apr 26, 2016, 10:41 AM
Post #12 of 16 (4885 views)
Permalink
Am 26.04.16 um 15:20 schrieb Antoin Verschuren:


[pid 21053] stat("/var/www/principals/", 0x7ffde03b0200) = -1 ENOENT (No
such file or directory)
[pid 21053] lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 21053] lstat("/var/www/principals", 0x7ffde03b0200) = -1 ENOENT (No
such file or directory)


no such file or directory?


--
Gruß Michael

Wenn du verstehst, was du tust, wirst du nichts lernen

Attached Files:

Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 26, 2016, 2:45 PM
Post #13 of 16 (4883 views)
Permalink
Op 26 apr. 2016, om 19:41 heeft Michael Grundmann <michael@linuxfox.de> het volgende geschreven:

> Am 26.04.16 um 15:20 schrieb Antoin Verschuren:
>
>
> [pid 21053] stat("/var/www/principals/", 0x7ffde03b0200) = -1 ENOENT (No
> such file or directory)
> [pid 21053] lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> [pid 21053] lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> [pid 21053] lstat("/var/www/principals", 0x7ffde03b0200) = -1 ENOENT (No
> such file or directory)
>
>
> no such file or directory?

I see more of these in my trace:

21053 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)
24085 stat("/var/www/cal/caldav.php/maria/", 0x7ffde03b0200) = -1 ENOTDIR (Not a directory)
24085 stat("/var/www/maria/", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
24085 lstat("/var/www/maria", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
24085 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)
24076 stat("/var/www/cal/caldav.php/maria/", 0x7ffde03b0200) = -1 ENOTDIR (Not a directory)
24076 stat("/var/www/maria/", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
24076 lstat("/var/www/maria", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
24076 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)

I’m not using a virtual host, but my caldav store is symbolically linked from my existing document root under a subdir /cal.
I don’t know why the whole path is searched like that, but it doesn’t look look like that breaks anything.
maria is one of my users, but I don’t know where the .pgpass or principals is coming from…:-s

Could a memory leak have something to do with this?
I found this bug report: https://bugs.php.net/bug.php?id=62242 on the xml_parser
That was in php5.4/5.5, but could it be worse in php7.0 since my setup worked under php5.6 in ubuntu 15.10 (and any lts version below from 10.04 onwards)?



I managed to get some more php errors reported, but most of them are warnings:

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; HTTPAuthSession has a deprecated constructor in /usr/share/davical/inc/HTTPAuthSession.php on line 17

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; Session has a deprecated constructor in /usr/share/awl/inc/Session.php on line 58

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalProp has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 57

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalComponent has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 353

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalendar has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 969

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; MenuOption has a deprecated constructor in /usr/share/awl/inc/MenuSet.php on line 21

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; MenuSet has a deprecated constructor in /usr/share/awl/inc/MenuSet.php on line 222

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; DBRecord has a deprecated constructor in /usr/share/awl/inc/DataUpdate.php on line 122

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; EntryField has a deprecated constructor in /usr/share/awl/inc/DataEntry.php on line 38

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; EntryForm has a deprecated constructor in /usr/share/awl/inc/DataEntry.php on line 334

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; BrowserColumn has a deprecated constructor in /usr/share/awl/inc/classBrowser.php on line 32

Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; Browser has a deprecated constructor in /usr/share/awl/inc/classBrowser.php on line 174


I didn’t find anything more on this, only that it’s not working.
So, I’m ready to try anything the next few days, but since I need my calendar, I’ll revert to ubuntu 15:10, or set up google calendars for all my users in a few days ;-(.

Antoin


- --
Antoin Verschuren

Tweevoren 6, 5672 SB Nuenen, NL
M: +31 6 37682392







------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general
Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
michael at linuxfox
Apr 27, 2016, 12:02 AM
Post #14 of 16 (4870 views)
Permalink
Am 26.04.16 um 23:45 schrieb Antoin Verschuren:

Hi Antoin,

I did this morning a fresh install - ubuntu 16.04 and davical
First I see, in ubuntu is no "dpkg-davical-configure", so the fresh
calendar-system is not working. I think on ubuntu 15 was a
dkpk-configure, but I am not sure.

root@ubuntu:/etc/davical# ls -al
insgesamt 8
drwxr-xr-x 2 root root 4096 Mär 23 01:51 .
drwxr-xr-x 100 root root 4096 Apr 27 08:56 ..
root@ubuntu:/etc/davical#


Now I have to drive to a customer - I will look to this on afternoon


> Op 26 apr. 2016, om 19:41 heeft Michael Grundmann <michael@linuxfox.de> het volgende geschreven:
>
>> Am 26.04.16 um 15:20 schrieb Antoin Verschuren:
>>
>>
>> [pid 21053] stat("/var/www/principals/", 0x7ffde03b0200) = -1 ENOENT (No
>> such file or directory)
>> [pid 21053] lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
>> [pid 21053] lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
>> [pid 21053] lstat("/var/www/principals", 0x7ffde03b0200) = -1 ENOENT (No
>> such file or directory)
>>
>>
>> no such file or directory?
>
> I see more of these in my trace:
>
> 21053 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)
> 24085 stat("/var/www/cal/caldav.php/maria/", 0x7ffde03b0200) = -1 ENOTDIR (Not a directory)
> 24085 stat("/var/www/maria/", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
> 24085 lstat("/var/www/maria", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
> 24085 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)
> 24076 stat("/var/www/cal/caldav.php/maria/", 0x7ffde03b0200) = -1 ENOTDIR (Not a directory)
> 24076 stat("/var/www/maria/", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
> 24076 lstat("/var/www/maria", 0x7ffde03afed0) = -1 ENOENT (No such file or directory)
> 24076 stat("/var/www/.pgpass", 0x7ffde03ace90) = -1 ENOENT (No such file or directory)
>
> I’m not using a virtual host, but my caldav store is symbolically linked from my existing document root under a subdir /cal.
> I don’t know why the whole path is searched like that, but it doesn’t look look like that breaks anything.
> maria is one of my users, but I don’t know where the .pgpass or principals is coming from…:-s
>
> Could a memory leak have something to do with this?
> I found this bug report: https://bugs.php.net/bug.php?id=62242 on the xml_parser
> That was in php5.4/5.5, but could it be worse in php7.0 since my setup worked under php5.6 in ubuntu 15.10 (and any lts version below from 10.04 onwards)?
>
>
>
> I managed to get some more php errors reported, but most of them are warnings:
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; HTTPAuthSession has a deprecated constructor in /usr/share/davical/inc/HTTPAuthSession.php on line 17
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; Session has a deprecated constructor in /usr/share/awl/inc/Session.php on line 58
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalProp has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 57
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalComponent has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 353
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; iCalendar has a deprecated constructor in /usr/share/awl/inc/iCalendar.php on line 969
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; MenuOption has a deprecated constructor in /usr/share/awl/inc/MenuSet.php on line 21
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; MenuSet has a deprecated constructor in /usr/share/awl/inc/MenuSet.php on line 222
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; DBRecord has a deprecated constructor in /usr/share/awl/inc/DataUpdate.php on line 122
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; EntryField has a deprecated constructor in /usr/share/awl/inc/DataEntry.php on line 38
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; EntryForm has a deprecated constructor in /usr/share/awl/inc/DataEntry.php on line 334
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; BrowserColumn has a deprecated constructor in /usr/share/awl/inc/classBrowser.php on line 32
>
> Deprecated: Methods with the same name as their class will not be constructors in a future version of PHP; Browser has a deprecated constructor in /usr/share/awl/inc/classBrowser.php on line 174
>
>
> I didn’t find anything more on this, only that it’s not working.
> So, I’m ready to try anything the next few days, but since I need my calendar, I’ll revert to ubuntu 15:10, or set up google calendars for all my users in a few days ;-(.
>
> Antoin
>
>
> - --
> Antoin Verschuren
>
> Tweevoren 6, 5672 SB Nuenen, NL
> M: +31 6 37682392
>
>
>
>
>
>
>
> ------------------------------------------------------------------------------
> Find and fix application performance issues faster with Applications Manager
> Applications Manager provides deep performance insights into multiple tiers of
> your business applications. It resolves application problems quickly and
> reduces your MTTR. Get your free trial!
> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
> _______________________________________________
> Davical-general mailing list
> Davical-general@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/davical-general
>


--
Gruß Michael

Wenn du verstehst, was du tust, wirst du nichts lernen

Attached Files:

Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
michael at linuxfox
Apr 27, 2016, 9:33 AM
Post #15 of 16 (4872 views)
Permalink
Hi Antoin,

I am so sorry, but a fresh install works like a charme on Ubuntu 16.04.
Maybe somewhat on your "old" installation was/is broken und you better
do a fresh install, dump your old db und import it on your new?

sorry, but i only can say: it works on a fresh installed ubuntu 16.04

look at:
a) http://www.linuxfox.de/davical/bild1.png
b) http://www.linuxfox.de/davical/bild2.png



--
Gruß Michael

Wenn du verstehst, was du tust, wirst du nichts lernen

Attached Files:

Re: [MASSMAIL] Re: Failures upgrading ubuntu 15.10 -> 16.04 php7 ? [ In reply to ]
davical at antoin
Apr 27, 2016, 2:49 PM
Post #16 of 16 (4867 views)
Permalink
Thank you for trying this Michael,
Yes, I’m giving up. I’ve purged and reinstalled davical, postgres, php, created a new DB, changed my symlink, used an alias, and connected with a clean device, but nothing helped.
Unfortunately I cannot shut this system down due other services, so I dumped my db, and will need to install on another server or perhaps under a virtual server to get this going.
Thanx again,

Antoin


Op 27 apr. 2016, om 18:33 heeft Michael Grundmann <michael@linuxfox.de> het volgende geschreven:

> Hi Antoin,
>
> I am so sorry, but a fresh install works like a charme on Ubuntu 16.04.
> Maybe somewhat on your "old" installation was/is broken und you better
> do a fresh install, dump your old db und import it on your new?
>
> sorry, but i only can say: it works on a fresh installed ubuntu 16.04
>
> look at:
> a) http://www.linuxfox.de/davical/bild1.png
> b) http://www.linuxfox.de/davical/bild2.png
>
>
>
> --
> Gruß Michael
>
> Wenn du verstehst, was du tust, wirst du nichts lernen
> <0x790E12D2.asc>------------------------------------------------------------------------------
> Find and fix application performance issues faster with Applications Manager
> Applications Manager provides deep performance insights into multiple tiers of
> your business applications. It resolves application problems quickly and
> reduces your MTTR. Get your free trial!
> https://ad.doubleclick.net/ddm/clk/302982198;130105516;z_______________________________________________
> Davical-general mailing list
> Davical-general@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/davical-general


------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
Davical-general mailing list
Davical-general@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/davical-general

©2024 GT.net. A Gossamer Threads company.
5th Floor, 455 Granville St., Vancouver, BC V6C 1T1, Canada | Legal