To detail more what happens:
I've stopped dovecot, sogo, deleted logs, then restarted in the same order.
now I have:
===============
#tail /var/log/dovecot.message && echo "===============" && tail
/var/log/sogo/sogo.log
2014-05-28 15:27:41 master: Info: Dovecot v2.1.17 starting up (core
dumps disabled)
===============
May 28 15:34:36 sogod [20692]: vmem size check enabled: shutting down
app when vmem > 384 MB
May 28 15:34:36 sogod [20692]: <0x0xb933db18[SOGoProductLoader]> SOGo
products loaded from '/usr/lib/GNUstep/SOGo':
May 28 15:34:36 sogod [20692]: <0x0xb933db18[SOGoProductLoader]>
CommonUI.SOGo, MainUI.SOGo, SchedulerUI.SOGo, Contacts.SOGo,
ContactsUI.SOGo, Mailer.SOGo, PreferencesUI.SOGo, Appointments.SOGo,
MailPartViewers.SOGo, AdministrationUI.SOGo, MailerUI.SOGo
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> listening on
127.0.0.1:20000
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> watchdog
process pid: 20692
May 28 15:34:36 sogod [20692]: <0x0xb74e98c0[WOWatchDogChild]> watchdog
request timeout set to 10 minutes
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> preparing 3
children
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> child spawned
with pid 20710
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> child spawned
with pid 20711
May 28 15:34:36 sogod [20692]: <0x0xb9467600[WOWatchDog]> child spawned
with pid 20712
===============
and stays like that while I'm not logged in the web ui.
apparently it starts 3 children.
if I load the web ui (still logged off) sogo log adds
===============
May 28 15:39:48 sogod [21017]: <0x0xb8325a58[SOGoCache]> Cache cleanup
interval set every 300.000000 seconds
May 28 15:39:48 sogod [21017]: <0x0xb8325a58[SOGoCache]> Using host(s)
'localhost' as server(s)
2014-05-28 15:39:48.252 sogod[21017] Note(SoObject): SoDebugKeyLookup is
enabled!
2014-05-28 15:39:48.253 sogod[21017] Note(SoObject): SoDebugBaseURL is
enabled!
2014-05-28 15:39:48.253 sogod[21017] Note(SoObject): relative base URLs
are enabled.
2014-05-28 15:39:48.257 sogod[21017] ERROR(-[NGBundleManager
bundleWithPath:]): could not create bundle for path:
'/usr/share/GNUstep/Libraries/gnustep-base/Versions/1.22/Resources/SSL.bundle'
2014-05-28 15:39:48.269 sogod[21017] WOCompoundElement: pool embedding
is on.
2014-05-28 15:39:48.269 sogod[21017] WOCompoundElement: id logging is on.
192.168.3.22 - - [28/May/2014:15:39:48 GMT] "GET /SOGo/so/ HTTP/1.1" 200
4273/0 0.057 11946 64% 3M
===============
now if I log into web ui (default module: calendar) sogo log adds:
===============
May 28 15:43:31 sogod [21017]: SOGoRootPage successful login from
'192.168.3.22' for user 'ardito' - expire = -1 grace = -1
May 28 15:43:31 sogod [21017]: [ERROR] <0x0xb874fde0[NGLdapAttribute]>
could not convert value of objectGUID to string
May 28 15:43:31 sogod [21017]: [ERROR] <0x0xb8764908[NGLdapAttribute]>
could not convert value of objectSid to string
May 28 15:43:31 sogod [21017]: [ERROR] <0x0xb87508c0[NGLdapAttribute]>
could not convert value of logonHours to string
May 28 15:43:31 sogod [21017]: [ERROR] <0x0xb8764d18[NGLdapAttribute]>
could not convert value of sIDHistory to string
May 28 15:43:31 sogod [21017]: [WARN]
<0x0xb872a648[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists
in DAV permissions table
May 28 15:43:31 sogod [21017]: [WARN]
<0x0xb872a648[SOGoWebDAVAclManager]> entry '{DAV:}write-properties'
already exists in DAV permissions table
May 28 15:43:31 sogod [21017]: [WARN]
<0x0xb872a648[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already
exists in DAV permissions table
2014-05-28 15:43:31.641 sogod[21017] Note: Using UTF-8 as URL encoding
in NGExtensions.
192.168.3.22 - - [28/May/2014:15:43:31 GMT] "POST /SOGo/connect
HTTP/1.1" 200 27/69 0.035 - - 720K
192.168.3.22 - - [28/May/2014:15:43:31 GMT] "GET /SOGo/so/ardito
HTTP/1.1" 302 0/0 0.002 - - 0
192.168.3.22 - - [28/May/2014:15:43:31 GMT] "GET /SOGo/so/ardito/view
HTTP/1.1" 302 0/0 0.004 - - 4K
192.168.3.22 - - [28/May/2014:15:43:31 GMT] "GET
/SOGo/so/ardito/Calendar HTTP/1.1" 302 0/0 0.003 - - 0
192.168.3.22 - - [28/May/2014:15:43:31 GMT] "GET
/SOGo/so/ardito/Calendar/view HTTP/1.1" 200 13134/0 0.065 47761 72% 1M
2014-05-28 15:43:32.020 sogod[21016] Note: Using UTF-8 as URL encoding
in NGExtensions.
May 28 15:43:32 sogod [21016]: <0x0xb82c9a98[SOGoCache]> Cache cleanup
interval set every 300.000000 seconds
May 28 15:43:32 sogod [21016]: <0x0xb82c9a98[SOGoCache]> Using host(s)
'localhost' as server(s)
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/personal/canAccessContent HTTP/1.1" 204 0/0
0.004 - - 0
2014-05-28 15:43:32.023 sogod[21015] Note: Using UTF-8 as URL encoding
in NGExtensions.
May 28 15:43:32 sogod [21015]: <0x0xb8416db8[SOGoCache]> Cache cleanup
interval set every 300.000000 seconds
May 28 15:43:32 sogod [21015]: <0x0xb8416db8[SOGoCache]> Using host(s)
'localhost' as server(s)
May 28 15:43:32 sogod [20986]: [ERROR] <0x0xb84fa600[WOWatchDog]> No
child available to handle incoming request!
May 28 15:43:32 sogod [20986]: [ERROR] <0x0xb84fa600[WOWatchDog]> No
child available to handle incoming request!
2014-05-28 15:43:32.027 sogod[21015] Note(SoObject): SoDebugKeyLookup is
enabled!
2014-05-28 15:43:32.027 sogod[21015] Note(SoObject): SoDebugBaseURL is
enabled!
2014-05-28 15:43:32.027 sogod[21016] Note(SoObject): SoDebugKeyLookup is
enabled!
2014-05-28 15:43:32.027 sogod[21015] Note(SoObject): relative base URLs
are enabled.
2014-05-28 15:43:32.027 sogod[21016] Note(SoObject): SoDebugBaseURL is
enabled!
2014-05-28 15:43:32.027 sogod[21016] Note(SoObject): relative base URLs
are enabled.
May 28 15:43:32 sogod [21015]: [WARN]
<0x0xb8613ad0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists
in DAV permissions table
May 28 15:43:32 sogod [21015]: [WARN]
<0x0xb8613ad0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties'
already exists in DAV permissions table
May 28 15:43:32 sogod [21015]: [WARN]
<0x0xb8613ad0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already
exists in DAV permissions table
May 28 15:43:32 sogod [21016]: [WARN]
<0x0xb8613900[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists
in DAV permissions table
May 28 15:43:32 sogod [21016]: [WARN]
<0x0xb8613900[SOGoWebDAVAclManager]> entry '{DAV:}write-properties'
already exists in DAV permissions table
May 28 15:43:32 sogod [21016]: [WARN]
<0x0xb8613900[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already
exists in DAV permissions table
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/taskslist?show-completed=0&asc=true&sort=end
HTTP/1.1" 200 2/0 0.004 - - 0
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/alarmslist?browserTime=1401284612 HTTP/1.1" 200
2/0 0.016 - - 1M
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/eventslist?asc=true&sort=start&day=&filterpopup=view_today
HTTP/1.1" 200 532/0 0.017 - - 1M
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/weekview HTTP/1.1" 200 2162/0 0.016 45090 95% 12K
192.168.3.22 - - [28/May/2014:15:43:32 GMT] "POST
/SOGo/so/ardito/Calendar/eventsblocks?sd=20140526&ed=20140601&view=weekview
HTTP/1.1" 200 868/0 0.007 - - 8K
===============
I've read that NGLdapAttribute errors are not so important
(https://lists.inverse.ca/sogo/arc/users/2012-05/msg00298.html)
but about those [WOWatchDog]> No child available to handle incoming
request! ?
and I'm the only user! Could be that 3 children is not enough?
when I switch to address book page adds:
===============
192.168.3.22 - - [28/May/2014:15:47:39 GMT] "GET
/SOGo/so/ardito/Contacts HTTP/1.1" 302 0/0 0.003 - - 0
192.168.3.22 - - [28/May/2014:15:47:39 GMT] "GET
/SOGo/so/ardito/Contacts/view HTTP/1.1" 200 7585/0 0.045 23963 68% 76K
192.168.3.22 - - [28/May/2014:15:47:40 GMT] "POST
/SOGo/so/ardito/Contacts/personal/canAccessContent HTTP/1.1" 204 0/0
0.003 - - 0
192.168.3.22 - - [28/May/2014:15:47:40 GMT] "POST
/SOGo/so/ardito/Contacts/directory/canAccessContent HTTP/1.1" 204 0/0
0.003 - - 0
192.168.3.22 - - [28/May/2014:15:47:40 GMT] "POST
/SOGo/so/ardito/Calendar/alarmslist?browserTime=1401284860 HTTP/1.1" 200
2/0 0.004 - - 0
===============
when I switch to mail page adds:
===============
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb8728a18[NGLdapAttribute]>
could not convert value of objectGUID to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb86897f0[NGLdapAttribute]>
could not convert value of objectSid to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb877dae8[NGLdapAttribute]>
could not convert value of logonHours to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb86da6a8[NGLdapAttribute]>
could not convert value of sIDHistory to string
192.168.3.22 - - [28/May/2014:15:48:40 GMT] "GET /SOGo/so/ardito/Mail
HTTP/1.1" 302 0/0 0.019 - - 0
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb8817df8[NGLdapAttribute]>
could not convert value of objectGUID to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb8783c50[NGLdapAttribute]>
could not convert value of objectSid to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb88320d0[NGLdapAttribute]>
could not convert value of logonHours to string
May 28 15:48:40 sogod [21017]: [ERROR] <0x0xb872b168[NGLdapAttribute]>
could not convert value of sIDHistory to string
2014-05-28 15:48:40.999 sogod[21017] WARNING: IMAP4 connection pooling
is disabled!
2014-05-28 15:48:43.031 sogod[21017] Note(NGImap4Connection): using '/'
as the IMAP4 folder separator.
192.168.3.22 - - [28/May/2014:15:48:43 GMT] "GET
/SOGo/so/ardito/Mail/view HTTP/1.1" 200 10006/0 2.352 34694 71% 1M
192.168.3.22 - - [28/May/2014:15:48:43 GMT] "POST
/SOGo/so/ardito/Calendar/alarmslist?browserTime=1401284923 HTTP/1.1" 200
2/0 0.008 - - 0
2014-05-28 15:48:43.645 sogod[21016] WARNING: IMAP4 connection pooling
is disabled!
2014-05-28 15:48:46.244 sogod[21016] Note(NGImap4Connection): using '/'
as the IMAP4 folder separator.
192.168.3.22 - - [28/May/2014:15:48:46 GMT] "POST
/SOGo/so/ardito/Mail/0/mailboxes HTTP/1.1" 200 534/0 2.764 - - 408K
192.168.3.22 - - [28/May/2014:15:48:46 GMT] "POST
/SOGo/so/ardito/Mail/foldersState HTTP/1.1" 200 48/0 0.003 - - 0
192.168.3.22 - - [28/May/2014:15:48:48 GMT] "POST
/SOGo/so/ardito/Mail/0/folderINBOX/unseenCount HTTP/1.1" 200 13/0 1.553
- - 0
===============
where I experiment the lag, and those timings of 2-3 seconds appear...
hope this sheds some more light...
Marco
-------------------
[Ai sensi e per gli effetti della Legge sulla tutela della privacy
(L. 196/2003), questa mail รจ destinata unicamente alle persone sopra
indicate e le informazioni in essa contenute sono da considerarsi
strettamente riservate. E' proibito leggere, copiare, usare o
diffondere il contenuto della presente mail senza autorizzazione.
Se avete ricevuto questo messaggio per errore, siete pregati di
rispedire la stessa al mittente. Grazie]
--
[email protected]
https://inverse.ca/sogo/lists
