View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0005622SOGoBackend Mailpublic2022-10-08 09:582022-10-20 12:24
ReporterHagbear Assigned To 
PrioritylowSeverityminorReproducibilityalways
Status newResolutionopen 
Product Version5.7.1 
Summary0005622: Sogo hangs after try open a shared folder if modify acl of this folder enabled
Description

Hi,

I use Sogo and Dovecot and use shared folder with acl. It works great, but i found a strange behavior of the sogo web gui.
I configuried dovecot with "acl_defaults_from_inbox=yes", so that the subfolders inherited the acl from the parent folder.
This works fine until i set the "Modify the acl of this folder" option, then the web gui hangs if i try open a subfolder that has no own acl. The log shows:
"sogod [6126]: [ERROR] <0x0x55a42ab17640[WOWatchDog]> No child available to handle incoming request!"
Ends up with that i have to restart the sogo service.
With Thunderbird it works fine. If i create a own acl in this subfolder it also work. If i disable the modify acl option, the webgui also works again.

TagsNo tags attached.

Activities

Christian Mack

Christian Mack

2022-10-10 13:22

developer   ~0016274

error message "No child available to handle incoming request!" normally means you run out of workers.
How many have you set?
Does it help to increase their number?
Hagbear

Hagbear

2022-10-10 16:26

reporter   ~0016277

default i use WOWorkersCount 3, i tried also with 10 but change nothing on this issue.
Christian Mack

Christian Mack

2022-10-11 07:20

developer   ~0016278

Could you enable the following debug option in sogo.conf and send us an anonymized sogo.log?
SOGoDebugRequests = YES;
With that option you get the starting of each request, not just its result in sogo.log.
I suspect some kind of loop here.
Else there would not be that "No child available.." error.
Hagbear

Hagbear

2022-10-13 15:48

reporter   ~0016280

of course.
after i set the option i restart sogo. first login as user test and set "Modify the acl of this folder" on my inbox folder to user wkadmin. than log out and log in again as wkadmin and try to access the shared folder of user test, after i try a few times sogo stop working.

