View Issue Details

IDProjectCategoryView StatusLast Update
0004470SOGoActiveSyncpublic2018-05-29 14:47
ReporterHy3n4 Assigned To 
PrioritynormalSeverityminorReproducibilityhave not tried
Status newResolutionopen 
Platform[Server] LinuxOSUbuntuOS Version16.04 LTS
Product Version2.3.23 
Summary0004470: ActiveSync Global Address book search cannot find any contact and ends with HTTP error 501
Description

We had to move PG database to a different server. Immediately after we switched database server in sogo.conf ActiveSync clients stopped finding contacts.
In sogo.log is this errors:
sogod[43943] EXCEPTION: <NSException: 0x55aad24104a0> NAME:NSInvalidArgumentException REASON:GSInlineArray(instance) does not recognize activeSyncRepresentationInContext: INFO:(null)
sogod [43943]: 10.4.107.173 "POST /SOGo/Microsoft-Server-ActiveSync?User=epos2test@epos.cd.cz&DeviceId=QC355KOF8T3RT53G15BN5VM6VG&DeviceType=iPhone&Cmd=Search HTTP/1.1" 501 0/40 0.153 - - 2M

Tried to debug LDAP and it seems returning correct search result.

We are using pgsql as user auth backend and openldap as global address book.

Steps To Reproduce

move database data to different server
change sogo.conf SOGoProfileURL, OCSFolderInfoURL, OCSSessionsFolderURL
try to search in GAL

Additional Information

ldap log:
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 fd=37 ACCEPT from IP=10.4.63.77:47131 (IP=0.0.0.0:389)
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=0 BIND dn="" method=128
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=0 RESULT tag=97 err=0 text=
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=)"
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=1 SRCH attr=subschemaSubentry
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=2 SRCH base="cn=Subschema" scope=0 deref=0 filter="(objectClass=
)"
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=2 SRCH attr=objectclasses
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=3 SRCH base="ou=people,o=ceske drahy,c=cz" scope=2 deref=0 filter="(&(|(sn=chadima)(cn=chadima)(mail=chadima))(objectClass=person))"
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=3 SRCH attr=*
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=3 SEARCH RESULT tag=101 err=0 nentries=3 text=
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 op=4 UNBIND
May 26 13:39:47 cdis000phaux264 slapd[4501]: conn=54764242 fd=37 closed

TagsActiveSync, iOS, ldap

Activities

tfu

tfu

2018-05-28 13:25

reporter   ~0012890

A stack trace when the exception is raised should help to narrow down the problem:
https://sogo.nu/support/faq/how-do-i-debug-sogo.html

Hy3n4

Hy3n4

2018-05-28 15:06

reporter   ~0012891

Thank you for reply.
I did a trace, thank you tfu for pointing me to that web page, and the result is:

May 28 16:31:45 sogod [1506]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?User=epos2test@epos.cd.cz&DeviceId=QC355KOF8T3RT53G15BN5VM6VG&DeviceType=iPhone&Cmd=Search'
2018-05-28 16:31:45.996 sogod[1506] PG0x0x555555cd7bb0 SQL: SELECT count() FROM sogo_cache_folder_epos2test_A_epos_D_cd_D_cz
2018-05-28 16:31:46.049 sogod[1506] PG0x0x555555e63350 SQL: SELECT
FROM sogo_view_default WHERE (LOWER(c_cn) LIKE '%chadima%' OR LOWER(mail) LIKE '%chadima%')

Breakpoint 1, -[NSException raise] (self=0x555555f62ac0, _cmd=0x7ffff5855b60 <_OBJC_SELECTOR_TABLE+384>) at NSException.m:960
960 NSException.m: No such file or directory.

That last line is really interesting a it obviously causing an error, but I am not sure what file or directory is sogod looking for?

this is the backtrace result:
https://pastebin.com/raw/VBsjqe4P

but after reading all that text I still can't tell what is that magic file sogod is missing.

I am new to debuging with gdp so I'm sorry if I'm missing something.

Thank you for Your time

tfu

tfu

2018-05-28 18:45

reporter   ~0012892

What is the result of the query on sogo_view_default. According to the exception the problem happens when processing "telephonenumber".

Hy3n4

Hy3n4

2018-05-28 21:11

reporter   ~0012893

Just out of curiosity, how did you found out that this exception happens when processing telephone number.

I tested search for LDAP entry without telephonenumber and it came out without an error. So I suppouse that wrong is in LDAP search result where by mistake result containing multiple phone numbers (2) and the second one is only international prefix (+420) and nothing else.

It seem that is the problem. I can say that this error was very hard to find. Thank you tfu for a great help.

tfu

tfu

2018-05-29 05:21

reporter   ~0012894

From backtrace:
0000006 0x00007fffe7f81d15 in -[SOGoActiveSyncDispatcher processSearchGAL:inResponse:] (self=0x555555e90ae0,
_cmd=0x7fffe81bbe50 <_OBJC_SELECTOR_TABLE+3120>, theDocumentElement=0x555555ecf860, theResponse=0x555555e63a50)
at SOGoActiveSyncDispatcher.m:2906 <<< at this line the attribute telephonenumber is processed

Hy3n4

Hy3n4

2018-05-29 14:47

reporter   ~0012896

Solved. It was really a telephonenumber attribute.

A special thanks to @tfu who taught me a bit more about debugging.

Issue History

Date Modified Username Field Change
2018-05-26 11:46 Hy3n4 New Issue
2018-05-26 11:51 Hy3n4 Tag Attached: ActiveSync
2018-05-26 11:51 Hy3n4 Tag Attached: iOS
2018-05-26 11:51 Hy3n4 Tag Attached: ldap
2018-05-28 13:25 tfu Note Added: 0012890
2018-05-28 15:06 Hy3n4 Note Added: 0012891
2018-05-28 18:45 tfu Note Added: 0012892
2018-05-28 21:11 Hy3n4 Note Added: 0012893
2018-05-29 05:21 tfu Note Added: 0012894
2018-05-29 14:47 Hy3n4 Note Added: 0012896