Hi,
Marc Patermann schrieb (23.07.2012 09:55 Uhr):
Slávek Banko schrieb (20.07.2012 16:30 Uhr):
Dne pá 20. července 2012 Marc Patermann napsal(a):
I successfully connected an iPhone to SOGo via CardDAV. The iPhone is
not complaining about the connection. A Virtualhost on port 8800 is
active. I see OPTION and PROFIND action in Apache accesslog and in
sogo.log for /SOGo/dav/test1/.
Here is the log. Is seem there is a loop at "67%", whatever that is.
127.0.0.1 - - [24/Jul/2012:10:51:09 GMT] "PROPFIND /SOGo/dav/test1/
HTTP/1.1" 207 536/439 0.010 1661 67% 0
Jul 24 10:51:19 sogod [1546]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:19 sogod [1546]: |SOGo| request took 0.001386 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:19 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 401 0/0 0.073 - - 0
Jul 24 10:51:19 sogod [1546]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:19 sogod [1546]: |SOGo| request took 0.002265 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:19 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 200 0/0 0.005 - - 0
Jul 24 10:51:19 sogod [1546]: |SOGo| starting method 'PROPFIND' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:19 sogod [1546]: |SOGo| request took 0.003002 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:19 GMT] "PROPFIND /SOGo/dav/test1/
HTTP/1.1" 207 536/439 0.008 1661 67% 0
Jul 24 10:51:29 sogod [1546]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:29 sogod [1546]: |SOGo| request took 0.001487 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:29 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 401 0/0 0.004 - - 0
Jul 24 10:51:29 sogod [1546]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:29 sogod [1546]: |SOGo| request took 0.001545 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:29 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 200 0/0 0.006 - - 0
Jul 24 10:51:29 sogod [1546]: |SOGo| starting method 'PROPFIND' on uri
'/SOGo/dav/test1/'
Jul 24 10:51:29 sogod [1546]: |SOGo| request took 0.003124 seconds to
execute
127.0.0.1 - - [24/Jul/2012:10:51:29 GMT] "PROPFIND /SOGo/dav/test1/
HTTP/1.1" 207 536/439 0.008 1661 67% 0
But on the iPhone I cannot see contacts from the server and contacts
added on the iPhone are not synced to the server.
(CalDAV works as expected.)
I got a backup for the user and the file does only include the contact
added via webGUI or Thunderbird.
What is happening here?
With which debug setting can I see what is wrong?
What debug setting should I use to see more?
I turned everything on I found in the faq, but do not see any helpful info:
Jul 24 11:00:19 sogod [7878]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse: test1
Jul 24 11:00:19 sogod [7878]: |SOGo| do traverse name: 'test1'
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<0x02446C80[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'access contents information' on object: <0x02446C80[SOGoUserFolder]:
name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'access contents information': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x24689e0[SOGoUser]: login=anonymous roles=Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles: Anonymous
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found no matching role.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D still anonymous,
requesting login ...
Jul 24 11:00:19 sogod [7878]: <[so-security]>D value
(0x0x2446c80,SOGoUserFolder) of key test1 didn't validate
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse miss: name=test1:
i=0,count=1
Jul 24 11:00:19 sogod [7878]: |SOGo| miss is last object.
Jul 24 11:00:19 sogod [7878]: |SOGo| handle miss error:
<SoAuthRequiredException: 0x2439c00> NAME:SoAuthRequired
REASON:authentication required
Jul 24 11:00:19 sogod [7878]: |SOGo| request took 0.072266 seconds to
execute
Jul 24 11:00:19 sogod [7878]: <0x0x2246f90[WOResponse]> Zipping of
response disabled
127.0.0.1 - - [24/Jul/2012:11:00:19 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 401 0/0 0.076 - - 0
Jul 24 11:00:19 sogod [7878]: |SOGo| starting method 'OPTIONS' on uri
'/SOGo/dav/test1/'
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse: test1
Jul 24 11:00:19 sogod [7878]: |SOGo| do traverse name: 'test1'
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<0x024B0370[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'access contents information' on object: <0x024B0370[SOGoUserFolder]:
name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'access contents information': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x2486ce0[SOGoUser]: login=test1 roles=Authenticated,Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found a valid role:
'Authenticated'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
permission 'access contents information'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
object (perm=access contents information).
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<SOGo[0x0x2063d30]: name=SOGo>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D object is public.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate key test1 of
object: <SOGo[0x0x2063d30]: name=SOGo>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found no security info
for key (class SOGo): test1
Jul 24 11:00:19 sogod [7878]: <[so-security]>D default is allow ...
Jul 24 11:00:19 sogod [7878]: |SOGo| set clientObject:
<0x024B0370[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'WebDAV Access' on object: <0x024B0370[SOGoUserFolder]: name=test1
container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'WebDAV Access': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x2486ce0[SOGoUser]: login=test1 roles=Authenticated,Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found a valid role:
'Authenticated'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
permission 'WebDAV Access'.
Jul 24 11:00:19 sogod [7878]: |SOGo| request took 0.020950 seconds to
execute
Jul 24 11:00:19 sogod [7878]: <0x0x243bd90[WOResponse]> Zipping of
response disabled
127.0.0.1 - - [24/Jul/2012:11:00:19 GMT] "OPTIONS /SOGo/dav/test1/
HTTP/1.1" 200 0/0 0.025 - - 0
Jul 24 11:00:19 sogod [7878]: |SOGo| starting method 'PROPFIND' on uri
'/SOGo/dav/test1/'
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse: test1
Jul 24 11:00:19 sogod [7878]: |SOGo| do traverse name: 'test1'
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<0x0248F420[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'access contents information' on object: <0x0248F420[SOGoUserFolder]:
name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'access contents information': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x24689e0[SOGoUser]: login=anonymous roles=Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles: Anonymous
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found no matching role.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D still anonymous,
requesting login ...
Jul 24 11:00:19 sogod [7878]: <[so-security]>D value
(0x0x248f420,SOGoUserFolder) of key test1 didn't validate
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse miss: name=test1:
i=0,count=1
Jul 24 11:00:19 sogod [7878]: |SOGo| miss is last object.
Jul 24 11:00:19 sogod [7878]: |SOGo| handle miss error:
<SoAuthRequiredException: 0x241ba00> NAME:SoAuthRequired
REASON:authentication required
Jul 24 11:00:19 sogod [7878]: |SOGo| request took 0.010751 seconds to
execute
Jul 24 11:00:19 sogod [7878]: <0x0x240df30[WOResponse]> Zipping of
response disabled
127.0.0.1 - - [24/Jul/2012:11:00:19 GMT] "PROPFIND /SOGo/dav/test1/
HTTP/1.1" 401 0/439 0.015 - - 0
Jul 24 11:00:19 sogod [7878]: |SOGo| starting method 'PROPFIND' on uri
'/SOGo/dav/test1/'
Jul 24 11:00:19 sogod [7878]: |SOGo| traverse: test1
Jul 24 11:00:19 sogod [7878]: |SOGo| do traverse name: 'test1'
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<0x024672B0[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'access contents information' on object: <0x024672B0[SOGoUserFolder]:
name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'access contents information': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x243e460[SOGoUser]: login=test1 roles=Authenticated,Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found a valid role:
'Authenticated'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
permission 'access contents information'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
object (perm=access contents information).
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate object:
<SOGo[0x0x2063d30]: name=SOGo>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D object is public.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate key test1 of
object: <SOGo[0x0x2063d30]: name=SOGo>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found no security info
for key (class SOGo): test1
Jul 24 11:00:19 sogod [7878]: <[so-security]>D default is allow ...
Jul 24 11:00:19 sogod [7878]: |SOGo| set clientObject:
<0x024672B0[SOGoUserFolder]: name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'WebDAV Access' on object: <0x024672B0[SOGoUserFolder]: name=test1
container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'WebDAV Access': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x243e460[SOGoUser]: login=test1 roles=Authenticated,Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found a valid role:
'Authenticated'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
permission 'WebDAV Access'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D validate permission
'Access Contents Information' on object: <0x024672B0[SOGoUserFolder]:
name=test1 container=0x02063D30/(null)>
Jul 24 11:00:19 sogod [7878]: <[so-security]>D possible roles for
permission 'Access Contents Information': Authenticated, PublicUser
Jul 24 11:00:19 sogod [7878]: <[so-security]>D got user:
<0x0x243e460[SOGoUser]: login=test1 roles=Authenticated,Anonymous>)
Jul 24 11:00:19 sogod [7878]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Jul 24 11:00:19 sogod [7878]: <[so-security]>D found a valid role:
'Authenticated'.
Jul 24 11:00:19 sogod [7878]: <[so-security]>D successfully validated
permission 'Access Contents Information'.
Jul 24 11:00:19 sogod [7878]: |SOGo| request took 0.029908 seconds to
execute
Jul 24 11:00:19 sogod [7878]: <0x0x2475b80[WOResponse]> Zipping of
response disabled
127.0.0.1 - - [24/Jul/2012:11:00:19 GMT] "PROPFIND /SOGo/dav/test1/
HTTP/1.1" 207 1661/439 0.035 - - 0
Apple in the instructions for CardDAV says port 8843:
The port is one of the only things, that you can configure for CardDAV
on the iPhone. And while the iPhone is not complaining and there are
connections on the SOGo side, I don't think this is the problem here.
As expected changing the port does not change anything (else).
Any hints?
Marc
--
[email protected]
https://inverse.ca/sogo/lists