View Issue Details

IDProjectCategoryView StatusLast Update
0004739SOGoBackend Calendarpublic2019-04-27 20:51
Reportertetsuo Assigned To 
PrioritynormalSeveritymajorReproducibilityalways
Status newResolutionopen 
Platform[Server] LinuxOSDebianOS Version8 (Jessie)
Product Version4.0.7 
Summary0004739: Calendar made public unreachable once access to DB tears down
Description

Afer activating public calendars and doing some testing to load the exported ics onto a website, it works for the first few minutes and then Sogo starts giving 404.

Activating debug, I can only see that sogo triggers the 404 without attempting to connect to the DB, even when there are connections established.

To get it working again I need to reconnect to the website with that particular user.

I am using LDAP auth + MySQL DB.

Problem happens both with memcached running or stopped.

Steps To Reproduce

Create a public calendar, curl it to verify you can download it from wherever.

Wait about 5-10 minutes, the curl command now fails and return 404.

Check Sogo logs, it returns 404 and no request is made to the database.

If I (re)initiate a connection to the website with the account of the user sharing the calendar, my curl requests are working again for few minutes.

Additional Information

On success, when access to the user sharing the calendar is fresh:

Apr 23 20:58:13 sogod [27451]: |SOGo| starting method 'GET' on uri '/SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics'
2019-04-23 20:58:13.870 sogod[27451:27451] <MySQL4Channel[0x0x563e6687e4d0] connection=0x0x563e66848f38> SQL: SELECT c_path4 FROM sogo_folder_info WHERE c_path2 = 'contact' AND c_folder_type = 'Appointment';
2019-04-23 20:58:13.870 sogod[27451:27451] <MySQL4Channel[0x0x563e6687e4d0] connection=0x0x563e66848f38> query has results, entering fetch-mode.
2019-04-23 20:58:13.871 sogod[27451:27451] <MySQL4Channel[0x0x563e66870170] connection=0x0x563e6675a888> SQL: SELECT b.c_name,b.c_version,b.c_lastmodified,b.c_creationdate,a.c_component,b.c_content FROM sogocontact00100b0efb3_quick a, sogocontact00100b0efb3 b WHERE (c_classification = 0) AND a.c_name = b.c_name AND (c_deleted != 1 OR c_deleted IS NULL);
2019-04-23 20:58:13.872 sogod[27451:27451] <MySQL4Channel[0x0x563e66870170] connection=0x0x563e6675a888> query has results, entering fetch-mode.
2019-04-23 20:58:13.879 sogod[27451:27451] <MySQL4Channel[0x0x563e6687e4d0] connection=0x0x563e66848f38> SQL: SELECT c_foldername FROM sogo_folder_info WHERE c_path = '/Users/contact/Calendar/602B-5CBDED80-1-73939F80';
2019-04-23 20:58:13.879 sogod[27451:27451] <MySQL4Channel[0x0x563e6687e4d0] connection=0x0x563e66848f38> query has results, entering fetch-mode.
2019-04-23 20:58:13.880 sogod[27451:27451] <MySQL4Channel[0x0x563e66870170] connection=0x0x563e6675a888> SQL: SELECT c_lastmodified FROM sogocontact00100b0efb3 ORDER BY c_lastmodified DESC;
2019-04-23 20:58:13.880 sogod[27451:27451] <MySQL4Channel[0x0x563e66870170] connection=0x0x563e6675a888> query has results, entering fetch-mode.
Apr 23 20:58:13 sogod [27451]: |SOGo| request took 0.011309 seconds to execute
Apr 23 20:58:13 sogod [27451]: ::ffff:X.X.145.X, ::ffff:X.X.145.X "GET /SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics HTTP/1.1" 200 1135/0 0.012 - - 0

When it fails:

Apr 23 21:08:23 sogod [27450]: |SOGo| starting method 'GET' on uri '/SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics'
Apr 23 21:08:23 sogod [27450]: |SOGo| request took 0.000468 seconds to execute
Apr 23 21:08:23 sogod [27450]: ::ffff:X.X.145.X, ::ffff:X.X.145.X "GET /SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics HTTP/1.1" 404 88/0 0.001 - - 0

Testing locally against sogo port directly gives same results:

Apr 23 21:13:45 sogod [27451]: |SOGo| starting method 'GET' on uri '/SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics'
Apr 23 21:13:45 sogod [27451]: |SOGo| request took 0.000476 seconds to execute
Apr 23 21:13:45 sogod [27451]: localhost "GET /SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics HTTP/1.1" 404 88/0 0.001 - - 0
Apr 23 21:13:46 sogod [27451]: |SOGo| starting method 'GET' on uri '/SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics'
Apr 23 21:13:46 sogod [27451]: |SOGo| request took 0.000341 seconds to execute
Apr 23 21:13:46 sogod [27451]: localhost "GET /SOGo/dav/public/contact/Calendar/602B-5CBDED80-1-73939F80.ics HTTP/1.1" 404 88/0 0.001 - - 0

TagsNo tags attached.

Activities

tetsuo

tetsuo

2019-04-23 20:20

reporter   ~0013552

Last edited: 2019-04-23 20:21

Sorry I forgot to amend the title. I thought it was related to DB connection, but I could reproduce the error with active established links to the DB, so I don't think it's related any more.

Also almost everytime when attempting to reconnect with the user sharing the calendar I get:

An error occurred during object publishing

tried to access private object (0x0x563e667b4eb0, SoClass=SOGoContactFolders)

tetsuo

tetsuo

2019-04-27 15:06

reporter   ~0013555

Last edited: 2019-04-27 20:51

I can reproduce this on a fresh install with restore, after switching to Postgres.

I got another instance running elsewhere without this issue.

EDIT:

Ok, I eventually figured it out. Problem was coming from the use of 'bindAsCurrentUser = YES;' in my configuration. This will partially break access to SOGo when trying to access a public calendar of another user after few minutes.

Issue History

Date Modified Username Field Change
2019-04-23 20:18 tetsuo New Issue
2019-04-23 20:20 tetsuo Note Added: 0013552
2019-04-23 20:21 tetsuo Note Edited: 0013552
2019-04-27 15:06 tetsuo Note Added: 0013555
2019-04-27 20:51 tetsuo Note Edited: 0013555