View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0002875SOGoBackend Generalpublic2014-08-03 10:012016-12-15 18:03
Reporterbf-sogo Assigned To 
PrioritynormalSeverityminorReproducibilityalways
Status newResolutionopen 
Platform[Server] LinuxOSUbuntuOS Version14.04 LTS
Product Version2.2.7 
Summary0002875: SOGo core dumps signal 6 after running out of database connections
Description

SOGo 2.2.7 (WOWorkersCount 4) is connected to a Postgresql 9.3.4 unix socket. The Connection limit for postgres is 250.

Browsing the calendar results in many database connections being spawned. Eventually SOGo stops displaying events in the calendar, the log shows sogod could not open additional conenctions to the database, received a signal 6 and dumped its core.

Immediately after startup 5 sogod (4 workers) are running, 16 postgres sogodb processes are running. After logging in the user in monthly calendar view 71 postgres sogodb processes are running. The user has 9 calendars on display (2 owned, 7 shared owned by other users). Browsing back through the monthly calendar view adds 9 postgres sogodb processes per month. At some point (usually after >100 postgres sogodb processes are running) no more events are displayed, the log shows sogod has shut down. Increasing the number of workers does not seem to make a difference.

Steps To Reproduce

replicate setup, browse calendar

Additional Information

sogo.log excerpt before crash:
192.168.4.48 - - [03/Aug/2014:11:52:28 GMT] "POST /SOGo/so/testuser/Calendar/dateselector?day=20140601 HTTP/1.0" 200 799/0 0.026 11078 92% 48K
192.168.4.48 - - [03/Aug/2014:11:52:28 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140601 HTTP/1.0" 200 1311/0 0.031 7598 82% 20K
192.168.4.48 - - [03/Aug/2014:11:52:28 GMT] "POST /SOGo/so/testuser/Calendar/eventsblocks?sd=20140526&ed=20140706&view=monthview HTTP/1.0" 200 3923/0 0.370 33454 88% 4M
192.168.4.48 - - [03/Aug/2014:11:52:35 GMT] "POST /SOGo/so/testuser/Calendar/dateselector?day=20140501 HTTP/1.0" 200 735/0 0.017 9370 92% 0
192.168.4.48 - - [03/Aug/2014:11:52:35 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140501 HTTP/1.0" 200 1197/0 0.017 6466 81% 0
192.168.4.48 - - [03/Aug/2014:11:52:35 GMT] "POST /SOGo/so/testuser/Calendar/eventsblocks?sd=20140428&ed=20140601&view=monthview HTTP/1.0" 200 3091/0 0.380 23806 87% 1M
192.168.4.48 - - [03/Aug/2014:11:52:40 GMT] "POST /SOGo/so/testuser/Calendar/dateselector?day=20140401 HTTP/1.0" 200 747/0 0.017 9371 92% -276K
192.168.4.48 - - [03/Aug/2014:11:52:40 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140401 HTTP/1.0" 200 1173/0 0.023 6486 81% 0
Aug 03 11:52:50 sogod [7570]: [ERROR] <0x0x7f6961ceed98[WOWatchDog]> No child available to handle incoming request!
192.168.4.48 - - [03/Aug/2014:11:52:50 GMT] "POST /SOGo/so/testuser/Calendar/alarmslist?browserTime=1407059570 HTTP/1.0" 200 2/0 0.054 - - 0
192.168.4.48 - - [03/Aug/2014:11:52:50 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140401 HTTP/1.0" 200 1173/0 0.015 6486 81% 0
192.168.4.48 - - [03/Aug/2014:11:52:50 GMT] "POST /SOGo/so/testuser/Calendar/activeTasks HTTP/1.0" 200 267/0 0.152 - - 476K
192.168.4.48 - - [03/Aug/2014:11:52:50 GMT] "POST /SOGo/so/testuser/Calendar/taskslist?show-completed=0&asc=true&sort=end&filterpopup=view_today HTTP/1.0" 200 2/0 0.200 - - 32K
192.168.4.48 - - [03/Aug/2014:11:52:50 GMT] "POST /SOGo/so/testuser/Calendar/eventslist?asc=true&sort=start&day=20140401&filterpopup=view_next14 HTTP/1.0" 200 657/0 0.275 3026 78% 0
192.168.4.48 - - [03/Aug/2014:11:52:57 GMT] "POST /SOGo/so/testuser/Calendar/dateselector?day=20140301 HTTP/1.0" 200 810/0 0.023 11077 92% 0
192.168.4.48 - - [03/Aug/2014:11:52:57 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140301 HTTP/1.0" 200 1184/0 0.026 6483 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:05 GMT] "POST /SOGo/so/testuser/Calendar/dateselector?day=20140201 HTTP/1.0" 200 751/0 0.153 9380 91% 0
192.168.4.48 - - [03/Aug/2014:11:53:05 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140201 HTTP/1.0" 200 1194/0 0.150 6537 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:12 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140301 HTTP/1.0" 200 1184/0 0.019 6483 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:13 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140401 HTTP/1.0" 200 1173/0 0.022 6486 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:14 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140501 HTTP/1.0" 200 1197/0 0.019 6466 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:16 GMT] "POST /SOGo/so/testuser/Calendar/dateselector HTTP/1.0" 200 751/0 0.017 9375 91% 0
192.168.4.48 - - [03/Aug/2014:11:53:16 GMT] "POST /SOGo/so/testuser/Calendar/monthview HTTP/1.0" 200 1199/0 0.026 6481 81% 0
192.168.4.48 - - [03/Aug/2014:11:53:16 GMT] "POST /SOGo/so/testuser/Calendar/eventsblocks?sd=20140728&ed=20140831&view=monthview HTTP/1.0" 200 1593/0 0.351 10989 85% 2M
192.168.4.48 - - [03/Aug/2014:11:53:22 GMT] "POST /SOGo/so/testuser/Calendar/monthview?day=20140701 HTTP/1.0" 200 1179/0 0.024 6479 81% 0
EXCEPTION: <PostgreSQL72CouldNotOpenChannelException: 0x7f6962032b38> NAME:NoMoreConnections REASON:cannot open a additional connection ! INFO:(null)
Aug 03 11:53:22 sogod [7570]: <0x0x7f6961c007c8[WOWatchDogChild]> child 7573 exited
Aug 03 11:53:22 sogod [7570]: <0x0x7f6961c007c8[WOWatchDogChild]> (terminated due to signal 6, coredump)

TagsNo tags attached.

Activities

ludovic

ludovic

2016-12-15 18:03

administrator   ~0010996

If you can reproduce it easily (I can't), produce a stack trace: https://sogo.nu/nc/support/faq/article/how-do-i-debug-sogo.html

Issue History

Date Modified Username Field Change
2014-08-03 10:01 bf-sogo New Issue
2016-12-15 18:03 ludovic Note Added: 0010996
2016-12-15 18:03 ludovic Severity crash => minor