SOGo | BTS

View Issue Details Jump to Notes ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0001767SOGoBackend Generalpublic2012-04-10 09:052012-04-23 11:11
Reportercnaumer 
Assigned Towsourdeau 
PrioritynormalSeveritymajorReproducibilityalways
StatusresolvedResolutionfixed 
PlatformOSOS Version
Product Version1.3.14 
Target VersionFixed in Version1.3.15 
Summary0001767: unescaped backslash in the calendar Postgres
DescriptionAfter the update to 1.3.14 from 1.3.12c I get several errors in the logs (see sogo.log). For the users there are some problems. Some users have lost their settings regarding the
calendars they have subscribed. And some acl-entrys are gone as well.

The system is a Centos 6.2 with all updates.

sope49-gdl1-postgresql-4.9-20120323_1664.el6.1.x86_64
when it wasn't working
sope49-gdl1-postgresql-4.9-20120214_1664.el6.1.x86_64
now and before where it was working and is now.
Additional InformationIf I run :
sogo-tool -v backup /home/sogo/backup_26032012 ALL

I get this error after the update to 1.3.14 from 1.3.12c

"CalendarDefaultFilter": "view_today"}
Mar 26 15:59:56 sogo-tool [12574]: [ERROR]
<0x0x2c6d528[SOGoSQLUserProfile]> failed to parse property list value
for settings profile (error: Parse failed at line 1 (char 8) -
unexpected character (wanted '=')): {"Mail": {"SortingState": ["date",
"0"], "ExpandedFolders": "[\\"\\/0\\",\\"\\/0\\/folderINBOX\\"]",
"folderForExpunge": "imaps:\\/\\/eg@192.168.0.99\\/INBOX\\/"},
"Calendar": {"View": "weekview", "SubscribedFolders":
["sogo:Calendar\\/725B-4C31DB00-235-3C8963C0"]},
"CalendarDefaultFilter": "view_today"}
Mar 26 15:59:57 sogo-tool [12574]: [ERROR]
<0x0x2649578[GSCBufferString]> json parser: Object value expected for
key: Mail
Mar 26 15:59:57 sogo-tool [12574]: [ERROR]
<0x0x2649578[GSCBufferString]> original string is: {"Mail":
{"DragHandleHorizontal": "243", "SortingState": ["date", "0"],
"ExpandedFolders": "[\\"\\/0\\",\\"\\/0\\/folderINBOX\\"]"}, "Calendar":
{"View": "weekview"}, "CalendarDefaultFilter": "view_today"}
Mar 26 15:59:57 sogo-tool [12574]: [ERROR]
<0x0x232dcf8[SOGoSQLUserProfile]> failed to parse property list value
for settings profile (error: Parse failed at line 1 (char 8) -
unexpected character (wanted '=')): {"Mail": {"DragHandleHorizontal":
"243", "SortingState": ["date", "0"], "ExpandedFolders":
"[\\"\\/0\\",\\"\\/0\\/folderINBOX\\"]"}, "Calendar": {"View":
"weekview"}, "CalendarDefaultFilter": "view_today"}
TagsNo tags attached.
Attached Fileslog file icon sogo.log [^] (2,866 bytes) 2012-04-10 09:05
txt file icon bt.txt [^] (4,569 bytes) 2012-04-16 04:48 [Show Content]
txt file icon bt2.txt [^] (3,453 bytes) 2012-04-16 05:22 [Show Content]
txt file icon tracking.txt [^] (5,376 bytes) 2012-04-17 10:37 [Show Content]
txt file icon tracking2.txt [^] (5,372 bytes) 2012-04-17 11:07 [Show Content]

- Relationships Relation Graph ] Dependency Graph ]

-  Notes
User avatar (0003716)
francis (administrator)
2012-04-11 09:51

On a copy of your database, execute the following commands from a PostgreSQL shell (psql) :

