View Issue Details

IDProjectCategoryView StatusLast Update
0002804SOGoActiveSyncpublic2014-10-16 17:29
Reporterbuzzzo Assigned Toludovic  
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionsuspended 
PlatformLinuxOSCentos 6.xOS Version64
Product Version2.2.4 
Summary0002804: After initial sync can't sync mails anymore
Description

version 2.2.5 nightly.

After initial sync due to account creation I can't sync anymore

Steps To Reproduce

Simply start a sync

TagsNo tags attached.

Activities

ludovic

ludovic

2014-06-06 14:17

administrator   ~0007153

Provide more info than this otherwise the ticket will be closed.

buzzzo

buzzzo

2014-06-06 14:48

reporter   ~0007154

Which kind of evidences do you need ?

ludovic

ludovic

2014-06-06 14:50

administrator   ~0007155

What about logs? sogod.log.

A pcap on port 20000 when that happens would be good to.

buzzzo

buzzzo

2014-06-06 15:16

reporter   ~0007156

Ok I will do it ASAP

buzzzo

buzzzo

2014-06-11 07:43

reporter   ~0007174

2014-06-11 09:40:29.827 sogod[30124] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.3-EAS-2.0'
2.199.230.218 - - [11/Jun/2014:09:40:33 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=buzzz%40gci.it&DeviceId=androidc1504138838&DeviceType=Android HTTP/1.1" 200 25/13 4.041 - - 4M
2014-06-11 09:40:34.102 sogod[30124] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.3-EAS-2.0'
Jun 11 09:40:38 sogod [30124]: <0x0x7f8206ac0da8[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
2014-06-11 09:40:47.338 sogod[30124] parseTimeZone: cannot parse time notation 'GMT'
2014-06-11 09:40:48.661 sogod[30124] parseTimeZone: cannot parse time notation 'GMT'
Jun 11 09:40:58 sogod [30124]: <0x0x7f820629fb48[NGMimeRFC822DateHeaderFieldParser]> WARNING: failed to parse RFC822 date field: '09:30:01 11-Jun-2014'
2014-06-11 09:40:59.163 sogod[30124] Change detected, we push the content.
2.199.230.218 - - [11/Jun/2014:09:41:05 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=buzzz%40gci.it&DeviceId=androidc1504138838&DeviceType=Android HTTP/1.1" 200 1078591/97 31.500 - - 56M
88.149.215.180 - - [11/Jun/2014:09:41:08 GMT] "POST /SOGo/so/lser@gci.it/Mail/0/folderINBOX/uids HTTP/1.1" 200 516/46 0.280 - - 0
88.149.215.180 - - [11/Jun/2014:09:41:08 GMT] "POST /SOGo/so/lser@gci.it/Mail/0/folderINBOX/unseenCount HTTP/1.1" 200 13/0 0.301 - - 0
2014-06-11 09:41:12.590 sogod[29694] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.3-EAS-2.0'
Jun 11 09:41:16 sogod [29694]: <0x0x7f82063ce3b8[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
62.101.65.66 - - [11/Jun/2014:09:41:17 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1353 0.547 - - 0
2014-06-11 09:41:25.961 sogod[29694] Change detected, we push the content.
2.199.230.218 - - [11/Jun/2014:09:41:26 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=buzzz%40gci.it&DeviceId=androidc1504138838&DeviceType=Android HTTP/1.1" 200 111724/97 13.437 - - 0
62.101.65.66 - - [11/Jun/2014:09:41:29 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderINBOX/unseenCount HTTP/1.1" 200 13/0 0.326 - - 0
62.101.65.66 - - [11/Jun/2014:09:41:30 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderINBOX/uids HTTP/1.1" 200 51373/46 0.524 150354 65% 0
62.101.65.66 - - [11/Jun/2014:09:41:30 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderINBOX/headers HTTP/1.1" 200 456/26 0.353 1211 62% 8K
2014-06-11 09:41:31.429 sogod[29694] -[WEClientCapabilities initWithRequest:]: Unknown WebClient: user-agent='Android/4.4.3-EAS-2.0'
2014-06-11 09:41:31.436 sogod[29694] Sleeping 10 seconds while detecting changes...
2014-06-11 09:41:41.440 sogod[29694] Sleeping 10 seconds while detecting changes...
2014-06-11 09:41:51.443 sogod[29694] Sleeping 10 seconds while detecting changes...
2.199.230.218 - - [11/Jun/2014:09:42:01 GMT] "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=buzzz%40gci.it&DeviceId=androidc1504138838&DeviceType=Android HTTP/1.1" 200 60/77 30.017 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:05 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.535 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:05 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.543 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:06 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.518 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:08 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.525 - - 0
88.149.215.180 - - [11/Jun/2014:09:42:08 GMT] "POST /SOGo/so/lser@gci.it/Mail/0/folderINBOX/uids HTTP/1.1" 200 516/46 0.267 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:09 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.525 - - 0
88.149.215.180 - - [11/Jun/2014:09:42:09 GMT] "POST /SOGo/so/lser@gci.it/Mail/0/folderINBOX/unseenCount HTTP/1.1" 200 13/0 0.301 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:09 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.529 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:11 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.519 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:13 GMT] "POST /SOGo/so/avig@gci.it/Mail/0/folderDrafts/newDraft1402471309-1/save HTTP/1.1" 200 2/1366 0.518 - - 0
62.101.65.66 - - [11/Jun/2014:09:42:17 GMT] "GET /SOGo/so/avig@gci.it/Mail/0/folderINBOX/expunge HTTP/1.1" 200 59/0 0.372 - - 4K

ludovic

ludovic

2014-06-11 12:29

administrator   ~0007179

We need a pcap.

buzzzo

buzzzo

2014-06-11 12:32

reporter   ~0007181

Could you kindly tell me the syntax of the pcap filter/command to sniff the traffic ?

ludovic

ludovic

2014-06-11 17:10

administrator   ~0007186

tcpdump -i lo -s 0 -w /tmp/dump.data tcp and port 20000

buzzzo

buzzzo

2014-06-12 17:03

reporter  

dump.data (1,449,794 bytes)
buzzzo

buzzzo

2014-06-12 17:05

reporter   ~0007203

Uploaded pcap

Tested with both android 4.4.3 and iphone ios 7.x
I was able to sync on android just one time.

buzzzo

buzzzo

2014-06-26 08:35

reporter   ~0007243

Any news about this issue ?

apkpotty

apkpotty

2014-06-29 14:26

reporter   ~0007251

Hi,

Having enabled IMAP debug in sogo.conf I get the following in sogo.log. I feel the issue might be that the "null" folder name being presented to IMAP. Not sure if the missing setannotation support in my dovecot could be causing the issue ...

C[0x79387dfc]: 80 setannotation "INBOX" "/comment" ("value.priv" "xxxxx_2a57_19605699_1d")
S[0x793a11f4]: 80 BAD Error in IMAP command SETANNOTATION: Unknown command.
C[0x79387dfc]: 81 status "INBOX" (x-guid)
S[0x793a11f4]: STATUS INBOX (X-GUID 97eafb032406b053430800002821f8ef)
S[0x793a11f4]: 81 OK Status completed.
C[0x79387dfc]: 82 unselect
S[0x793a11f4]: 82 BAD No mailbox selected.
C[0x79387dfc]: 83 select "(null)"
S[0x793a11f4]: 83 NO Mailbox doesn't exist: (null)
C[0x79387dfc]: 84 UID SORT (DATE) UTF-8 ((MODSEQ 1) (NOT DELETED)) (SINCE "30-May-2014")
S[0x793a11f4]: 84 BAD No mailbox selected.
C[0x79387dfc]: 85 UID FETCH 1:
(UID) (CHANGEDSINCE 1 VANISHED)
S[0x793a11f4]: 85 BAD No mailbox selected.

[ERROR] <0x0x78ad810c[NGImap4Connection]> could not sort contents of URL: imaps://user@localhost:1143/%28null%29/?tls=YES

--
Anantha Potty

ludovic

ludovic

2014-06-29 14:36

administrator   ~0007252

What IMAP server are you using?

As you can see SETANNOTATION isn't supported nor X-GUI. One of the two is required for proper ActiveSync support.

apkpotty

apkpotty

2014-06-29 14:38

reporter   ~0007253

dovecot-2.2.12 built from sources ...

apkpotty

apkpotty

2014-06-29 15:01

reporter   ~0007254

X-GUID seems to be supported? Anyway how to get setannotation support into dovecot?

apkpotty

apkpotty

2014-06-29 15:08

reporter   ~0007255

sorry for the dovecot question. Am installing dovecot-metadata-plugin will report after testing ...

ludovic

ludovic

2014-06-29 15:54

administrator   ~0007256

Well indeed it seems to be supported. Have you compiled SOGo yourself?

apkpotty

apkpotty

2014-06-29 15:57

reporter   ~0007257

yes. SOGo/SOPE 2.2.5 downloaded from sogo.nu

ludovic

ludovic

2014-06-29 16:25

administrator   ~0007258

You might to run sogod inside GDB and set a breakpoint on "seletct" (in NGImap4Client) and produce a stacktrace when you get a "nil" value.

See http://www.sogo.nu/fr/nc/support/faq/article/how-do-i-debug-sogo.html

apkpotty

apkpotty

2014-07-03 11:35

reporter   ~0007278

ran using gdb. hit "virtual memory exhausted: ...".

set ulimit to allow more memory resources and the issue seems to be solved. running with or without GDB does not give the "null" folder as before ...

thanks for point me in the right direction ...

regards,
Anantha Potty

Issue History

Date Modified Username Field Change
2014-06-06 12:45 buzzzo New Issue
2014-06-06 14:17 ludovic Note Added: 0007153
2014-06-06 14:48 buzzzo Note Added: 0007154
2014-06-06 14:50 ludovic Note Added: 0007155
2014-06-06 15:16 buzzzo Note Added: 0007156
2014-06-11 07:43 buzzzo Note Added: 0007174
2014-06-11 12:29 ludovic Note Added: 0007179
2014-06-11 12:32 buzzzo Note Added: 0007181
2014-06-11 17:10 ludovic Note Added: 0007186
2014-06-12 17:03 buzzzo File Added: dump.data
2014-06-12 17:05 buzzzo Note Added: 0007203
2014-06-26 08:35 buzzzo Note Added: 0007243
2014-06-29 14:26 apkpotty Note Added: 0007251
2014-06-29 14:36 ludovic Note Added: 0007252
2014-06-29 14:38 apkpotty Note Added: 0007253
2014-06-29 15:01 apkpotty Note Added: 0007254
2014-06-29 15:08 apkpotty Note Added: 0007255
2014-06-29 15:54 ludovic Note Added: 0007256
2014-06-29 15:57 apkpotty Note Added: 0007257
2014-06-29 16:25 ludovic Note Added: 0007258
2014-07-03 11:35 apkpotty Note Added: 0007278
2014-10-16 17:29 ludovic Status new => resolved
2014-10-16 17:29 ludovic Resolution open => suspended
2014-10-16 17:29 ludovic Assigned To => ludovic