View Issue Details

IDProjectCategoryView StatusLast Update
0004379SOGoBackend Generalpublic2018-02-02 11:49
Reporterdolgov Assigned To 
PriorityhighSeverityminorReproducibilityalways
Status newResolutionopen 
Platformx64OSFreebsdOS Version11.1
Product Version3.2.10 
Summary0004379: Login fail with Unhandled Error Response
Description

Upgrading from sogo-3.2.8 to 3.2.9 and 3.2.10 is successful but login fails with Unhandled error response and the following error from sogo log
[WOWatchDogChild]> (terminated due to signal 6)

Steps To Reproduce

Any Login to SOGO in web-browser

Additional Information

~ # uname -v
FreeBSD 11.1-STABLE #0 r328533: Mon Jan 29 13:47:58 MSK 2018 root@mx1:/usr/obj/usr/src/sys/GENERIC

~ # pkg info sogo3
sogo3-3.2.10_2
Name : sogo3
Version : 3.2.10_2
Installed on : Wed Jan 31 12:45:29 2018 MSK
Origin : www/sogo3
Architecture : FreeBSD:11:amd64
Prefix : /usr/local
Categories : gnustep www
Licenses : GPLv2
Maintainer : euan@potensol.com
WWW : http://sogo.nu/
Comment : Groupware server with a focus on scalability and open standards
Options :
ACTIVESYNC : off
Shared Libs required:
libNGObjWeb.so.4.9
libNGStreams.so.4.9
libobjc.so.4.6
libNGExtensions.so.4.9
libSaxObjC.so.4.9
libNGMime.so.4.9
libgnustep-base.so.1.25
libGDLAccess.so.4.9
libEOControl.so.4.9
libSBJson.so.2
libWEExtensions.so.4.9
libmemcached.so.11
libNGLdap.so.4.9
libDOM.so.4.9
libcurl.so.4
Shared Libs provided:
libSOGo.so.3
libGDLContentStore.so.4.9
libNGCards.so.4.9
libSOGoUI.so.3.2
Annotations :
FreeBSD_version: 1101001
repo_type : binary
repository : FreeBSD
Flat size : 48.4MiB
Description :
SOGo is a fully supported and trusted groupware server with a focus on
scalability and open standards. It provides a rich AJAX-based Web
interface and supports multiple native clients through the use of
standard protocols such as CalDAV, CardDAV and GroupDAV.

WWW: http://sogo.nu/

sogo.log:

Jan 31 13:18:00 sogod [24499]: <0x0x80ca92b90[WOWatchDogChild]> child 24500 exited
Jan 31 13:18:00 sogod [24499]: <0x0x80ca92b90[WOWatchDogChild]> (terminated due to signal 6)
Jan 31 13:18:00 sogod [24499]: <0x0x80b269410[WOWatchDog]> child spawned with pid 24505

TagsNo tags attached.

Activities

dolgov

dolgov

2018-02-01 14:31

reporter   ~0012541

In sogo2 2.3.23 i have same error

Christian Mack

Christian Mack

2018-02-02 09:04

developer   ~0012542

There should be an error message from WOWatchDog before that.
It will tell you, why it is killing your child 24500.

Possible reasons:
It took too long to answer for a status request.
Its memory consumption passed the set treshold.
The child was too long busy with one request.

dolgov

dolgov

2018-02-02 09:08

reporter   ~0012543

WOWatchDog don't send any message before kill

