CalDAV Unauthorized mit em Client

moe 2018-02-02 10:57:56 UTC #1

Moin,

wie ich schon in diesem Thread geschrieben habe:

Funktioniert der Sync mit dem emClient absolut hervorragend für Kalender, Adressbücher und Infolog.

Es gibt nur ein Detail wo es ein winziges, aber nerviges Problem gibt:

Sobald ich eine einzige DAV-Ressource (Kaldender, Adressbuch, Infolog) verbunden habe und dann eine
Email öffne und den Namen des Empfängers eintippe, scheint der emClient eine Authorisierung per CalDAV zu machen und in diesem Fall scheitert er und bekommt die Rückmeldung “Unauthorized”

Und öffnet dieses Fenster zur Passworteingabe … das kann ich dann durch abbrechen wegklicken, aber es ist total nervig, dass das immer hochkommt.

Ich habe daher mal auf dem eGW Server ins Log geschaut, kann aber nicht genau beurteilen was das schief läuft:

*** 192.168.3.90 2018-02-02T11:38:39+01:00
REPORT /egroupware/groupdav.php/principals/users/kontakttest/ HTTP/1.1
User-Agent: eM Client/7.1.31849.0
Accept-Encoding: gzip, deflate
Content-Type: text/xml; charset=utf-8
Accept: text/xml
Brief: t
Depth: 0
Host: meinedomain.de
Content-Length: 912

<?xml version="1.0" encoding="utf-8"?><D:principal-property-search test="anyof" xmlns:D="DAV:"><D:property-search><D:prop><D:displayname /></D:prop>               <D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><first-name xmlns="http://calendarserver.org/ns/" /><               /D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><last-name xmlns="http://calendarserver.org/n               s/" /></D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><email-address-set xmlns="http://calen               darserver.org/ns/" /></D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:prop><D:displayname /><calendar-user-type xmlns               ="urn:ietf:params:xml:ns:caldav" /><email-address-set xmlns="http://calendarserver.org/ns/" /></D:prop><D:apply-to-principal-collection-set /></D:pr               incipal-property-search>
HTTP/1.1 401 Unauthorized
Date: Fri, 02 Feb 2018 10:38:39 GMT
Server: Apache/2.4.18 (Ubuntu)
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate
Pragma: no-cache
X-Dav-Powered-By: EGroupware 17.1 CalDAV/CardDAV/GroupDAV server
WWW-Authenticate: Basic realm="An error happened: Argument 2 passed to EGroupware\Api\CalDAV\Principals::principal_set() must be of the type array,                null given, called in /usr/share/egroupware/api/src/CalDAV/Principals.php on line 980"
X-WebDAV-Status: 401 Unauthorized
### REPORT principal-property-search /principals/users/kontakttest/ --> "401 Unauthorized" took 0.088 s

*** 192.168.3.90 2018-02-02T11:38:39+01:00
REPORT /egroupware/groupdav.php/principals/users/kontakttest/ HTTP/1.1
User-Agent: eM Client/7.1.31849.0
Accept-Encoding: gzip, deflate
Content-Type: text/xml; charset=utf-8
Accept: text/xml
Brief: t
Depth: 0
Host: meinedomain.de
Content-Length: 912

<?xml version="1.0" encoding="utf-8"?><D:principal-property-search test="anyof" xmlns:D="DAV:"><D:property-search><D:prop><D:displayname /></D:prop>               <D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><first-name xmlns="http://calendarserver.org/ns/" /><               /D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><last-name xmlns="http://calendarserver.org/n               s/" /></D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:property-search><D:prop><email-address-set xmlns="http://calen               darserver.org/ns/" /></D:prop><D:match match-type="starts-with">aher</D:match></D:property-search><D:prop><D:displayname /><calendar-user-type xmlns               ="urn:ietf:params:xml:ns:caldav" /><email-address-set xmlns="http://calendarserver.org/ns/" /></D:prop><D:apply-to-principal-collection-set /></D:pr               incipal-property-search>
HTTP/1.1 401 Unauthorized
Date: Fri, 02 Feb 2018 10:38:39 GMT
Server: Apache/2.4.18 (Ubuntu)
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate
Pragma: no-cache
X-Dav-Powered-By: EGroupware 17.1 CalDAV/CardDAV/GroupDAV server
WWW-Authenticate: Basic realm="An error happened: Argument 2 passed to EGroupware\Api\CalDAV\Principals::principal_set() must be of the type array,                null given, called in /usr/share/egroupware/api/src/CalDAV/Principals.php on line 980"
X-WebDAV-Status: 401 Unauthorized
### REPORT principal-property-search /principals/users/kontakttest/ --> "401 Unauthorized" took 0.081 s