begin transaction;
update sogo_user_profile set c_settings = replace(c_settings, '\\', '\');
update sogo_user_profile set c_defaults = replace(c_defaults, '\\', '\');
commit;


Let us know if it fixes the problem.
(0003729)
cnaumer (reporter)
2012-04-13 04:05

Should I do this before the update or afterwards?
User avatar (0003730)
francis (administrator)
2012-04-13 08:45

After the update.
(0003732)
cnaumer (reporter)
2012-04-13 10:42

OK I did the update and tried to run this:

begin transaction;
update sogo_user_profile set c_settings = replace(c_settings, '\\', '\');
update sogo_user_profile set c_defaults = replace(c_defaults, '\\', '\');

After this I got a syntax error.

then I tried this:
begin transaction;
update sogo_user_profile set c_settings = replace(c_settings, '\\\\', '\\');
update sogo_user_profile set c_defaults = replace(c_defaults, '\\\\', '\\');

as someone posted in the mailing list. This gave some warnings but did the right thing because it seems to work right now.

So thank you.
(0003733)
cnaumer (reporter)
2012-04-13 10:54
edited on: 2012-04-13 10:56

said to soon...

Other errors:

Apr 13 16:50:24 sogod [12905]: <0x0x14f74b8[GCSFolderManager]> ERROR(-[GCSFolderManager performSQL:]): cannot execute
  SQL 'SELECT c_folder_id, c_path, c_location, c_quick_location, c_acl_location, c_folder_type FROM sogo_folder_info WHERE c_path1 = 'Users' AND c_path2 = 'ab' AND c_path3 = 'Calendar\' AND c_path4 = 'C46F60DA-7180-0001-6E6F-39804B0F1B3E'':
  <PostgreSQL72Exception: 0x1ffce48> NAME:PostgreSQL72FatalError REASON:fatal pgsql error (channel=<0x0x3e2c388[PostgreSQL72Channel]: connection=<0x0x3d27328[PGConnection]: connection=0x0x235e440>>): FEHLER: Syntaxfehler bei »C46F60DA«
ZEILE 1: ...2 = 'ab' AND c_path3 = 'Calendar\' AND c_path4 = 'C46F60DA-7...
                                                              ^
TIP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'.



And:

2012-04-13 16:50:26.590 sogod[12908] <0x0x1b08648[PostgreSQL72Channel]: connection=<0x0x1ceb9e8[PGConnection]: connection=0x0x1d43c40>>: message: WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante
ZEILE 1: ...c_foldername FROM sogo_folder_info WHERE c_path = '/Users/cn...
                                                              ^
TIP: Verwenden Sie die Syntax für Escape-Zeichenketten, z.B. E'\r\n'.

2012-04-13 16:50:26.591 sogod[12908] <0x0x1c9fd48[PostgreSQL72Channel]: connection=<0x0x1b1f3c8[PGConnection]: connection=0x0x1d3a780>>: message: WARNUNG: nicht standardkonforme Verwendung von Escape in Zeichenkettenkonstante
ZEILE 1: ...c_foldername FROM sogo_folder_info WHERE c_path = '/Users/ab...

(0003734)
wsourdeau (viewer)
2012-04-13 10:56

The SQL fix will only fix the settings and defaults.

For the other error that you are having, we don't have a solution yet, especially since we cannot reproduce it.
Can you show us the output of "SELECT * FROM sogo_folder_info WHERE c_path2= 'ts'"?
(0003735)
cnaumer (reporter)
2012-04-13 11:04

SELECT * FROM sogo_folder_info WHERE c_path2= 'df'
the user with this error is df:


32 /Users/df/Contacts/personal Users df Contacts personal Persönliches Adressbuch postgresql://sogo:sogo@localhost:5432/sogo/sogodf001763b3ee8 postgresql://sogo:sogo@localhost:5432/sogo/sogodf001763b3ee8_quick postgresql://sogo:sogo@localhost:5432/sogo/sogodf001763b3ee8_acl Contact

33 /Users/df/Calendar/personal Users df Calendar personal Persönlicher Kalender postgresql://sogo:sogo@localhost:5432/sogo/sogodf0025f541d63 postgresql://sogo:sogo@localhost:5432/sogo/sogodf0025f541d63_quick postgresql://sogo:sogo@localhost:5432/sogo/sogodf0025f541d63_acl Appointment
(0003736)
wsourdeau (viewer)
2012-04-13 11:12

That's strange.... I would expect a value of "Calendar'" for c_path2 instead of "Calendar". But this is good news.

Can you install sogo-dbg (debian) or (sogo-debug), launch gdb on an instance, setup a breakpoint with "b [GCSFolderManager folderAtPath:]", perform a backtrace, and issue a "po _path" where you reached it?

Thanks
(0003737)
cnaumer (reporter)
2012-04-13 13:40

Will try that. Which debug-info rpm are needed for this? just sogo-debuginfo? I'll have to wait till monday to reproduce though.
(0003742)
cnaumer (reporter)
2012-04-16 04:51
edited on: 2012-04-16 05:24

Added the backtrace. The first 4 lines were the first I caught. The rest was the second backtrace. Hope it helps. This user doesn't experience any errors. And the error in the logs only shows up with some users.

Here is what I did:
gdb -p [pid of instance]

b GCSFolderManager.m:250
continue

bt

For bt2.txt I did this:
b [GCSFolderManager folderAtPath:]

po _path

output was this:

/Users/kr/Calendar/personal

bt

output is in bt2.txt

(0003752)
gienger (reporter)
2012-04-17 09:01
edited on: 2012-04-17 09:04

We have the same problem with some users, and in fact in sogo_user_info there are \\ when there should be a \:

 popXXXXXX | {"SOGoLanguage": "German"} | {"Mail": {"DragHandleHorizontal": "248", "SortingState": ["date", "0"], "ExpandedFolders": "[\\"\\/0\\",\\"\\/0\\/folderXXXXX\\",\\"\\/0\\/folderXXXXX\\/folderXXXXXXXX\\",\\"\\/0\\/folderXX\\",\\"\\/0\\/folderXXXX\\"]", "DragHandleVertical": "483", "ColumnsState": {"subjectHeader": "31", "priorityHeader": "5", "fromHeader": "19", "dateHeader": "26"}}, "CalendarDefaultFilter": "view_today", "Calendar": {"FolderColors": {"popXXXXXX:Calendar\\/XXXX-XXXXXXXX-XX-XXXXXXXX": "#FF9933"}, "InactiveFolders": ["personal"], "View": "monthview", "FreeBusyExclusions": {"popXXXXXX:Calendar\\/XXXX-XXXXXXXX-XX-XXXXXXXX": 0}}}
(1 row)



However only a small set of accounts do have these double slashes in this folder.

my first guess would be to use the replace command on a snapshot to test it...


Addendum:

And it becomes worse, example:

"XXXXX:Calendar\\\/personal", "XXXXXX:Calendar\\\/personal", "XXXXXXX:Calendar\\\/personal", "XXXXXX:Calendar\\\/personal", "XXXXXXX:
Calendar\\\/personal"

So the number of backslashes gets or got bigger due to some sort....

(0003753)
wsourdeau (viewer)
2012-04-17 09:27

cnaumer: that's good because the bug is not there. Can you launch gdb again, and set a breakpoint on GCSFolderManager.m:250 instead? When it reaches that point, perform a "bt" and a "po _sql" from there. Afterwards do a "f 1" and a "po _path", and then leave gdb.

Moreoever, can you list the version numbers for sope-gdl1 as well as sope-gdl1-postgresql?

Thank you very much!
(0003754)
wsourdeau (viewer)
2012-04-17 09:33

gienger: guttentag!

I would even suggest to use the sogo nightlies, are they include a fix for that issue... You are using 1.3.14 right now, right?
(0003755)
cnaumer (reporter)
2012-04-17 10:40
edited on: 2012-04-17 11:08

in tracking.txt and in tracking2.txt is the output of:
b GCSFolderManager.m:250

bt

po _sql

f 1

po _path

this was two separate pids.
hope it helps.

(0003756)
wsourdeau (viewer)
2012-04-17 11:08

cnaumer: yep, it does. This enables me to narrow it down to the subscriptions, which are stored in the sogo_user_profile table. So again, it's likely a matter of fixing the user entries.
Now.... it depends on the versions of SOGo that you are using.
With 1.3.12, the info in sogo_user_profile is written wrong, but a work around for a problem with the Oracle backend had a side-effect of interpreting the wrong data properly.
With 1.3.13 and 1.3.14, the data written to sogo_user_profile is right and the work-around has been removed. Thus, the problem is the interpretation of data written by 1.3.12 and older with more recent versions.
So, let's say for example that you are using 1.3.12 in prod and 1.3.14 in testing, but using the same database, you will always have this issue because those data is rewritten nearly during each web operation.

So the "replace"trick above must work, in its second form indeed, but only with 1.3.14.

Does the above fit your situation?
(0003759)
cnaumer (reporter)
2012-04-17 11:44
edited on: 2012-04-17 12:02

Forgot to mention the versions we are using:

sogo-1.3.14-1.centos6.x86_64
sope49-gdl1-4.9-20120323_1664.el6.1.x86_64
sope49-gdl1-postgresql-4.9-20120323_1664.el6.1.x86_64

We used 1.3.12c in production and I upgraded to 1.3.14 and since then we get those error messages.

I tried the SQL commands again. I had to run them several times so that it worked. I checked the DB entries for the users that I know where the error happen and they had "\\/" in some entries and now they don't have them anymore.

With one of the users I can now say it works! After correction every entry of the subscribed address books were synced as if they were not there at all.

(0003760)
casties (reporter)
2012-04-17 11:52

We are also using 1.3.12 now and we had problems after the upgrade to 1.3.14 (and went back to 1.3.12).

So this means that the data in the profile is incorrect and we have to do

update sogo_user_profile set c_settings = replace(c_settings, '\\', '\');

in c_settings and c_profiles after the update to 1.3.14 and everything will be fine?
(0003761)
mjr (reporter)
2012-04-17 12:17

Related question: should there ever be a double backslash in c_settings or c_profiles?
(0003764)
wsourdeau (viewer)
2012-04-18 09:28

cnaumer: I don't understand "After correction every entry of the subscribed address books were synced as if they were not there at all." because you mention a "correction" but then that the addressbooks are missing.... You mean that the contacts have disappeared?
(0003765)
wsourdeau (viewer)
2012-04-18 09:34

mjr: it depoends on the versoin of PostgreSQL you are using. There are versions which acccept the "\" escaping and others do not. The only reason for escaping a character in pg is when the character is a "'", since it has a special meaning, and the proper way to do it is to double it in queries. For example, for a field of value "l'apostrophe" (a good french restaurant). you would need towrite a WHERE clause this way:
"WHERE c_restaurant = 'l''apostrophe'". For certain version of postgres, it was possible to do it this way instead: "WHERE c_restaurant = 'l\'apostrophe'", while postgres actually requires the use of an "E" to declare such strings, where our example becomes "WHERE c_restaurant = E'l\'apostrophe'".

But the SQL standard version is the first one and it's the one we have been using since 2 releases but it caused migration problems that we did not foresee.
(0003776)
gienger (reporter)
2012-04-19 09:09

Next thing:

Our setup runs on CentOS 5.8 with database on a remote PostgreSQL host, using Version 8.4.11 - all entries are correct (c_defaults and c_settings).

When dumping this database (on the 8.4.11 host) and replaying that dump on a CentOS machine with PostgreSQL 8.4.9 all is ok, a "SELECT" in psql just returns the correct fields.

But at the moment SOGo 1.3.14 running un CentOS 5.8 connects to the PGsql database on CentOS 5.8 it invalidates some settings (all these where a backslash is in) and for that reason shared calendars and address books vanish and all calendar colors are set back to gray).

The same SOGo 1.3.14 running on CentOS 5.8 connecting to the PGsql 8.4.11 remote database behaves just normally - with the same data.
(0003777)
cnaumer (reporter)
2012-04-19 09:24

wsourdeau: I cannot say if the contacts were not there as I didn't check that. I just saw (in the logs) after I removed the the backslahes that one address book was synced completely (>2500 contacts). This address book is not used heavily so didn't get reports that is wasn't working.
More clear now?
(0003778)
wsourdeau (viewer)
2012-04-19 09:26

gienger: can you ensure that the parameter "standard_conforming_strings" is set to "on" in your postgres configuration?
(0003779)
gienger (reporter)
2012-04-19 09:43

@wsourdeau: On the 8.4.9 host:

#standard_conforming_strings = off

(commented out, so standard "off").

On the 8.4.11 host: the same:

#standard_conforming_strings = off



Using online retrieval:

both are set to off.
(0003780)
wsourdeau (viewer)
2012-04-19 09:44

gienger: can you try by setting it to 'on'?
(0003785)
wsourdeau (viewer)
2012-04-19 11:19

gienger: I have rebuild the nightlies with a potential fix. Can you install sope49-gdl1-postgresql-4.9-20120419_1664 from the nigthly repository? (https://inverse.ca/downloads/SOGo/RHEL5/nightly/x86_64/RPMS/sope49-gdl1-postgresql-4.9-20120419_1664.el5.1.x86_64.rpm [^])

Note that the fix is safe and has no side-effect so it's a very low-risk update.
(0003795)
gienger (reporter)
2012-04-20 04:48

wsourdeau; Yup it works with that patch. Oui ça marche avec cette retouche. ;-)
(0003806)
wsourdeau (viewer)
2012-04-23 11:11

Super, we finally found the solution. Thanks to everyone.

- Issue History
Date Modified Username Field Change
2012-04-10 09:05 cnaumer New Issue
2012-04-10 09:05 cnaumer File Added: sogo.log
2012-04-11 09:51 francis Note Added: 0003716
2012-04-13 04:05 cnaumer Note Added: 0003729
2012-04-13 08:45 francis Note Added: 0003730
2012-04-13 10:42 cnaumer Note Added: 0003732
2012-04-13 10:54 cnaumer Note Added: 0003733
2012-04-13 10:55 cnaumer Note Edited: 0003733
2012-04-13 10:56 cnaumer Note Edited: 0003733
2012-04-13 10:56 wsourdeau Note Added: 0003734
2012-04-13 11:04 cnaumer Note Added: 0003735
2012-04-13 11:12 wsourdeau Note Added: 0003736
2012-04-13 13:40 cnaumer Note Added: 0003737
2012-04-16 04:48 cnaumer File Added: bt.txt
2012-04-16 04:51 cnaumer Note Added: 0003742
2012-04-16 05:20 cnaumer Note Edited: 0003742
2012-04-16 05:22 cnaumer File Added: bt2.txt
2012-04-16 05:23 cnaumer Note Edited: 0003742
2012-04-16 05:24 cnaumer Note Edited: 0003742
2012-04-17 09:01 gienger Note Added: 0003752
2012-04-17 09:04 gienger Note Edited: 0003752
2012-04-17 09:27 wsourdeau Note Added: 0003753
2012-04-17 09:33 wsourdeau Note Added: 0003754
2012-04-17 10:37 cnaumer File Added: tracking.txt
2012-04-17 10:40 cnaumer Note Added: 0003755
2012-04-17 11:07 cnaumer File Added: tracking2.txt
2012-04-17 11:08 cnaumer Note Edited: 0003755
2012-04-17 11:08 wsourdeau Note Added: 0003756
2012-04-17 11:44 cnaumer Note Added: 0003759
2012-04-17 11:52 casties Note Added: 0003760
2012-04-17 11:55 cnaumer Note Edited: 0003759
2012-04-17 12:02 cnaumer Note Edited: 0003759
2012-04-17 12:17 mjr Note Added: 0003761
2012-04-18 09:28 wsourdeau Note Added: 0003764
2012-04-18 09:34 wsourdeau Note Added: 0003765
2012-04-19 09:09 gienger Note Added: 0003776
2012-04-19 09:24 cnaumer Note Added: 0003777
2012-04-19 09:26 wsourdeau Note Added: 0003778
2012-04-19 09:43 gienger Note Added: 0003779
2012-04-19 09:44 wsourdeau Note Added: 0003780
2012-04-19 11:19 wsourdeau Note Added: 0003785
2012-04-20 04:48 gienger Note Added: 0003795
2012-04-23 11:11 wsourdeau Note Added: 0003806
2012-04-23 11:11 wsourdeau Status new => resolved
2012-04-23 11:11 wsourdeau Fixed in Version => 1.3.15
2012-04-23 11:11 wsourdeau Resolution open => fixed
2012-04-23 11:11 wsourdeau Assigned To => wsourdeau


Copyright © 2000 - 2018 MantisBT Team
Powered by Mantis Bugtracker