Jul 22 00:51:05 sogod [77844]: version 5.8.4 (build root@web-01 202307212357) -- starting Jul 22 00:51:05 sogod [77844]: vmem size check enabled: shutting down app when vmem > 1000 MB. Currently at 432 MB Jul 22 00:51:05 sogod [77844]: <0x0x5606edf97fa0[SOGoProductLoader]> SOGo products loaded from '/usr/local/lib64/GNUstep/SOGo': Jul 22 00:51:05 sogod [77844]: <0x0x5606edf97fa0[SOGoProductLoader]> Appointments.SOGo, Contacts.SOGo, Mailer.SOGo, CommonUI.SOGo, ContactsUI.SOGo, MailPartViewers.SOGo, MailerUI.SOGo, MainUI.SOGo, PreferencesUI.SOGo, SchedulerUI.SOGo, AdministrationUI.SOGo, ActiveSync.SOGo Jul 22 00:51:05 sogod [77844]: All products loaded - current memory usage at 484 MB Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> listening on 0.0.0.0:20000 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> watchdog process pid: 77844 Jul 22 00:51:05 sogod [77844]: <0x0x7fd0f3ef4fe0[WOWatchDogChild]> watchdog request timeout set to 6 minutes Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> preparing 20 children Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77846 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77847 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77848 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77849 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77850 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77851 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77852 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77853 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77854 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77855 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77856 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77857 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77858 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77859 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77860 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77861 Jul 22 00:51:05 sogod [77847]: <0x0x5606ee1f0400[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77846]: <0x0x5606ee1f14d0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77862 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77863 Jul 22 00:51:05 sogod [77849]: <0x0x5606ee1e4fb0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77848]: <0x0x5606ee1ef690[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77864 Jul 22 00:51:05 sogod [77844]: <0x0x5606edfc9fd0[WOWatchDog]> child spawned with pid 77865 Jul 22 00:51:05 sogod [77851]: <0x0x5606ee1eae60[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77850]: <0x0x5606ee1ec4b0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77854]: <0x0x5606ee1e4fb0[WOHttpAdaptor]> notified the watchdog that we are readyJul 22 00:51:05 sogod [77853]: <0x0x5606ee1e7520[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77855]: <0x0x5606ee1e31f0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77852]: <0x0x5606ee1e9cf0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77858]: <0x0x5606ee19db20[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77857]: <0x0x5606ee1c2d40[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77860]: <0x0x5606ede1c8d0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77859]: <0x0x5606ee19cec0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77862]: <0x0x5606ee18ea50[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77856]: <0x0x5606ee1c2d40[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77864]: <0x0x5606ee18ba80[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77865]: <0x0x5606ee16c730[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77863]: <0x0x5606ee18b770[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:05 sogod [77861]: <0x0x5606ee195ae0[WOHttpAdaptor]> notified the watchdog that we are ready Jul 22 00:51:13 sogod [77861]: <0x0x5606edde4db0[SOGoCache]> Cache cleanup interval set every 300.000000 seconds Jul 22 00:51:13 sogod [77861]: <0x0x5606edde4db0[SOGoCache]> Using host(s) '127.0.0.1' as server(s) Jul 22 00:51:13 sogod [77861]: <0x0x5606eddea5d0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table Jul 22 00:51:13 sogod [77861]: <0x0x5606eddea5d0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table Jul 22 00:51:13 sogod [77861]: <0x0x5606eddea5d0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table Jul 22 00:51:13 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/personal/newguid HTTP/1.1" 200 55/0 0.027 - - 1M - 13 Jul 22 00:51:14 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/UIxAppointmentEditorTemplate HTTP/1.1" 200 39114/0 0.114 - - 2M - 13 Jul 22 00:51:26 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Contacts/allContactSearch?search=te HTTP/1.1" 200 2230/0 0.072 - - 932K - 14 Jul 22 00:51:27 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Contacts/allContactSearch?search=test HTTP/1.1" 200 881/0 0.021 - - 0 - 15 Jul 22 00:51:27 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Contacts/allContactSearch?search=test0 HTTP/1.1" 200 36/0 0.018 - - 0 - 15 Jul 22 00:51:28 sogod [77861]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Contacts/allContactSearch?search=test HTTP/1.1" 200 881/0 0.021 - - 0 - 15 Jul 22 00:51:31 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached HeatbeatInterval (354) Jul 22 00:51:31 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached folders ("vevent%2Fpersonal", "mail%2F40b59d35cefcba64cfc53a003abbbae4", "vcard%2Fpersonal", "mail%2F41b59d35cefcba64cfc53a003abbbae4", "vtodo%2Fpersonal") Jul 22 00:51:31 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user testuser02@desplite.ru in Ping... Jul 22 00:51:32 sogod [77863]: <0x0x5606edda7220[SOGoCache]> Cache cleanup interval set every 300.000000 seconds Jul 22 00:51:32 sogod [77863]: <0x0x5606edda7220[SOGoCache]> Using host(s) '127.0.0.1' as server(s) Jul 22 00:51:32 sogod [77865]: <0x0x5606edda7410[SOGoCache]> Cache cleanup interval set every 300.000000 seconds Jul 22 00:51:32 sogod [77865]: <0x0x5606edda7410[SOGoCache]> Using host(s) '127.0.0.1' as server(s) Jul 22 00:51:32 sogod [77864]: <0x0x5606edda7220[SOGoCache]> Cache cleanup interval set every 300.000000 seconds Jul 22 00:51:32 sogod [77864]: <0x0x5606edda7220[SOGoCache]> Using host(s) '127.0.0.1' as server(s) Jul 22 00:51:32 sogod [77865]: <0x0x5606ee0d93e0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table Jul 22 00:51:32 sogod [77865]: <0x0x5606ee0d93e0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table Jul 22 00:51:32 sogod [77865]: <0x0x5606ee0d93e0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table Jul 22 00:51:32 sogod [77864]: <0x0x5606eddd0080[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table Jul 22 00:51:32 sogod [77864]: <0x0x5606eddd0080[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table Jul 22 00:51:32 sogod [77864]: <0x0x5606eddd0080[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table Jul 22 00:51:32 sogod [77863]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Contacts/allContactSearch?search=test HTTP/1.1" 200 881/0 0.094 - - 4M - 14 Jul 22 00:51:32 sogod [77865]: 89.20.1.36 "GET /SOGo/so/testuser02@desplite.ru/freebusy.ifb/ajaxRead?eday=20230728&sday=20230715 HTTP/1.1" 200 2/0 0.063 - - 3M - 13 Jul 22 00:51:32 sogod [77864]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/freebusy.ifb/ajaxRead?eday=20230728&sday=20230715 HTTP/1.1" 200 2/0 0.062 - - 3M - 13 Jul 22 00:51:42 sogod [77864]: 89.20.1.36 "POST /SOGo/so/testuser01@desplite.ru/Calendar/personal/13025-64BAFE00-1-16AC4E20.ics/saveAsAppointment HTTP/1.1" 200 20/11139 0.521 - - 5M - 14 Jul 22 00:51:42 sogod [77864]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/eventslist?asc=1&day=20230722&filterpopup=view_next7&search=title_Category_Location&sort=start&value= HTTP/1.1" 200 863/0 0.023 - - 0 - 14 Jul 22 00:51:42 sogod [77865]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/alarmslist?browserTime=1689976302 HTTP/1.1" 200 60/0 0.019 - - 0 - 14 Jul 22 00:51:42 sogod [77864]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/eventsblocks?ed=20230723&sd=20230717&view=weekview HTTP/1.1" 200 1066/0 0.020 - - 0 - 14 Jul 22 00:51:58 sogod [77864]: <0x0x5606ede04c80[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached HeatbeatInterval (354) Jul 22 00:51:58 sogod [77864]: <0x0x5606ede04c80[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached folders ("mail%2F784fc63af739436486952f003abbbae4", "mail%2Fb8eb4307143a436422962f003abbbae4", "vcard%2Fpersonal") Jul 22 00:52:01 sogod [77865]: 89.20.1.36 "POST /SOGo/so/testuser01@desplite.ru/Mail/0/folderINBOX/changes HTTP/1.1" 200 19/144 0.123 - - 1M - 15 Jul 22 00:52:01 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user testuser02@desplite.ru in Ping... Jul 22 00:52:31 sogod [77844]: [WARN] <0x0x5606ee0930d0[WOWatchDogChild]> pid 77861 has been hanging in the same request for 1 minutes Jul 22 00:52:32 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user testuser02@desplite.ru in Ping... Jul 22 00:52:40 sogod [77865]: <0x0x5606ee4385b0[SOGoActiveSyncDispatcher]> EAS - request for device KKN5M03JQ97UR7RDM6IU028FB8: web-01_12edf_2a6b344f_0 Jul 22 00:52:40 sogod [77865]: <0x0x5606ee4385b0[SOGoActiveSyncDispatcher]> EAS - response for device KKN5M03JQ97UR7RDM6IU028FB8: 1 web-01_12edf_2a6b344f_0 0 Jul 22 00:52:40 sogod [77865]: 95.217.221.171 "POST /SOGo/Microsoft-Server-ActiveSync?User=testuser02@desplite.ru&DeviceId=KKN5M03JQ97UR7RDM6IU028FB8&DeviceType=iPhone&Cmd=FolderSync HTTP/1.1" 200 47/35 0.187 - - 1M - 15 Jul 22 00:52:40 sogod [77865]: <0x0x5606ee441020[SOGoActiveSyncDispatcher]> EAS - request for device KKN5M03JQ97UR7RDM6IU028FB8: -1 vevent%2Fpersonal 25 1 32768 Jul 22 00:52:40 sogod [77865]: <0x0x5606ee441020[SOGoActiveSyncDispatcher]> EAS - Use original serverId: 13025-64BAFE00-1-16AC4E20 (null) Jul 22 00:52:40 sogod [77865]: <0x0x5606ee441020[SOGoActiveSyncDispatcher]> Change detected during Sync, we push the content. Jul 22 00:52:40 sogod [77865]: <0x0x5606ee441020[SOGoActiveSyncDispatcher]> EAS - response for device KKN5M03JQ97UR7RDM6IU028FB8: Calendar 1689976302 vevent%2Fpersonal 1 13025-64BAFE00-1-16AC4E20 0 20230721T215142Z 20230722T070000Z 20230722T080000Z TP///wAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABQ2gAA0H8AANAvUu4GVgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA== testuser01@desplite.ru Тестовый Юзер1 testuser02@desplite.ru Тестовый Юзер2 5 1 1 5 1 2 3 test meeting qwerty 13025-64BAFE00-1-16AC4E20 3 1 Jul 22 00:52:40 sogod [77865]: 95.217.221.171 "POST /SOGo/Microsoft-Server-ActiveSync?User=testuser02@desplite.ru&DeviceId=KKN5M03JQ97UR7RDM6IU028FB8&DeviceType=iPhone&Cmd=Sync HTTP/1.1" 200 618/64 0.041 - - 516K - 15 Jul 22 00:52:42 sogod [77865]: <0x0x5606edf6b730[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached HeatbeatInterval (354) Jul 22 00:52:42 sogod [77865]: <0x0x5606edf6b730[SOGoActiveSyncDispatcher]> EAS - Empty Ping request - using cached folders ("vevent%2Fpersonal", "mail%2F40b59d35cefcba64cfc53a003abbbae4", "vcard%2Fpersonal", "mail%2F41b59d35cefcba64cfc53a003abbbae4", "vtodo%2Fpersonal") Jul 22 00:52:43 sogod [77856]: <0x0x5606edda70a0[SOGoCache]> Cache cleanup interval set every 300.000000 seconds Jul 22 00:52:43 sogod [77856]: <0x0x5606edda70a0[SOGoCache]> Using host(s) '127.0.0.1' as server(s) Jul 22 00:52:43 sogod [77863]: <0x0x5606ee197090[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table Jul 22 00:52:43 sogod [77863]: <0x0x5606ee197090[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table Jul 22 00:52:43 sogod [77863]: <0x0x5606ee197090[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table Jul 22 00:52:43 sogod [77856]: <0x0x5606ede03870[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table Jul 22 00:52:43 sogod [77856]: <0x0x5606ede03870[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table Jul 22 00:52:43 sogod [77856]: <0x0x5606ede03870[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table Jul 22 00:52:43 sogod [77865]: <0x0x5606edf6b730[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user testuser02@desplite.ru in Ping... Jul 22 00:52:43 sogod [77863]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/eventslist?asc=1&day=20230722&filterpopup=view_next7&search=title_Category_Location&sort=start&value= HTTP/1.1" 200 863/0 0.049 - - 1M - 15 Jul 22 00:52:43 sogod [77856]: 89.20.1.36 "GET /SOGo/so/testuser01@desplite.ru/Calendar/eventsblocks?ed=20230723&sd=20230717&view=weekview HTTP/1.1" 200 1066/0 0.043 - - 2M - 14 Jul 22 00:52:58 sogod [77844]: [WARN] <0x0x5606ee0baba0[WOWatchDogChild]> pid 77864 has been hanging in the same request for 1 minutes Jul 22 00:53:02 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> EAS - Ping request canceled (77865) Jul 22 00:53:02 sogod [77861]: <0x0x5606ee120c50[SOGoActiveSyncDispatcher]> EAS - response for device KKN5M03JQ97UR7RDM6IU028FB8: 1 Jul 22 00:53:02 sogod [77861]: 95.217.221.171 "POST /SOGo/Microsoft-Server-ActiveSync?User=testuser02@desplite.ru&DeviceId=KKN5M03JQ97UR7RDM6IU028FB8&DeviceType=iPhone&Cmd=Ping HTTP/1.1" 200 13/0 90.480 - - 2M - 15 Jul 22 00:53:02 sogod [77856]: 89.20.1.36 "POST /SOGo/so/testuser01@desplite.ru/Mail/0/folderINBOX/changes HTTP/1.1" 200 19/144 0.119 - - 1M - 15 Jul 22 00:53:13 sogod [77865]: <0x0x5606edf6b730[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user testuser02@desplite.ru in Ping...