sogo.log (20,514 bytes)    
Oct 13 17:35:45 sogod [11373]: version 5.7.1 -- starting
Oct 13 17:35:45 sogod [11373]: vmem size check enabled: shutting down app when vmem > 384 MB. Currently at 89 MB
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd62d8a60[SOGoProductLoader]> SOGo products loaded from '/usr/lib/GNUstep/SOGo':
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd62d8a60[SOGoProductLoader]>   AdministrationUI.SOGo, Appointments.SOGo, CommonUI.SOGo, Contacts.SOGo, ContactsUI.SOGo, MailPartViewers.SOGo, Mailer.SOGo, MailerUI.SOGo, MainUI.SOGo, PreferencesUI.SOGo, SchedulerUI.SOGo
Oct 13 17:35:45 sogod [11373]: All products loaded - current memory usage at 98 MB
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> listening on 127.0.0.1:20000
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> watchdog process pid: 11373
Oct 13 17:35:45 sogod [11373]: <0x0x7f886f0e3340[WOWatchDogChild]> watchdog request timeout set to 10 minutes
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> preparing 3 children
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> child spawned with pid 11374
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> child spawned with pid 11375
Oct 13 17:35:45 sogod [11373]: <0x0x55bfd630a650[WOWatchDog]> child spawned with pid 11376
Oct 13 17:35:45 sogod [11376]: <0x0x55bfd65200b0[WOHttpAdaptor]> notified the watchdog that we are ready
Oct 13 17:35:45 sogod [11374]: <0x0x55bfd6522f50[WOHttpAdaptor]> notified the watchdog that we are ready
Oct 13 17:35:45 sogod [11375]: <0x0x55bfd62dc4a0[WOHttpAdaptor]> notified the watchdog that we are ready
Oct 13 17:36:01 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo'
Oct 13 17:36:01 sogod [11375]: <0x0x55bfd6182c60[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Oct 13 17:36:01 sogod [11375]: <0x0x55bfd6182c60[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Oct 13 17:36:01 sogod [11375]: [WARN] <0x0x7f886f104a80[WOxElemBuilder]> could not locate builders: WOxExtElemBuilder,WOxExtElemBuilder
Oct 13 17:36:01 sogod [11375]: |SOGo| request took 0.010744 seconds to execute
Oct 13 17:36:01 sogod [11375]: 127.0.0.1 "GET /SOGo HTTP/1.1" 302 0/0 0.012 - - 3M - 12
Oct 13 17:36:01 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/'
Oct 13 17:36:01 sogod [11375]: |SOGo| request took 0.011418 seconds to execute
Oct 13 17:36:01 sogod [11375]: 127.0.0.1 "GET /SOGo/ HTTP/1.1" 200 10317/0 0.013 36752 71% 1M - 12
Oct 13 17:36:15 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/connect'
Oct 13 17:36:15 sogod [11375]: SOGoRootPage successful login from '127.0.0.1' for user 'test' - expire = -1  grace = -1
Oct 13 17:36:15 sogod [11375]: |SOGo| request took 0.263029 seconds to execute
Oct 13 17:36:15 sogod [11375]: 127.0.0.1 "POST /SOGo/connect HTTP/1.1" 200 41/76 0.265 - - 4M - 13
Oct 13 17:36:16 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/test'
Oct 13 17:36:16 sogod [11375]: |SOGo| request took 0.001367 seconds to execute
Oct 13 17:36:16 sogod [11375]: 127.0.0.1 "GET /SOGo/test HTTP/1.1" 302 0/0 0.002 - - 0 - 13
Oct 13 17:36:16 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/test/view'
Oct 13 17:36:16 sogod [11375]: |SOGo| request took 0.002207 seconds to execute
Oct 13 17:36:16 sogod [11375]: 127.0.0.1 "GET /SOGo/test/view HTTP/1.1" 302 0/0 0.003 - - 0 - 13
Oct 13 17:36:16 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail'
Oct 13 17:36:16 sogod [11375]: |SOGo| request took 0.001290 seconds to execute
Oct 13 17:36:16 sogod [11375]: 127.0.0.1 "GET /SOGo/so/test/Mail HTTP/1.1" 302 0/0 0.002 - - 0 - 13
Oct 13 17:36:16 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/view'
Oct 13 17:36:16 sogod [11375]: |SOGo| request took 0.036952 seconds to execute
Oct 13 17:36:16 sogod [11375]: 127.0.0.1 "GET /SOGo/so/test/Mail/view HTTP/1.1" 200 20615/0 0.039 89484 76% 1M - 13
Oct 13 17:36:17 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Calendar/alarmslist?browserTime=1665675377'
Oct 13 17:36:17 sogod [11375]: [WARN] <0x0x55bfd67492b0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Oct 13 17:36:17 sogod [11375]: [WARN] <0x0x55bfd67492b0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Oct 13 17:36:17 sogod [11375]: [WARN] <0x0x55bfd67492b0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Oct 13 17:36:17 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/changes'
Oct 13 17:36:17 sogod [11376]: <0x0x55bfd61816c0[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Oct 13 17:36:17 sogod [11376]: <0x0x55bfd61816c0[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Oct 13 17:36:17 sogod [11375]: |SOGo| request took 0.004380 seconds to execute
Oct 13 17:36:17 sogod [11375]: 127.0.0.1 "GET /SOGo/so/test/Calendar/alarmslist?browserTime=1665675377 HTTP/1.1" 200 63/0 0.006 - - 0 - 13
Oct 13 17:36:17 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/view'
Oct 13 17:36:17 sogod [11376]: |SOGo| request took 0.241276 seconds to execute
Oct 13 17:36:17 sogod [11376]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/changes HTTP/1.1" 200 22/126 0.244 - - 2M - 13
Oct 13 17:36:17 sogod [11375]: |SOGo| request took 0.359647 seconds to execute
Oct 13 17:36:17 sogod [11375]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/view HTTP/1.1" 200 2160/0 0.360 - - 0 - 14
Oct 13 17:36:17 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/view'
Oct 13 17:36:17 sogod [11375]: |SOGo| request took 0.150732 seconds to execute
Oct 13 17:36:17 sogod [11375]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/view HTTP/1.1" 200 2119/48 0.152 - - 3M - 14
Oct 13 17:36:17 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/unseenCount'
Oct 13 17:36:17 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/labels'
Oct 13 17:36:18 sogod [11375]: |SOGo| request took 0.123551 seconds to execute
Oct 13 17:36:18 sogod [11375]: 127.0.0.1 "POST /SOGo/so/test/Mail/unseenCount HTTP/1.1" 200 20/31 0.125 - - 0 - 13
Oct 13 17:36:18 sogod [11376]: |SOGo| request took 0.171427 seconds to execute
Oct 13 17:36:18 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/labels HTTP/1.1" 200 2/0 0.172 - - 0 - 13
Oct 13 17:36:23 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/acls'
Oct 13 17:36:23 sogod [11376]: [WARN] <0x0x7f886f104a80[WOxElemBuilder]> could not locate builders: WOxExtElemBuilder,WOxExtElemBuilder
Oct 13 17:36:23 sogod [11376]: |SOGo| request took 0.109550 seconds to execute
Oct 13 17:36:23 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/acls HTTP/1.1" 200 232/0 0.110 - - 2M - 13
Oct 13 17:36:23 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/UIxAclEditor'
Oct 13 17:36:23 sogod [11376]: |SOGo| request took 0.090410 seconds to execute
Oct 13 17:36:23 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/UIxAclEditor HTTP/1.1" 200 1322/0 0.091 3929 66% 352K - 13
Oct 13 17:36:27 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/userRights?uid=wkadmin'
Oct 13 17:36:27 sogod [11376]: |SOGo| request took 0.103241 seconds to execute
Oct 13 17:36:27 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/userRights?uid=wkadmin HTTP/1.1" 200 279/0 0.104 - - 0 - 13
Oct 13 17:36:30 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/saveUserRights'
Oct 13 17:36:30 sogod [11376]: |SOGo| request took 0.497580 seconds to execute
Oct 13 17:36:30 sogod [11376]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/saveUserRights HTTP/1.1" 200 0/431 0.499 - - 0 - 13
Oct 13 17:36:33 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderDrafts/view'
Oct 13 17:36:33 sogod [11376]: |SOGo| request took 0.167048 seconds to execute
Oct 13 17:36:33 sogod [11376]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/folderDrafts/view HTTP/1.1" 200 467/48 0.168 - - 296K - 13
Oct 13 17:36:33 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderDrafts/labels'
Oct 13 17:36:34 sogod [11376]: |SOGo| request took 0.114215 seconds to execute
Oct 13 17:36:34 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/folderDrafts/labels HTTP/1.1" 200 2/0 0.115 - - 0 - 13
Oct 13 17:36:34 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderSent/view'
Oct 13 17:36:34 sogod [11376]: |SOGo| request took 0.166709 seconds to execute
Oct 13 17:36:34 sogod [11376]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/folderSent/view HTTP/1.1" 200 467/48 0.168 - - 520K - 13
Oct 13 17:36:34 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderSent/labels'
Oct 13 17:36:34 sogod [11376]: |SOGo| request took 0.112045 seconds to execute
Oct 13 17:36:34 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/folderSent/labels HTTP/1.1" 200 2/0 0.113 - - 0 - 13
Oct 13 17:36:35 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderTrash/view'
Oct 13 17:36:35 sogod [11376]: |SOGo| request took 0.162916 seconds to execute
Oct 13 17:36:35 sogod [11376]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/folderTrash/view HTTP/1.1" 200 467/48 0.164 - - 0 - 13
Oct 13 17:36:35 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderTrash/labels'
Oct 13 17:36:35 sogod [11376]: |SOGo| request took 0.110070 seconds to execute
Oct 13 17:36:35 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/Mail/0/folderINBOX/folderTrash/labels HTTP/1.1" 200 2/0 0.111 - - 0 - 13
Oct 13 17:36:36 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/test/logoff'
Oct 13 17:36:36 sogod [11376]: SOGoUserHomePage user 'test' logged off
Oct 13 17:36:36 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/so/test/Mail/0/folderINBOX/folderTrash/expunge'
Oct 13 17:36:36 sogod [11376]: |SOGo| request took 0.011960 seconds to execute
Oct 13 17:36:36 sogod [11376]: 127.0.0.1 "GET /SOGo/so/test/logoff HTTP/1.1" 302 0/0 0.013 - - 0 - 12
Oct 13 17:36:36 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/'
Oct 13 17:36:37 sogod [11376]: |SOGo| request took 0.015914 seconds to execute
Oct 13 17:36:37 sogod [11376]: 127.0.0.1 "GET /SOGo/so/ HTTP/1.1" 200 10316/0 0.017 36758 71% 1M - 12
Oct 13 17:36:37 sogod [11375]: |SOGo| request took 0.109269 seconds to execute
Oct 13 17:36:37 sogod [11375]: [ERROR] <0x0x55bfd6520ef0[WOHttpTransaction]> client disconnected during delivery of response for <WORequest[0x0x55bfd6a4cb70]: method=POST uri=/SOGo/so/test/Mail/0/folderINBOX/folderTrash/expunge app=SOGo rqKey=so rqPath=test/Mail/0/folderINBOX/folderTrash/expunge> (len=36): the socket was shutdown
Oct 13 17:36:37 sogod [11375]: 127.0.0.1 "POST /SOGo/so/test/Mail/0/folderINBOX/folderTrash/expunge HTTP/1.1" 500 36/0 0.110 - - 0 - 14
Oct 13 17:36:46 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/connect'
Oct 13 17:36:46 sogod [11375]: SOGoRootPage successful login from '127.0.0.1' for user 'wkadmin' - expire = -1  grace = -1
Oct 13 17:36:46 sogod [11375]: |SOGo| request took 0.108190 seconds to execute
Oct 13 17:36:46 sogod [11375]: 127.0.0.1 "POST /SOGo/connect HTTP/1.1" 200 45/79 0.109 - - 0 - 14
Oct 13 17:36:47 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin'
Oct 13 17:36:47 sogod [11375]: |SOGo| request took 0.001264 seconds to execute
Oct 13 17:36:47 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin HTTP/1.1" 302 0/0 0.002 - - 0 - 14
Oct 13 17:36:47 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/view'
Oct 13 17:36:47 sogod [11375]: |SOGo| request took 0.001793 seconds to execute
Oct 13 17:36:47 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin/view HTTP/1.1" 302 0/0 0.003 - - 0 - 14
Oct 13 17:36:47 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail'
Oct 13 17:36:47 sogod [11375]: |SOGo| request took 0.001171 seconds to execute
Oct 13 17:36:47 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail HTTP/1.1" 302 0/0 0.002 - - 0 - 14
Oct 13 17:36:47 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail/view'
Oct 13 17:36:47 sogod [11375]: |SOGo| request took 0.018215 seconds to execute
Oct 13 17:36:47 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail/view HTTP/1.1" 200 23617/0 0.020 92781 74% 1M - 14
Oct 13 17:36:48 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Calendar/alarmslist?browserTime=1665675408'
Oct 13 17:36:48 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/folderINBOX/changes'
Oct 13 17:36:48 sogod [11374]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail/0/view'
Oct 13 17:36:48 sogod [11374]: <0x0x55bfd62a5d10[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Oct 13 17:36:48 sogod [11374]: <0x0x55bfd62a5d10[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Oct 13 17:36:48 sogod [11375]: |SOGo| request took 0.002946 seconds to execute
Oct 13 17:36:48 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin/Calendar/alarmslist?browserTime=1665675408 HTTP/1.1" 200 63/0 0.005 - - 0 - 14
Oct 13 17:36:48 sogod [11376]: |SOGo| request took 0.152226 seconds to execute
Oct 13 17:36:48 sogod [11376]: 127.0.0.1 "POST /SOGo/so/wkadmin/Mail/0/folderINBOX/changes HTTP/1.1" 200 21/126 0.153 - - 0 - 13
Oct 13 17:36:48 sogod [11374]: |SOGo| request took 0.218785 seconds to execute
Oct 13 17:36:48 sogod [11374]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail/0/view HTTP/1.1" 200 2052/0 0.220 - - 4M - 13
Oct 13 17:36:48 sogod [11374]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/folderINBOX/view'
Oct 13 17:36:48 sogod [11374]: |SOGo| request took 0.150050 seconds to execute
Oct 13 17:36:48 sogod [11374]: 127.0.0.1 "POST /SOGo/so/wkadmin/Mail/0/folderINBOX/view HTTP/1.1" 200 2143/48 0.151 - - 1M - 13
Oct 13 17:36:48 sogod [11374]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/unseenCount'
Oct 13 17:36:48 sogod [11376]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail/0/folderINBOX/labels'
Oct 13 17:36:49 sogod [11376]: |SOGo| request took 0.119111 seconds to execute
Oct 13 17:36:49 sogod [11376]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail/0/folderINBOX/labels HTTP/1.1" 200 2/0 0.120 - - 0 - 13
Oct 13 17:36:49 sogod [11374]: |SOGo| request took 0.176029 seconds to execute
Oct 13 17:36:49 sogod [11374]: 127.0.0.1 "POST /SOGo/so/wkadmin/Mail/unseenCount HTTP/1.1" 200 20/31 0.177 - - 0 - 12
Oct 13 17:36:51 sogod [11374]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderDrafts/view'
Oct 13 17:36:52 sogod [11374]: |SOGo| request took 0.210382 seconds to execute
Oct 13 17:36:52 sogod [11374]: 127.0.0.1 "POST /SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderDrafts/view HTTP/1.1" 200 466/48 0.211 - - 0 - 13
Oct 13 17:36:52 sogod [11374]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderDrafts/labels'
Oct 13 17:36:52 sogod [11374]: |SOGo| request took 0.171031 seconds to execute
Oct 13 17:36:52 sogod [11374]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderDrafts/labels HTTP/1.1" 200 2/0 0.172 - - 0 - 13
Oct 13 17:36:53 sogod [11374]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderJunk/view'
Oct 13 17:36:57 sogod [11376]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderSent/view'
Oct 13 17:37:00 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderTemplates/view'
Oct 13 17:37:00 sogod [11375]: |SOGo| request took 0.536690 seconds to execute
Oct 13 17:37:00 sogod [11375]: 127.0.0.1 "POST /SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderTemplates/view HTTP/1.1" 200 460/48 0.538 - - 0 - 15
Oct 13 17:37:00 sogod [11375]: |SOGo| starting method 'GET' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderTemplates/labels'
Oct 13 17:37:01 sogod [11375]: |SOGo| request took 0.172861 seconds to execute
Oct 13 17:37:01 sogod [11375]: 127.0.0.1 "GET /SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderTemplates/labels HTTP/1.1" 200 2/0 0.174 - - 0 - 15
Oct 13 17:37:02 sogod [11375]: |SOGo| starting method 'POST' on uri '/SOGo/so/wkadmin/Mail/0/foldershared/foldertest/folderSent/view'
Oct 13 17:37:28 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:29 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:30 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:31 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:33 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:34 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:35 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:36 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:38 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:39 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:40 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:41 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:43 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:44 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:45 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:46 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:48 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:49 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:50 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:52 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:53 sogod [11373]: [WARN] <0x0x55bfd63d0630[WOWatchDogChild]> pid 11374 has been hanging in the same request for 1 minutes
Oct 13 17:37:53 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:54 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:55 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:57 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:57 sogod [11373]: [WARN] <0x0x55bfd63cfb40[WOWatchDogChild]> pid 11376 has been hanging in the same request for 1 minutes
Oct 13 17:37:58 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:37:59 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:38:00 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:38:02 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:38:02 sogod [11373]: [WARN] <0x0x55bfd63cfea0[WOWatchDogChild]> pid 11375 has been hanging in the same request for 1 minutes
Oct 13 17:38:03 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
Oct 13 17:38:04 sogod [11373]: [ERROR] <0x0x55bfd630a650[WOWatchDog]> No child available to handle incoming request!
sogo.log (20,514 bytes)   
Christian Mack

Christian Mack

2022-10-20 12:24

developer   ~0016297

1)Post access for shared/test/Drafts is successful.
With that you get all emails within that folder.
2) You also get all labels of emails within (Get)
3) Then you try a Post for shared/test/Junk, which doesn't get a response for at least 2 minutes.
Therefore the first worker is blocked.
4) Then you try a Post for shared/test/Sent, which also doesn't get a response for at least 2 minutes.
With that the second worker is blocked.
5) Then you get a successful Post request for shared/test/Templates, ...
6) and a successful Get request for its labels.
7) Now you try another Post for shared/test/Sent, which as before doesn't get a response, blocking the last worker.

Whatever you try now throws "No child available to handle incoming request!", as all 3 workers are busy waiting for responses from your IMAP server.

You need to check your IMAP servers logs, why it doesn't respond within several minutes for those folders.

Issue History

Date Modified Username Field Change
2022-10-08 09:58 Hagbear New Issue
2022-10-10 13:22 Christian Mack Note Added: 0016274
2022-10-10 16:26 Hagbear Note Added: 0016277
2022-10-11 07:20 Christian Mack Note Added: 0016278
2022-10-13 15:48 Hagbear Note Added: 0016280
2022-10-13 15:48 Hagbear File Added: sogo.log
2022-10-20 12:24 Christian Mack Note Added: 0016297