Feb 02 09:56:25 sogod [72082]: <0x0x80c87a690[WOWatchDog]> all children exited. We now terminate.
Feb 02 09:56:25 sogod [72395]: version 3.2.10 (build root@111amd64-default-job-12 201801302135) -- starting
Feb 02 09:56:25 sogod [72395]: vmem size check enabled: shutting down app when vmem > 384 MB. Currently at 0 MB
Feb 02 09:56:25 sogod [72395]: <0x0x80e246b30[SOGoProductLoader]> SOGo products loaded from '/usr/local/GNUstep/Local/Library/SOGo':
Feb 02 09:56:25 sogod [72395]: <0x0x80e246b30[SOGoProductLoader]> Appointments.SOGo, Mailer.SOGo, AdministrationUI.SOGo, CommonUI.SOGo, Contacts.SOGo, ContactsUI.SOGo, MailPartViewers.SOGo, MailerUI.SOGo, MainUI.SOGo, PreferencesUI.SOGo, SchedulerUI.SOGo
Feb 02 09:56:25 sogod [72395]: All products loaded - current memory usage at 0 MB
Feb 02 09:56:25 sogod [72395]: <0x0x80c87a690[WOWatchDog]> listening on 127.0.0.1:20000
Feb 02 09:56:25 sogod [72395]: <0x0x80c87a690[WOWatchDog]> watchdog process pid: 72395
Feb 02 09:56:25 sogod [72395]: <0x0x8030fc940[WOWatchDogChild]> watchdog request timeout set to 10 minutes
Feb 02 09:56:25 sogod [72395]: <0x0x80c87a690[WOWatchDog]> preparing 1 children
Feb 02 09:56:25 sogod [72395]: <0x0x80c87a690[WOWatchDog]> child spawned with pid 72396
2018-02-02 09:56:25.672 sogod[72396:100178] PostgreSQL72 connection established: <0x0x8109b0330[PGConnection]: connection=0x0x80cb13100>
2018-02-02 09:56:25.673 sogod[72396:100178] PostgreSQL72 channel 0x0x80c8a2b30 opened (connection=<0x0x8109b0330[PGConnection]: connection=0x0x80cb13100>)
2018-02-02 09:56:25.673 sogod[72396:100178] PG0x0x80c8a2b30 SQL: SELECT count() FROM sogo_user_profile
2018-02-02 09:56:25.674 sogod[72396:100178] PG0x0x80c8a2b30 SQL: SELECT count(
) FROM sogo_folder_info
2018-02-02 09:56:25.677 sogod[72396:100178] PG0x0x80c8a2b30 SQL: SELECT count(*) FROM sogo_sessions_folder
Feb 02 09:56:25 sogod [72396]: <0x0x80cb0bc40[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 02 09:56:39 sogod [72396]: <0x0x80e31c570[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Feb 02 09:56:39 sogod [72396]: <0x0x80e31c570[SOGoCache]> Using host(s) 'localhost' as server(s)
2018-02-02 09:56:39.297 sogod[72396:100178] PostgreSQL72 connection established: <0x0x811167730[PGConnection]: connection=0x0x80cb14980>
2018-02-02 09:56:39.297 sogod[72396:100178] PostgreSQL72 channel 0x0x80c8a4b10 opened (connection=<0x0x811167730[PGConnection]: connection=0x0x80cb14980>)
2018-02-02 09:56:39.298 sogod[72396:100178] PG0x0x80c8a4b10 SQL: SELECT c_password FROM users WHERE c_uid = 'dolgov'
Feb 02 09:56:39 sogod [72395]: <0x0x80e27efb0[WOWatchDogChild]> child 72396 exited
Feb 02 09:56:39 sogod [72395]: <0x0x80e27efb0[WOWatchDogChild]> (terminated due to signal 6)
Feb 02 09:56:39 sogod [72395]: <0x0x80c87a690[WOWatchDog]> child spawned with pid 72400
2018-02-02 09:56:39.693 sogod[72400:100143] PostgreSQL72 connection established: <0x0x8109b03f0[PGConnection]: connection=0x0x80cb13100>
2018-02-02 09:56:39.693 sogod[72400:100143] PostgreSQL72 channel 0x0x80c8a2b30 opened (connection=<0x0x8109b03f0[PGConnection]: connection=0x0x80cb13100>)
2018-02-02 09:56:39.693 sogod[72400:100143] PG0x0x80c8a2b30 SQL: SELECT count() FROM sogo_user_profile
2018-02-02 09:56:39.695 sogod[72400:100143] PG0x0x80c8a2b30 SQL: SELECT count(
) FROM sogo_folder_info
2018-02-02 09:56:39.697 sogod[72400:100143] PG0x0x80c8a2b30 SQL: SELECT count(*) FROM sogo_sessions_folder
Feb 02 09:56:39 sogod [72400]: <0x0x80cb0bc40[WOHttpAdaptor]> notified the watchdog that we are ready

Christian Mack

Christian Mack

2018-02-02 09:28

developer   ~0012544

So WOWatchDog is only starting a new child, but not killing the old one.
Strange, never had that.

Can you do that query on the command line with psql and the same credentials as in sogo.conf?
SELECT c_password FROM users WHERE c_uid = 'dolgov';

dolgov

dolgov

2018-02-02 10:01

reporter   ~0012545

mail=> SELECT c_password FROM users WHERE c_uid = 'dolgov';
c_password

218ab169663dec20fcb4ca7fa8d9785f
(1 row)

dolgov

dolgov

2018-02-02 11:48

reporter   ~0012546

Last edited: 2018-02-02 11:49

I found same bug on FreeBSD bugtracker
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=224986

Issue History

Date Modified Username Field Change
2018-02-01 09:51 dolgov New Issue
2018-02-01 14:31 dolgov Note Added: 0012541
2018-02-02 09:04 Christian Mack Note Added: 0012542
2018-02-02 09:08 dolgov Note Added: 0012543
2018-02-02 09:28 Christian Mack Note Added: 0012544
2018-02-02 10:01 dolgov Note Added: 0012545
2018-02-02 11:48 dolgov Note Added: 0012546
2018-02-02 11:49 dolgov Note Edited: 0012546