Dear Julian,
Thank you for the reply,
Sure I've tried it with the debugging options from the FAQ.
Here's the log with all relevant verbosity turned on:
Nov 10 17:51:20 sogod [8249]: version 1.3.9 (build @vizzini.inverse.ca
201110281414) -- starting
Nov 10 17:51:20 sogod [8249]: vmem size check enabled: shutting down app when
vmem > 384 MB
Nov 10 17:51:20 sogod [8249]: <0x0x8a35e18[SOGoProductLoader]> SOGo products
loaded from '/usr/lib/GNUstep/SOGo':
Nov 10 17:51:20 sogod [8249]: <0x0x8a35e18[SOGoProductLoader]>
AdministrationUI.SOGo, Appointments.SOGo, ContactsUI.SOGo, CommonUI.SOGo,
MailPartViewers.SOGo, MailerUI.SOGo, Contacts.SOGo, SchedulerUI.SOGo,
Mailer.SOGo, MainUI.SOGo, PreferencesUI.SOGo
Nov 10 17:51:20 sogod [8249]: <0x0x8a4a960[WOWatchDog]> listening on *:20000
Nov 10 17:51:20 sogod [8249]: <0x0x8a4a960[WOWatchDog]> watchdog process pid:
8249
Nov 10 17:51:20 sogod [8249]: <0x0xb7495fe0[WOWatchDogChild]> watchdog request
timeout set to 10 minutes
Nov 10 17:51:20 sogod [8249]: <0x0x8a4a960[WOWatchDog]> preparing 1 children
Nov 10 17:51:20 sogod [8249]: <0x0x8a4a960[WOWatchDog]> child spawned with pid
8255
2011-11-10 17:51:20.449 sogod[8255] PostgreSQL72 connection established:
<0x0x8b45e90[PGConnection]: connection=0x0x8b2d9d0>
2011-11-10 17:51:20.450 sogod[8255] PostgreSQL72 channel 0x0x8b58a48 opened
(connection=<0x0x8b45e90[PGConnection]: connection=0x0x8b2d9d0>)
2011-11-10 17:51:20.450 sogod[8255] PG0x0x8b58a48 SQL: SELECT count(*) FROM
sogo_user_profile
2011-11-10 17:51:20.452 sogod[8255] PG0x0x8b58a48 SQL: SELECT count(*) FROM
sogo_folder_info
2011-11-10 17:51:20.456 sogod[8255] PG0x0x8b58a48 SQL: SELECT count(*) FROM
sogo_sessions_folder
Nov 10 17:51:59 sogod [8255]: |SOGo| starting method 'GET' on uri '/SOGo'
Nov 10 17:51:59 sogod [8255]: <0x0x8cb6420[SOGoCache]> Cache cleanup interval
set every 300.000000 seconds
Nov 10 17:51:59 sogod [8255]: <0x0x8cb6420[SOGoCache]> Using host(s)
'localhost' as server(s)
Nov 10 17:51:59 sogod [8255]: |SOGo| traverse(acquire): SOGo
Nov 10 17:51:59 sogod [8255]: |SOGo| do traverse name: 'SOGo'
2011-11-10 17:51:59.140 sogod[8255] Note(SoObject): SoDebugKeyLookup is
enabled!
2011-11-10 17:51:59.141 sogod[8255] Note(SoObject): SoDebugBaseURL is enabled!
2011-11-10 17:51:59.141 sogod[8255] Note(SoObject): relative base URLs are
enabled.
Nov 10 17:51:59 sogod [8255]: <[so-security]>D validate object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:51:59 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:51:59 sogod [8255]: <[so-security]>D validate key SOGo of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:51:59 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): SOGo
Nov 10 17:51:59 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:51:59 sogod [8255]: |SOGo| set clientObject: <SOGo[0x0x8ac18e0]:
name=SOGo>
2011-11-10 17:51:59.143 sogod[8255] PG0x0x8b58a48 SQL: SELECT c_defaults FROM
sogo_user_profile WHERE c_uid = 'anonymous'
2011-11-10 17:51:59.150 sogod[8255] ERROR(-[NGBundleManager bundleWithPath:]):
could not create bundle for path:
'/usr/share/GNUstep/Libraries/gnustep-base/Versions/1.20/Resources/SSL.bundle'
2011-11-10 17:51:59.163 sogod[8255] WOCompoundElement: pool embedding is on.
2011-11-10 17:51:59.163 sogod[8255] WOCompoundElement: id logging is on.
Nov 10 17:51:59 sogod [8255]: |SOGo| request took 0.030597 seconds to execute
localhost - - [10/Nov/2011:17:51:59 GMT] "GET /SOGo HTTP/1.1" 302 0/0 0.034 - -
1M
Nov 10 17:51:59 sogod [8255]: |SOGo| starting method 'GET' on uri '/SOGo/'
Nov 10 17:51:59 sogod [8255]: |SOGo| traverse(acquire): SOGo
Nov 10 17:51:59 sogod [8255]: |SOGo| do traverse name: 'SOGo'
Nov 10 17:51:59 sogod [8255]: <[so-security]>D validate object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:51:59 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:51:59 sogod [8255]: <[so-security]>D validate key SOGo of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:51:59 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): SOGo
Nov 10 17:51:59 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:51:59 sogod [8255]: |SOGo| set clientObject: <SOGo[0x0x8ac18e0]:
name=SOGo>
2011-11-10 17:51:59.219 sogod[8255] WARNING(-[NSNull(misc) count]): called
NSNull -count (returns 0) !!!
Nov 10 17:51:59 sogod [8255]: |SOGo| request took 0.050411 seconds to execute
localhost - - [10/Nov/2011:17:51:59 GMT] "GET /SOGo/ HTTP/1.1" 200 3596/0 0.052
10904 67% 788K
And after I submit the login form:
Nov 10 17:52:43 sogod [8255]: |SOGo| starting method 'POST' on uri
'/SOGo/connect'
Nov 10 17:52:43 sogod [8255]: |SOGo| traverse(acquire): SOGo => connect
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'SOGo'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key SOGo of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): SOGo
Nov 10 17:52:43 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'connect'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key connect of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission '<public>'
on object: <SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission '<public>'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated key
(connect).
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<0x0x8d43350[SoPageInvocation]: class=SOGoRootPage action=connect bound
instantiated product=<0x0x8ad20a8[SoProduct]: loaded code-loaded
bundle=/usr/lib/GNUstep/SOGo/MainUI.SOGo #classes=8 #categories=4
rm=0x0x8ad42c0>>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key connect of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission '<public>'
on object: <SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission '<public>'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated key
(connect).
Nov 10 17:52:43 sogod [8255]: |SOGo| set clientObject: <SOGo[0x0x8ac18e0]:
name=SOGo>
Nov 10 17:52:43 sogod [8255]: SOGoRootPage successful login for user 'rav' -
expire = -1 grace = -1
2011-11-10 17:52:43.655 sogod[8255] PostgreSQL72 connection established:
<0x0x8d3d610[PGConnection]: connection=0x0x8dca880>
2011-11-10 17:52:43.655 sogod[8255] PostgreSQL72 channel 0x0x8d1c9a8 opened
(connection=<0x0x8d3d610[PGConnection]: connection=0x0x8dca880>)
2011-11-10 17:52:43.656 sogod[8255] PG0x0x8d1c9a8 SQL: BEGIN TRANSACTION
2011-11-10 17:52:43.656 sogod[8255] PG0x0x8d1c9a8 SQL: SELECT
t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM
sogo_sessions_folder t1 WHERE t1.c_id='tkVMMRjg7MpwEqbMyhY8IA=='
2011-11-10 17:52:43.662 sogod[8255] PG0x0x8d1c9a8 SQL: ROLLBACK TRANSACTION
2011-11-10 17:52:43.662 sogod[8255] PG0x0x8b58a48 SQL: BEGIN TRANSACTION
2011-11-10 17:52:43.663 sogod[8255] PG0x0x8b58a48 SQL: INSERT INTO
sogo_sessions_folder (c_value, c_lastseen, c_creationdate, c_id) VALUES
('gCl3IyerkFklZlLIElUEuBPnqyBbyJTVHPeGatVln1eiasYHTWuV6QzapGJFKQ0Uew3PuYMkLglLVOcLxk8/1g==',
1320933163, 1320933163, 'tkVMMRjg7MpwEqbMyhY8IA==')
2011-11-10 17:52:43.664 sogod[8255] PG0x0x8b58a48 SQL: COMMIT TRANSACTION
2011-11-10 17:52:43.677 sogod[8255] -[NGLdapConnection
_searchAtBaseDN:qualifier:attributes:scope:]: search with at base @ filter @
for attrs
2011-11-10 17:52:43.685 sogod[8255] PG0x0x8d1c9a8 SQL: SELECT c_defaults FROM
sogo_user_profile WHERE c_uid = 'rav'
2011-11-10 17:52:43.687 sogod[8255] PG0x0x8b58a48 SQL: BEGIN TRANSACTION
2011-11-10 17:52:43.687 sogod[8255] PG0x0x8b58a48 SQL: UPDATE sogo_user_profile
SET c_defaults = '{"SOGoLanguage": "English"}' WHERE c_uid = 'rav'
2011-11-10 17:52:43.688 sogod[8255] PG0x0x8b58a48 SQL: COMMIT TRANSACTION
Nov 10 17:52:43 sogod [8255]: [WARN] <0x0x8d02d80[SOGoWebDAVAclManager]> entry
'{DAV:}write' already exists in DAV permissions table
Nov 10 17:52:43 sogod [8255]: [WARN] <0x0x8d02d80[SOGoWebDAVAclManager]> entry
'{DAV:}write-properties' already exists in DAV permissions table
Nov 10 17:52:43 sogod [8255]: [WARN] <0x0x8d02d80[SOGoWebDAVAclManager]> entry
'{DAV:}write-content' already exists in DAV permissions table
2011-11-10 17:52:43.691 sogod[8255] PG0x0x8d1c9a8 SQL: SELECT c_settings FROM
sogo_user_profile WHERE c_uid = 'rav'
Nov 10 17:52:43 sogod [8255]: |SOGo| request took 0.091658 seconds to execute
2011-11-10 17:52:43.693 sogod[8255] Note: Using UTF-8 as URL encoding in
NGExtensions.
localhost - - [10/Nov/2011:17:52:43 GMT] "POST /SOGo/connect HTTP/1.1" 200
27/81 0.094 - - 980K
Nov 10 17:52:43 sogod [8255]: |SOGo| starting method 'GET' on uri '/SOGo/rav'
Nov 10 17:52:43 sogod [8255]: |SOGo| traverse(acquire): SOGo => rav
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'SOGo'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key SOGo of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): SOGo
Nov 10 17:52:43 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'rav'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<0x08D0D200[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission 'access
contents information' on object: <0x08D0D200[SOGoUserFolder]: name=rav
container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D possible roles for permission
'access contents information': Authenticated, PublicUser
Nov 10 17:52:43 sogod [8255]: <[so-security]>D got user:
<0x0x8de70a0[SOGoUser]: login=rav roles=Authenticated,Anonymous>)
Nov 10 17:52:43 sogod [8255]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found a valid role:
'Authenticated'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission 'access contents information'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated object
(perm=access contents information).
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key rav of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): rav
Nov 10 17:52:43 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:52:43 sogod [8255]: |SOGo| set clientObject:
<0x08D0D200[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: |SOGo| request took 0.003576 seconds to execute
localhost - - [10/Nov/2011:17:52:43 GMT] "GET /SOGo/rav HTTP/1.1" 302 0/0 0.005
- - 16K
Nov 10 17:52:43 sogod [8255]: |SOGo| starting method 'GET' on uri
'/SOGo/rav/view'
Nov 10 17:52:43 sogod [8255]: |SOGo| traverse(acquire): SOGo => rav => view
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'SOGo'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key SOGo of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): SOGo
Nov 10 17:52:43 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'rav'
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission 'access
contents information' on object: <0x08D45B68[SOGoUserFolder]: name=rav
container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D possible roles for permission
'access contents information': Authenticated, PublicUser
Nov 10 17:52:43 sogod [8255]: <[so-security]>D got user:
<0x0x8d859b8[SOGoUser]: login=rav roles=Authenticated,Anonymous>)
Nov 10 17:52:43 sogod [8255]: <[so-security]>D user roles:
Authenticated,Anonymous,Owner
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found a valid role:
'Authenticated'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission 'access contents information'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated object
(perm=access contents information).
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key rav of object:
<SOGo[0x0x8ac18e0]: name=SOGo>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D found no security info for key
(class SOGo): rav
Nov 10 17:52:43 sogod [8255]: <[so-security]>D default is allow ...
Nov 10 17:52:43 sogod [8255]: |SOGo| do traverse name: 'view'
Nov 10 17:52:43 sogod [8255]: <<0x08D45B68[SOGoUserFolder]:rav>>D traverse key
'view' (acquire=yes) ..
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key view of object:
<0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission '<public>'
on object: <0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission '<public>'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated key
(view).
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate object:
<0x0x8add708[SoPageInvocation]: class=SOGoUserHomePage
product=<0x0x8ad20a8[SoProduct]: loaded code-loaded
bundle=/usr/lib/GNUstep/SOGo/MainUI.SOGo #classes=8 #categories=4
rm=0x0x8ad42c0>>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D object is public.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate key view of object:
<0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D validate permission '<public>'
on object: <0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated
permission '<public>'.
Nov 10 17:52:43 sogod [8255]: <[so-security]>D successfully validated key
(view).
Nov 10 17:52:43 sogod [8255]: <<0x08D45B68[SOGoUserFolder]:rav>>D key 'view'
resolved: <0x0x8add708[SoPageInvocation]: class=SOGoUserHomePage
product=<0x0x8ad20a8[SoProduct]: loaded code-loaded
bundle=/usr/lib/GNUstep/SOGo/MainUI.SOGo #classes=8 #categories=4
rm=0x0x8ad42c0>>
Nov 10 17:52:43 sogod [8255]: |SOGo| set clientObject:
<0x08D45B68[SOGoUserFolder]: name=rav container=0x08AC18E0/(nil)>
Nov 10 17:52:43 sogod [8255]: |SOGo| request took 0.007254 seconds to execute
localhost - - [10/Nov/2011:17:52:43 GMT] "GET /SOGo/rav/view HTTP/1.1" 302 0/0
0.009 - - 0
And there it stops. :(
Maybe I'm missing something in this log?
--
[email protected]
https://inverse.ca/sogo/lists