RalfBecker 2018-02-02 11:37:30 UTC #2

Problem ist, dass es zu einem Fehler im PHP Code auf dem Server kommt:

Der einzige Weg so einen Fehler per CalDAV/CardDAV zu signalisieren ist als Authentication Failure.

Muss mir anschauen was da das Problem ist.
Kannst Du Deine Umgebung beschreiben: welche Distro & PHP Version

Ralf

moe 2018-02-02 11:53:03 UTC #3

Hi Ralf,

danke für dein schnelles Feedback.

es ist ein Ubuntu 16.04 server mit PHP 7.0.22 aktuellester Stand.

Gruß Moe

RalfBecker 2018-02-04 08:06:49 UTC #4

Gibt es einen Benutzer “kontakttest”?
Den Fehler kann es eigentlich nur geben, wenn es den Benutzer nicht gibt oder er in keiner einzigen Gruppe Mitglied ist.

Ralf

moe 2018-02-04 15:52:38 UTC #5

Hi Ralf,

Ja, der Benutzer “kontakttest” ist der mit dem ich in diesem Falle teste.
Der Benutzer ist auch in mehreren Gruppen Mitglied und kann sich auch ganz normal über das Webinterface einloggen. Auch der Sync funktioniert ja grundsätzlich mit diesem Benutzer sehr gut.

Gruß Moe

moe 2018-02-05 07:42:30 UTC #6

Moin Ralf,

noch ein Nachtrag:
Wöchentlich lasse ich mir die mit Logwatch aufbereiteten Logs zusenden.
Hier gibt es auch schon solange wir CalDAV nutzen diese Meldungen…
Obwohl auch da der Sync im Prinzip funktioniert.
Ich habe die user0 - user5 Namen ausgetauscht. Es handelt sich auch hier um vorhandene User.
Der “kontakttest” User den ich für die Tests benutzte führt als Topscorer die Unauthorized-Liste an.

  401 Unauthorized
     /egroupware/groupdav.php/principals/users/kontakttest/: 319 Time(s)
     /egroupware/groupdav.php/user0/: 209 Time(s)
     /egroupware/groupdav.php/: 205 Time(s)
     /egroupware/groupdav.php/principals/users/user1/: 113 Time(s)
     /egroupware/groupdav.php/user2/calendar/: 92 Time(s)
     /egroupware/groupdav.php/user3/calendar/: 79 Time(s)
     /egroupware/groupdav.php/user4/: 69 Time(s)
     /egroupware/groupdav.php/user5/calendar/: 53 Time(s)

RalfBecker 2018-02-05 07:54:43 UTC #7

Der 401 Unauthorized kommt halt für alle Fehler, dh. es muss nicht immer der gleiche sein.

Was hast Du für ein Account Backend?
Evtl. haben wir ja da ein Problem mit den Gruppenmitgliedschaften.

Ralf

moe 2018-02-05 07:55:29 UTC #8

Account Backend ist LDAP.

Gruß Moe

RalfBecker 2018-02-05 08:34:10 UTC #9

Hmm, evtl. liegt da ja ein Problem.

Ich habe mir den Code nochmal angeschaut, kann aber auf den ersten Blick nichts auffälliges finden.

Du kannst mal den folgenden Patch probieren:

RalfsMac:egroupware ralf$ git diff api/src/Accounts.php
diff --git a/api/src/Accounts.php b/api/src/Accounts.php
index ec3ac52aa0..054eb74e97 100644
--- a/api/src/Accounts.php
+++ b/api/src/Accounts.php
@@ -1195,9 +1195,10 @@ class Accounts

                        $account = Cache::getCache($instance->config['install_id'], __CLASS__, 'account-'.$account_id);

-                       if (!isset($account))   // not in instance cache --> read from backend
+                       if (!isset($account) ||         // not in instance cache --> read from backend
+                               empty($account[$instance->get_type($account_id) == 'u' ? 'memberships' : 'members']))
                        {
-                               if (($account = $instance->backend->read($account_id)))
+                               if ($account || ($account = $instance->backend->read($account_id)))
                                {
                                        if ($instance->get_type($account_id) == 'u')
                                        {

Er sorgt dafür wenn ein Account ohne members(hips) gecached wurde, das diese nachgeladen werden. Wie es dazu kommt ist mir unklar.

Ich weiß das wir dazu schon immer mal wieder Reports hatten, aber nie genug Feedback um die Ursache zu finden und zu beheben.

Ralf

moe 2018-02-05 08:42:59 UTC #10

Ja, teste ich gerne … allerdings auf unserem Testserver.
Dort kann ich nur natürlich nur für die Tests mit dem Testuser sprechen … das läuft aber gegen den gleichen LDAP (Mirror).

Könntest du mir evtl. eine fertige Datei zur Verfügung stellen, die ich austauschen kann?
Moe

RalfBecker 2018-02-05 09:23:21 UTC #11

Accounts.php (40.4 KB)

Nach api/src/Accounts.php speichern.

Ralf

moe 2018-02-05 11:32:48 UTC #12

Hallo Ralf,

ich habe nun mal getestet und etwas interessantes festgestellt.
Vorab: die Codeänderung hat nichts geändert was das Problem angeht.

ABER: Im Apache-Error.log gibt es immer wenn der Fehler auftritt einen Stacktrace bestehend aus den folgenden Zeilen. Wenn ich den Apache neu starte und dann den Fehler provoziere, kommt dieser Stacktrace genau einmal und im Client gibt es kein augenscheinliches Problem.
Aber sobald ich den Fehler ein zweites Mal provoziere tritt er wieder auf UND der Stacktrace aus den identischen Zeilen kommt genau zweimal. Da das Verhalten sich unterscheidet sobald einmal etwas in den Cache gelaufen ist, gehe ich stark davon aus, dass es ein Caching-problem ist wie von dir vermutet.
Allerdings sollte der Fehler vermutlich auch gar nicht auftreten (also die Fehler im Log).

Hier jetzt einmal der Stacktrace (Wenn der Fehler im Client hochkommt , gibt es diesen 2x hintereinander).

[Mon Feb 05 12:21:06.560403 2018] [:error] [pid 16608] [client 192.168.3.90:61713] An error happened (TypeError): Argument 2 passed to EGroupware\\Api\\CalDAV\\Principals::principal_set() must be of the type array, null given, called in /usr/share/egroupware/api/src/CalDAV/Principals.php on line 980
[Mon Feb 05 12:21:06.560572 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #0 /usr/share/egroupware/api/src/CalDAV/Principals.php(980): EGroupware\\Api\\CalDAV\\Principals->principal_set('group-membershi...', NULL, Array, '0')
[Mon Feb 05 12:21:06.560589 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #1 /usr/share/egroupware/api/src/CalDAV/Principals.php(794): EGroupware\\Api\\CalDAV\\Principals->add_account(Array)
[Mon Feb 05 12:21:06.560617 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #2 /usr/share/egroupware/api/src/CalDAV/Principals.php(1628): EGroupware\\Api\\CalDAV\\Principals->propfind_users('', '', Array)
[Mon Feb 05 12:21:06.560628 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #3 /usr/share/egroupware/api/src/CalDAV/Principals.php(157): EGroupware\\Api\\CalDAV\\Principals->propfind_principals(Array)
[Mon Feb 05 12:21:06.560639 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #4 /usr/share/egroupware/api/src/CalDAV/Principals.php(522): EGroupware\\Api\\CalDAV\\Principals->propfind('/principals/', Array, Array, 2521)
[Mon Feb 05 12:21:06.560649 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #5 /usr/share/egroupware/api/src/CalDAV/Principals.php(125): EGroupware\\Api\\CalDAV\\Principals->principal_property_search_report('/principals/', Array, Array, 2521)
[Mon Feb 05 12:21:06.560659 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #6 /usr/share/egroupware/api/src/CalDAV.php(441): EGroupware\\Api\\CalDAV\\Principals->propfind('/principals/use...', Array, Array, 2521, 'kontakttest')
[Mon Feb 05 12:21:06.560670 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #7 /usr/share/egroupware/api/src/CalDAV.php(966): EGroupware\\Api\\CalDAV->PROPFIND(Array, Array, 'REPORT')
[Mon Feb 05 12:21:06.560681 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #8 /usr/share/egroupware/api/src/WebDAV/Server.php(686): EGroupware\\Api\\CalDAV->REPORT(Array, Array)
[Mon Feb 05 12:21:06.560691 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #9 /usr/share/egroupware/api/src/CalDAV.php(976): HTTP_WebDAV_Server->http_PROPFIND('REPORT')
[Mon Feb 05 12:21:06.560701 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #10 /usr/share/egroupware/api/src/WebDAV/Server.php(306): EGroupware\\Api\\CalDAV->http_REPORT()
[Mon Feb 05 12:21:06.560711 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #11 /usr/share/egroupware/api/src/CalDAV.php(2052): HTTP_WebDAV_Server->ServeRequest(NULL)
[Mon Feb 05 12:21:06.560720 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #12 /usr/share/egroupware/groupdav.php(52): EGroupware\\Api\\CalDAV->ServeRequest()
[Mon Feb 05 12:21:06.560730 2018] [:error] [pid 16608] [client 192.168.3.90:61713] #13 {main}
[Mon Feb 05 12:21:06.560750 2018] [:error] [pid 16608] [client 192.168.3.90:61713] # Instance=default, User=kontakttest, Request=REPORT https://egwtest.meinedomain.de/egroupware/groupdav.php/principals/users/kontakttest/, User-agent=eM Client/7.1.31849.0

moe 2018-02-06 08:58:35 UTC #13

Hallo Ralf,

kann ich dir hier noch irgendwas zur Klärung liefern oder testen?

Moe

moe 2018-02-12 07:17:43 UTC #14

Hallo Ralf,

könntest du mir hierzu bitte noch ein Feedback geben?
Für den Kunden hängt die Entscheidung für oder gegen
eGroupware genau davon ab ob der Sync sauber funktioniert.

BTW: Ich habe auch in den Logs generell seit Jahren gesehen dass dort für alle User “Unauthorized” Meldungen bei Benutzung von CalDAV/WebDAV auftreten. Diese waren aber eher “geräuschlos”.
Das lässt aber trotzdem vermuten, dass irgendwas nicht korrekt funktioniert bzw. falsche Rückmeldungen kommen.

Gruß Moe

moe 2018-02-13 13:59:01 UTC #15

Das Problem ist gelöst!

Der Fehler liegt in der Funktion “memberships” in der Accounts.php.

Wenn die account_ID = 0 ist (was klassicherweise bei root der Fall ist)
schlägt der Vergleich IF-Klausel fehl und die Funktion gibt NULL an die
Funktion “principal_set” zurück daher fliegt einem diese Funktion um die Ohren.

Hier der diff als Patchvorschlag:

 api/src/Accounts.php | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/api/src/Accounts.php b/api/src/Accounts.php
index ec3ac52aa0..6cc58eed06 100644
--- a/api/src/Accounts.php
+++ b/api/src/Accounts.php
@@ -860,10 +860,14 @@ class Accounts
 		{
 			$account_id = $this->name2id($account_id,'account_lid','u');
 		}
-		if ($account_id && ($data = self::cache_read($account_id)))
+		if ($account_id !== false && ($data = self::cache_read($account_id)))
 		{
 			$ret = $just_id && $data['memberships'] ? array_keys($data['memberships']) : $data['memberships'];
 		}
+		else
+		{
+			$ret = array();
+		}
 		//error_log(__METHOD__."($account_id, $just_id) data=".array2string($data)." returning ".array2string($ret));
 		return $ret;
 	}
--

Ergänzung:
Der emClient scheint “intelligent” über alles was er übder die DAV-Schnittstelle bekommt zu iterieren. Denn im Testfall habe ich lediglich
einen Klandersync und keinen mit Adressbuch eingerichtet. Trotzdem fragt er das automatisch ab.

Moe

moe 2018-02-21 08:42:11 UTC #16

Hallo Ralf,

nochmals die Bitte um Rückmeldung… kannst du diesen Fix so einbauen?

Moe

RalfBecker 2018-02-21 09:27:40 UTC #17

Die Begründung die Du gibst ist falsch, wir haben keinen Benutzer root mit account_id 0, das ist nur in implizites Konstrukt im Dateimanager.

Das heißt es erklärt nicht warum oder wie es bei Dir einen Benutzer ohne Gruppenmitgliedschaften gibt.

Bau doch mal an der Stelle Deines Patches folgendes zusätzlich ein:

	function memberships($account_id, $just_id=false)
	{
		$_account_id = $account_id;
		if (!is_int($account_id) && !is_numeric($account_id))
		{
			$account_id = $this->name2id($account_id,'account_lid','u');
		}
		error_log(__METHOD__."(".array2string($_account_id).", ".array2string($just_id).") account_id=".array2string($account_id)." ". function_backtrace());

Ralf

moe 2018-02-21 13:02:15 UTC #18

Den User root im LDAP gab es schon lange bevor es beim Kunden eGroupware gab da die LDAP-DB einfach schon älter ist. LDAP kann doch auch einfach Nutzer enthalten, die in keiner Gruppe Mitglied sind. Was spricht dagegen?

Moe

RalfBecker 2018-02-21 13:26:47 UTC #19

So macht das ja schon mehr Sinn.

Dann sollte self::cache_read($account_id=0) bei dir ja etwas zurück liefern, das evtl. keine memberships enthält.

In dem Fall sollte der Code dann so aussehen:

		if ($account_id !== false && ($data = self::cache_read($account_id)))
		{
			$ret = $just_id && $data['memberships'] ? array_keys($data['memberships']) : (array)$data['memberships'];
		}

Damit wird für nicht existierende Konten immer noch NULL zurück geliefert.

Versuch das mal bei Dir. Wenn es nicht funktioniert pose mal das die error_log aus meinem letzten Post liefern.

Ralf

moe 2018-02-27 14:02:18 UTC #20

Hallo Ralf,

zwischenzeitlich habe ich das Problem beseitigt, indem ich den Benutzer “root” aus LDAP gelöscht habe. Daher kann ich leider nicht testen, ob der Patch Besserung bringt.

Bei meinen Tests ist mir jedoch aufgefallen, dass eGroupware “root” immer die Account-ID 0 zugewiesen hat, selbst nachdem diese im LDAP geändert wurde und ich per Neustart sichergestellt habe, dass keine Caches dazwischenfunken konnten.

Vorher wie nachher jedenfalls war “root” für eGroupware scheinbar nicht existent. Folgerichtig lieferte die Funktion EGroupware\Api\Accounts::memberships() als Ergebnis null zurück. Da in der Funktion EGroupware\Api\CalDAV\Principals::add_account() der Rückgabewert von memberships() direkt an die Funktion EGroupware\Api\CalDAV\Principals::principals_set() übergeben wird (Zeilen 979-980), diese jedoch gemäß Type Hint ein Array als Parameter erwartet, brach PHP mit dem oben beschriebenen TypeError ab.

Moe