0004379: Login fail with Unhandled Error Response - SOGo | BTS

ID	Project	Category	View Status	Date Submitted	Last Update

0004379	SOGo	Backend General	public	2018-02-01 09:51	2018-02-02 11:49

Reporter	dolgov	Assigned To
Priority	high	Severity	minor	Reproducibility	always
Status	new	Resolution	open
Platform	x64	OS	Freebsd	OS Version	11.1
Product Version	3.2.10

Summary	0004379: 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
Tags	No tags attached.

dolgov 2018-02-01 14:31 reporter ~0012541	In sogo2 2.3.23 i have same error

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 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 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 2018-02-02 10:01 reporter ~0012545	mail=> SELECT c_password FROM users WHERE c_uid = 'dolgov'; c_password 218ab169663dec20fcb4ca7fa8d9785f (1 row)

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

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