View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0003603 | SOGo | ActiveSync | public | 2016-03-27 11:13 | 2016-03-28 21:40 |
Reporter | m_emelchenkov | Assigned To | ludovic | ||
Priority | normal | Severity | major | Reproducibility | always |
Status | resolved | Resolution | fixed | ||
Platform | iPhone | OS | iOS | OS Version | 8.4.1 |
Product Version | nightly v2 | ||||
Fixed in Version | 3.1.0 | ||||
Summary | 0003603: SOGoActiveSyncDispatcher multiplied | ||||
Description | Every time I refreshing Inbox in Mail.app on iPhone I see in logs | ||||
Tags | No tags attached. | ||||
After sometime (timeout): "client disconnected during delivery of response for <WORequest[0x0x7f73209d30d8]: method=POST......the socket was shutdown". "frozen" connections each time I refreshing mail Inbox. /nginx/ / SOGo / |
|
Also (maybe not related and maybe even not a bug) after receiving mail there are two "Change detected during Sync, we push the content." records in logs and two POSTs. Should it fire two times on single incoming message or not? |
|
By the way, after receiving mail it stops SOGoActiveSyncDispatcher, so no new mail delivered to iPhone. After some time it starts dispatch it again. Too many points, let's diagnose step-by-step starting from my first problem described in "Description". If other problems will exists after fixing it then I will open new issues there. Thanks. |
|
3603.diff (2,784 bytes)
diff --git a/ActiveSync/SOGoActiveSyncDispatcher.m b/ActiveSync/SOGoActiveSyncDispatcher.m index 17599ae..091efc6 100644 --- a/ActiveSync/SOGoActiveSyncDispatcher.m +++ b/ActiveSync/SOGoActiveSyncDispatcher.m @@ -2164,7 +2164,7 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. - (void) processPing: (id <DOMElement>) theDocumentElement inResponse: (WOResponse *) theResponse { - NSString *collectionId, *realCollectionId, *syncKey; + NSString *collectionId, *realCollectionId, *syncKey, *key, *processIdentifier; NSMutableArray *foldersWithChanges, *allFoldersID; SOGoMicrosoftActiveSyncFolderType folderType; NSMutableDictionary *folderMetadata; @@ -2177,8 +2177,13 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. NSData *d; NSAutoreleasePool *pool; - int i, j, heartbeatInterval, defaultInterval, internalInterval, status; + int i, j, heartbeatInterval, defaultInterval, internalInterval, status, total_sleep; + // Let other ping requests know that a new request has arrived. + processIdentifier = [NSString stringWithFormat: @"%d", [[NSProcessInfo processInfo] processIdentifier]]; + key = [NSString stringWithFormat: @"%@+%@", [[context activeUser] login], [context objectForKey: @"DeviceType"]]; + [[SOGoCache sharedCache] setValue: processIdentifier forKey: key]; + defaults = [SOGoSystemDefaults sharedSystemDefaults]; defaultInterval = [defaults maximumPingInterval]; internalInterval = [defaults internalSyncInterval]; @@ -2272,8 +2277,29 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. } else { - [self logWithFormat: @"Sleeping %d seconds while detecting changes in Ping...", internalInterval]; - sleep(internalInterval); + total_sleep = 0; + + while (total_sleep < internalInterval) + { + // We check if we must break the current ping request since an other ping request + // has just arrived. + if ([[SOGoCache sharedCache] valueForKey: key] && ![[[SOGoCache sharedCache] valueForKey: key] isEqualToString: processIdentifier]) + { + if (debugOn) + [self logWithFormat: @"EAS - Ping request canceled (%@)", [[SOGoCache sharedCache] valueForKey: key]]; + + // Make sure we end the heardbeat-loop. + heartbeatInterval = internalInterval = 1; + + break; + } + else + { + [self logWithFormat: @"Sleeping %d seconds while detecting changes in Ping...", internalInterval-total_sleep]; + sleep(5); + total_sleep += 5; + } + } } } |
|
Attached patch should avoid duplicate ping requests. |
|
Why not do the same thing we do for Sync requests? Using only the SOGoCache isn't cluster safe. Using SOGoCacheGCSObject is. |
|
3603-1.diff (3,074 bytes)
diff --git a/ActiveSync/SOGoActiveSyncDispatcher.m b/ActiveSync/SOGoActiveSyncDispatcher.m index 17599ae..3c8a66e 100644 --- a/ActiveSync/SOGoActiveSyncDispatcher.m +++ b/ActiveSync/SOGoActiveSyncDispatcher.m @@ -2164,11 +2164,12 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. - (void) processPing: (id <DOMElement>) theDocumentElement inResponse: (WOResponse *) theResponse { - NSString *collectionId, *realCollectionId, *syncKey; + NSString *collectionId, *realCollectionId, *syncKey, *processIdentifier, *pingRequestInCache; NSMutableArray *foldersWithChanges, *allFoldersID; SOGoMicrosoftActiveSyncFolderType folderType; NSMutableDictionary *folderMetadata; SOGoSystemDefaults *defaults; + SOGoCacheGCSObject *o; id <DOMElement> aCollection; NSArray *allCollections; @@ -2177,8 +2178,17 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. NSData *d; NSAutoreleasePool *pool; - int i, j, heartbeatInterval, defaultInterval, internalInterval, status; + int i, j, heartbeatInterval, defaultInterval, internalInterval, status, total_sleep; + // Let other ping requests know that a new request has arrived. + processIdentifier = [NSString stringWithFormat: @"%d", [[NSProcessInfo processInfo] processIdentifier]]; + o = [SOGoCacheGCSObject objectWithName: [context objectForKey: @"DeviceId"] inContainer: nil useCache: NO]; + [o setObjectType: ActiveSyncGlobalCacheObject]; + [o setTableUrl: [self folderTableURL]]; + [o reloadIfNeeded]; + [[o properties] setObject: processIdentifier forKey: @"PingRequest"]; + [o save]; + defaults = [SOGoSystemDefaults sharedSystemDefaults]; defaultInterval = [defaults maximumPingInterval]; internalInterval = [defaults internalSyncInterval]; @@ -2272,8 +2282,30 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. } else { - [self logWithFormat: @"Sleeping %d seconds while detecting changes in Ping...", internalInterval]; - sleep(internalInterval); + total_sleep = 0; + + while (total_sleep < internalInterval) + { + // We check if we must break the current ping request since an other ping request + // has just arrived. + pingRequestInCache = [[self globalMetadataForDevice] objectForKey: @"PingRequest"]; + if (pingRequestInCache && ![pingRequestInCache isEqualToString: processIdentifier]) + { + if (debugOn) + [self logWithFormat: @"EAS - Ping request canceled (%@)", pingRequestInCache]; + + // Make sure we end the heardbeat-loop. + internalInterval = heartbeatInterval; + + break; + } + else + { + [self logWithFormat: @"Sleeping %d seconds while detecting changes in Ping...", internalInterval-total_sleep]; + sleep(5); + total_sleep += 5; + } + } } } |
|
Attached a new version of the patch. |
|
How about cleaning up this data in case we got stale data with sogo-tool? You could also replace in your patch: processIdentifier = [NSString stringWithFormat: @"%d", [[NSProcessInfo processInfo] processIdentifier]]; with: o = [self globalMetadataForDevice]; |
|
I'd love to test! Can I wait for nightly build or need to compile it myself? |
|
I don't think that there is an additional cleanup needed. "globalMetadata" will be cleaned with resetdevice. With the change you suggested o would be a dictionary, how do you suggest to do the save ([o save])? |
|
[o save] :-) |
|
don't think so. |
|
Ah, true - forget it then. |
|
Also fixed for 2.3.10. |
|
sogo: master 5a342f2f 2016-03-28 17:37 Details Diff |
(fix) prevent double Sync ops from same device (fixes 0003603) |
Affected Issues 0003603 |
|
mod - ActiveSync/SOGoActiveSyncDispatcher.m | Diff File | ||
sogo: v2 821b9d1f 2016-03-28 17:37 Details Diff |
(fix) prevent double Sync ops from same device (fixes 0003603) |
Affected Issues 0003603 |
|
mod - ActiveSync/SOGoActiveSyncDispatcher.m | Diff File |
Date Modified | Username | Field | Change |
---|---|---|---|
2016-03-27 11:13 | m_emelchenkov | New Issue | |
2016-03-27 11:18 | m_emelchenkov | Note Added: 0009850 | |
2016-03-27 11:39 | m_emelchenkov | Note Added: 0009851 | |
2016-03-27 11:43 | m_emelchenkov | Note Added: 0009852 | |
2016-03-28 16:08 | tfu | File Added: 3603.diff | |
2016-03-28 16:09 | tfu | Note Added: 0009853 | |
2016-03-28 17:33 | ludovic | Note Added: 0009854 | |
2016-03-28 19:31 | tfu | File Added: 3603-1.diff | |
2016-03-28 19:31 | tfu | Note Added: 0009858 | |
2016-03-28 19:52 | ludovic | Note Added: 0009859 | |
2016-03-28 20:29 | m_emelchenkov | Note Added: 0009860 | |
2016-03-28 20:37 | tfu | Note Added: 0009861 | |
2016-03-28 21:14 | ludovic | Note Added: 0009862 | |
2016-03-28 21:32 | tfu | Note Added: 0009863 | |
2016-03-28 21:34 | ludovic | Note Added: 0009864 | |
2016-03-28 21:38 | ludovic | Changeset attached | => sogo master 5a342f2f |
2016-03-28 21:38 | ludovic | Assigned To | => ludovic |
2016-03-28 21:38 | ludovic | Resolution | open => fixed |
2016-03-28 21:39 | ludovic | Changeset attached | => sogo v2 821b9d1f |
2016-03-28 21:40 | ludovic | Note Added: 0009865 | |
2016-03-28 21:40 | ludovic | Status | new => resolved |
2016-03-28 21:40 | ludovic | Fixed in Version | => 3.1.0 |