Closed Bug 1511991 Opened 6 years ago Closed 5 years ago

TB (all I have used up to 60.3.2) slow to read larger gmail messages, spin dumps

Categories

(Thunderbird :: Untriaged, defect)

defect
Not set
major

Tracking

(Not tracked)

RESOLVED INVALID

People

(Reporter: bugzilla, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: perf)

Attachments

(6 files)

13.31 KB, text/plain
Details
72.26 KB, application/octet-stream
Details
79.57 KB, application/vnd.openxmlformats-officedocument.spreadsheetml.sheet
Details
214.72 KB, text/plain
Details
107.28 KB, text/plain
Details
156 bytes, text/plain
Details
Attached file cleanTBspindump.txt
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1.2 Safari/605.1.15

Steps to reproduce:

try to read an html (google searches) email in map gmail account. Often 100-200Kb they are very slow to arrive, often provoke spin dump due to excessive wakes and produce report with hugely deep stack trace that looks like recursion error, maybe in displaying the waiting spinning icon. The data read from Gmail seems at fault.


Actual results:

Spindump produced, a long delay, eventually the mail arrives.
IF TB is newly restarted then a similar email will d/l and display at normal speed (<1s rather than 30s+) and the stack does not go deep as far as I can see in profiling etc. The data arrives very slowly. Some years ago I did a lot of logging of this issue with debug logging on, I may still have that stuff. The behaviour persisted for some years.


Expected results:

Show spinner for short time, access the email, display it.
When I say data read at fault I mean that polling the data is slow (bandwidth is fine) but TB is only asking slowly or having security or other issues make it slow. Here is a sample while spinning back in July I have on hand:
Path:            /Applications/Thunderbird.app/Contents/MacOS/thunderbird
Load Address:    0x10a9cb000
Identifier:      org.mozilla.thunderbird
Version:         52.9.1 (52.9.1)
Code Type:       X86-64
Parent Process:  ??? [1]

Date/Time:       2018-07-18 16:17:34.418 +0100
Launch Time:     2018-07-18 16:02:15.181 +0100
OS Version:      Mac OS X 10.11.6 (15G22010)
Report Version:  7
Analysis Tool:   /usr/bin/sample
----

Call graph:
    2163 Thread_2377736   DispatchQueue_1: com.apple.main-thread  (serial)
    + 1943 ???  (in XUL)  load address 0x10b1db000 + 0x21546f2  [0x10d32f6f2]
    + ! 1942 -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:]  (in AppKit) + 454  [0x7fff91aa5226]
    + ! : 1938 _DPSNextEvent  (in AppKit) + 1067  [0x7fff91aa5df6]
    + ! : | 1938 _BlockUntilNextEventMatchingListInModeWithFilter  (in HIToolbox) + 71  [0x7fff906245af]
    + ! : |   1911 ReceiveNextEventCommon  (in HIToolbox) + 432  [0x7fff9062476f]
    + ! : |   + 1911 RunCurrentEventLoopInMode  (in HIToolbox) + 235  [0x7fff90624935]
    + ! : |   +   1906 CFRunLoopRunSpecific  (in CoreFoundation) + 296  [0x7fff834ade28]
    + ! : |   +   ! 1885 __CFRunLoopRun  (in CoreFoundation) + 1356  [0x7fff834ae5dc]
    + ! : |   +   ! : 1885 __CFRunLoopServiceMachPort  (in CoreFoundation) + 212  [0x7fff834af114]
    + ! : |   +   ! :   1885 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   ! :     1885 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   ! 17 __CFRunLoopRun  (in CoreFoundation) + 927  [0x7fff834ae42f]
    + ! : |   +   ! : 16 __CFRunLoopDoSources0  (in CoreFoundation) + 556  [0x7fff834aef0c]
    + ! : |   +   ! : | 15 ???  (in XUL)  load address 0x10b1db000 + 0x21550aa  [0x10d3300aa]
    + ! : |   +   ! : | + 10 -[NSEvent _postAtStart:]  (in AppKit) + 85  [0x7fff91cbcfe3]
    + ! : |   +   ! : | + ! 8 PostEventToQueueInternal  (in HIToolbox) + 789  [0x7fff906258c1]
    + ! : |   +   ! : | + ! : 7 CFRunLoopWakeUp  (in CoreFoundation) + 204  [0x7fff8349cbec]
    + ! : |   +   ! : | + ! : | 7 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   ! : | + ! : |   7 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   ! : | + ! : 1 CFRunLoopWakeUp  (in CoreFoundation) + 240  [0x7fff8349cc10]
    + ! : |   +   ! : | + ! :   1 _pthread_mutex_unlock_drop  (in libsystem_pthread.dylib) + 60  [0x7fff89e16d8c]
    + ! : |   +   ! : | + ! :     1 __psynch_mutexdrop  (in libsystem_kernel.dylib) + 10  [0x7fff9771edce]
    + ! : |   +   ! : | + ! 1 PostEventToQueueInternal  (in HIToolbox) + 802  [0x7fff906258ce]
    + ! : |   +   ! : | + ! : 1 _NotifyEventLoopObservers  (in HIToolbox) + 155  [0x7fff905fbf96]
    + ! : |   +   ! : | + ! :   1 SCTKeyEventObserver  (in Shortcut) + 26  [0x7fff8880dce7]
    + ! : |   +   ! : | + ! :     1 GetEventClass  (in HIToolbox) + 0  [0x7fff905f942e]
    + ! : |   +   ! : | + ! 1 pthread_mutex_lock  (in libsystem_pthread.dylib) + 84  [0x7fff89e144b0]
    + ! : |   +   ! : | + 2 -[NSEvent _postAtStart:]  (in AppKit) + 44  [0x7fff91cbcfba]
    + ! : |   +   ! : | + ! 2 -[NSEvent _eventRefInternal]  (in AppKit) + 40  [0x7fff91c4a7d5]
    + ! : |   +   ! : | + !   2 -[NSEvent CGEvent]  (in AppKit) + 129  [0x7fff91cbd0e7]
    + ! : |   +   ! : | + !     1 -[NSEvent _cgsEventRecord]  (in AppKit) + 341  [0x7fff91cb26dd]
    + ! : |   +   ! : | + !     : 1 -[NSEvent window]  (in AppKit) + 71  [0x7fff91c34549]
    + ! : |   +   ! : | + !     :   1 -[NSApplication(NSWindowCache) _findWindowUsingCache:]  (in AppKit) + 233  [0x7fff91aae001]
    + ! : |   +   ! : | + !     1 -[NSEvent _cgsEventRecord]  (in AppKit) + 0  [0x7fff91cb2588]
    + ! : |   +   ! : | + 2 CFRunLoopWakeUp  (in CoreFoundation) + 226  [0x7fff8349cc02]
    + ! : |   +   ! : | + ! 2 mach_msg_destroy  (in libsystem_kernel.dylib) + 34  [0x7fff97718654]
    + ! : |   +   ! : | + !   2 mach_port_deallocate  (in libsystem_kernel.dylib) + 17  [0x7fff9771d8b0]
    + ! : |   +   ! : | + !     2 _kernelrpc_mach_port_deallocate_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718ee2]
    + ! : |   +   ! : | + 1 CFRunLoopWakeUp  (in CoreFoundation) + 204  [0x7fff8349cbec]
    + ! : |   +   ! : | +   1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   ! : | +     1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   ! : | 1 PR_GetThreadPrivate  (in libnss3.dylib) + 15  [0x10b0b91cf]
    + ! : |   +   ! : 1 __CFRunLoopDoSources0  (in CoreFoundation) + 110  [0x7fff834aed4e]
    + ! : |   +   ! :   1 CFSetApplyFunction  (in CoreFoundation) + 186  [0x7fff8347dcba]
    + ! : |   +   ! :     1 CFBasicHashApply  (in CoreFoundation) + 128  [0x7fff83469140]
    + ! : |   +   ! :       1 __CFSetApplyFunction_block_invoke  (in CoreFoundation) + 18  [0x7fff8347dd22]
    + ! : |   +   ! :         1 __CFRunLoopCollectSources0  (in CoreFoundation) + 22  [0x7fff834aef86]
    + ! : |   +   ! 1 __CFRunLoopRun  (in CoreFoundation) + 1109  [0x7fff834ae4e5]
    + ! : |   +   ! : 1 mach_port_insert_member  (in libsystem_kernel.dylib) + 23  [0x7fff9771d9fc]
    + ! : |   +   ! :   1 _kernelrpc_mach_port_insert_member_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f12]
    + ! : |   +   ! 1 __CFRunLoopRun  (in CoreFoundation) + 1476  [0x7fff834ae654]
    + ! : |   +   ! : 1 _pthread_mutex_lock_slow  (in libsystem_pthread.dylib) + 300  [0x7fff89e145f5]
    + ! : |   +   ! :   1 _pthread_mutex_lock_wait  (in libsystem_pthread.dylib) + 89  [0x7fff89e16e4a]
    + ! : |   +   ! :     1 __psynch_mutexwait  (in libsystem_kernel.dylib) + 10  [0x7fff9771ede6]
    + ! : |   +   ! 1 __CFRunLoopRun  (in CoreFoundation) + 1949  [0x7fff834ae82d]
    + ! : |   +   ! : 1 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__  (in CoreFoundation) + 9  [0x7fff834ef949]
    + ! : |   +   ! :   1 _dispatch_main_queue_callback_4CF  (in libdispatch.dylib) + 1685  [0x7fff8ba1ec1c]
    + ! : |   +   ! :     1 _dispatch_client_callout  (in libdispatch.dylib) + 8  [0x7fff8ba0b40b]
    + ! : |   +   ! :       1 _dispatch_call_block_and_release  (in libdispatch.dylib) + 12  [0x7fff8ba1693d]
    + ! : |   +   ! :         1 ___ZN21CGSDatagramReadStream24dispatch_datagrams_asyncEP16dispatch_queue_sPS__block_invoke  (in CoreGraphics) + 18  [0x7fff978a298e]
    + ! : |   +   ! :           1 CGSDatagramReadStream::dispatch_datagrams()  (in CoreGraphics) + 442  [0x7fff9786642e]
    + ! : |   +   ! :             1 (anonymous namespace)::notify_datagram_handler(unsigned int, CGSDatagramType, void*, unsigned long, void*)  (in CoreGraphics) + 864  [0x7fff978697fe]
    + ! : |   +   ! :               1 spacesNotificationHandler  (in AppKit) + 119  [0x7fff91dd5021]
    + ! : |   +   ! :                 1 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 66  [0x7fff82ffcf5a]
    + ! : |   +   ! :                   1 _CFXNotificationPost  (in CoreFoundation) + 693  [0x7fff834817e5]
    + ! : |   +   ! :                     1 -[_CFXNotificationRegistrar find:object:observer:enumerator:]  (in CoreFoundation) + 1922  [0x7fff83482592]
    + ! : |   +   ! :                       1 ___CFXNotificationPost_block_invoke  (in CoreFoundation) + 50  [0x7fff834c5782]
    + ! : |   +   ! :                         1 _CFXRegistrationPost  (in CoreFoundation) + 407  [0x7fff834c5a17]
    + ! : |   +   ! :                           1 ___CFXRegistrationPost_block_invoke  (in CoreFoundation) + 63  [0x7fff834c5a9f]
    + ! : |   +   ! :                             1 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__  (in CoreFoundation) + 12  [0x7fff834c5b0c]
    + ! : |   +   ! :                               1 -[NSApplication activeSpaceChanged:]  (in AppKit) + 42  [0x7fff91dd505e]
    + ! : |   +   ! :                                 1 -[NSApplication _updateActiveWindowForSpaceChange]  (in AppKit) + 51  [0x7fff91dd50f3]
    + ! : |   +   ! :                                   1 -[NSWindow isOnActiveSpace]  (in AppKit) + 22  [0x7fff91cec11e]
    + ! : |   +   ! :                                     1 -[NSWindow _isInSomeVisibleSpace]  (in AppKit) + 115  [0x7fff91cb5658]
    + ! : |   +   ! :                                       1 +[NSCGSWindow(NSCGSSpace) isAnyWindowOnAVisibleSpace:]  (in AppKit) + 711  [0x7fff92081a11]
    + ! : |   +   ! :                                         1 CGSManagedDisplayCurrentSpaceAllowsWindow  (in CoreGraphics) + 133  [0x7fff97cbaefa]
    + ! : |   +   ! :                                           1 property_list_call_as_buffer  (in CoreGraphics) + 89  [0x7fff978aac02]
    + ! : |   +   ! :                                             1 __CGSManagedDisplayCurrentSpaceAllowsWindow_block_invoke  (in CoreGraphics) + 163  [0x7fff97cbc46b]
    + ! : |   +   ! :                                               1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   ! :                                                 1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   ! 1 __CFRunLoopRun  (in CoreFoundation) + 1133  [0x7fff834ae4fd]
    + ! : |   +   2 CFRunLoopRunSpecific  (in CoreFoundation) + 323  [0x7fff834ade43]
    + ! : |   +   1 CFRunLoopRunSpecific  (in CoreFoundation) + 101  [0x7fff834add65]
    + ! : |   +   ! 1 __CFRunLoopFindMode  (in CoreFoundation) + 977  [0x7fff8347d311]
    + ! : |   +   1 CFRunLoopRunSpecific  (in CoreFoundation) + 328  [0x7fff834ade48]
    + ! : |   +   ! 1 __CFRunLoopDoObservers  (in CoreFoundation) + 435  [0x7fff834cef63]
    + ! : |   +   !   1 _pthread_mutex_lock_slow  (in libsystem_pthread.dylib) + 300  [0x7fff89e145f5]
    + ! : |   +   !     1 _pthread_mutex_lock_wait  (in libsystem_pthread.dylib) + 89  [0x7fff89e16e4a]
    + ! : |   +   !       1 __psynch_mutexwait  (in libsystem_kernel.dylib) + 10  [0x7fff9771ede6]
    + ! : |   +   1 CFRunLoopRunSpecific  (in CoreFoundation) + 361  [0x7fff834ade69]
    + ! : |   +     1 szone_free  (in libsystem_malloc.dylib) + 4555  [0x7fff84bbd564]
    + ! : |   26 ReceiveNextEventCommon  (in HIToolbox) + 184  [0x7fff90624677]
    + ! : |   + 26 RunCurrentEventLoopInMode  (in HIToolbox) + 235  [0x7fff90624935]
    + ! : |   +   12 CFRunLoopRunSpecific  (in CoreFoundation) + 296  [0x7fff834ade28]
    + ! : |   +   ! 8 __CFRunLoopRun  (in CoreFoundation) + 872  [0x7fff834ae3f8]
    + ! : |   +   ! : 7 __CFRunLoopDoObservers  (in CoreFoundation) + 391  [0x7fff834cef37]
    + ! : |   +   ! : | 7 __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__  (in CoreFoundation) + 23  [0x7fff834cefc7]
    + ! : |   +   ! : |   6 __38-[NSApplication setWindowsNeedUpdate:]_block_invoke2625  (in AppKit) + 76  [0x7fff91ef8122]
    + ! : |   +   ! : |   + 3 -[NSApplication updateWindows]  (in AppKit) + 58  [0x7fff91aa7bfb]
    + ! : |   +   ! : |   + ! 2 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 42  [0x7fff82ffcf42]
    + ! : |   +   ! : |   + ! : 1 +[NSConcreteNotification newTempNotificationWithName:object:userInfo:]  (in Foundation) + 61  [0x7fff82ffcfbb]
    + ! : |   +   ! : |   + ! : 1 objc_msgSend  (in libobjc.A.dylib) + 26  [0x7fff912184da]
    + ! : |   +   ! : |   + ! 1 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 66  [0x7fff82ffcf5a]
    + ! : |   +   ! : |   + !   1 _CFXNotificationPost  (in CoreFoundation) + 693  [0x7fff834817e5]
    + ! : |   +   ! : |   + !     1 -[_CFXNotificationRegistrar find:object:observer:enumerator:]  (in CoreFoundation) + 1829  [0x7fff83482535]
    + ! : |   +   ! : |   + !       1 _CFAutoreleasePoolPop  (in CoreFoundation) + 50  [0x7fff8346dbc2]
    + ! : |   +   ! : |   + !         1 (anonymous namespace)::AutoreleasePoolPage::pop(void*)  (in libobjc.A.dylib) + 524  [0x7fff9121db6a]
    + ! : |   +   ! : |   + 3 -[NSApplication updateWindows]  (in AppKit) + 70  [0x7fff91aa7c07]
    + ! : |   +   ! : |   +   2 -[NSApplication(NSWindowCache) _updateWindowsUsingCache]  (in AppKit) + 533  [0x7fff91aa95dd]
    + ! : |   +   ! : |   +   : 2 objc_object::sidetable_release(bool)  (in libobjc.A.dylib) + 242  [0x7fff9121f288]
    + ! : |   +   ! : |   +   :   2 -[__NSArrayM dealloc]  (in CoreFoundation) + 376  [0x7fff83453aa8]
    + ! : |   +   ! : |   +   :     2 object_dispose  (in libobjc.A.dylib) + 30  [0x7fff9121ecd7]
    + ! : |   +   ! : |   +   :       1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x2753  [0x10a9d6753]
    + ! : |   +   ! : |   +   :       1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x2779  [0x10a9d6779]
    + ! : |   +   ! : |   +   1 -[NSApplication(NSWindowCache) _updateWindowsUsingCache]  (in AppKit) + 521  [0x7fff91aa95d1]
    + ! : |   +   ! : |   +     1 -[NSArray makeObjectsPerformSelector:]  (in CoreFoundation) + 480  [0x7fff834cfb90]
    + ! : |   +   ! : |   +       1 -[NSWindow update]  (in AppKit) + 0  [0x7fff91beb16e]
    + ! : |   +   ! : |   1 NSPopAutoreleasePool  (in Foundation) + 1  [0x7fff82ffa8a0]
    + ! : |   +   ! : 1 __CFRunLoopDoObservers  (in CoreFoundation) + 405  [0x7fff834cef45]
    + ! : |   +   ! :   1 CFRunLoopObserverInvalidate  (in CoreFoundation) + 295  [0x7fff834cf3b7]
    + ! : |   +   ! :     1 _Block_release  (in libsystem_blocks.dylib) + 137  [0x7fff977ca6ba]
    + ! : |   +   ! :       1 objc_destructInstance  (in libobjc.A.dylib) + 124  [0x7fff9121ed5c]
    + ! : |   +   ! :         1 objc_object::sidetable_clearDeallocating()  (in libobjc.A.dylib) + 94  [0x7fff9121ede4]
    + ! : |   +   ! :           1 objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::find(DisguisedPtr<objc_object> const&)  (in libobjc.A.dylib) + 35  [0x7fff9121ee63]
    + ! : |   +   ! :             1 bool objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::LookupBucketFor<DisguisedPtr<objc_object> >(DisguisedPtr<objc_object> const&, std::__1::pair<DisguisedPtr<objc_object>, unsigned long> const*&) const  (in libobjc.A.dylib) + 155  [0x7fff9123560d]
    + ! : |   +   ! 2 __CFRunLoopRun  (in CoreFoundation) + 927  [0x7fff834ae42f]
    + ! : |   +   ! : 1 __CFRunLoopDoSources0  (in CoreFoundation) + 110  [0x7fff834aed4e]
    + ! : |   +   ! : | 1 CFSetApplyFunction  (in CoreFoundation) + 186  [0x7fff8347dcba]
    + ! : |   +   ! : |   1 CFBasicHashApply  (in CoreFoundation) + 128  [0x7fff83469140]
    + ! : |   +   ! : |     1 __CFSetApplyFunction_block_invoke  (in CoreFoundation) + 18  [0x7fff8347dd22]
    + ! : |   +   ! : |       1 __CFRunLoopCollectSources0  (in CoreFoundation) + 98  [0x7fff834aefd2]
    + ! : |   +   ! : |         1 CFArrayCreateMutable  (in CoreFoundation) + 131  [0x7fff8344c323]
    + ! : |   +   ! : |           1 -[__NSPlaceholderArray initWithCapacity:]  (in CoreFoundation) + 114  [0x7fff8344c402]
    + ! : |   +   ! : |             1 DYLD-STUB$$objc_assign_ivar  (in CoreFoundation) + 0  [0x7fff835f97a8]
    + ! : |   +   ! : 1 __CFRunLoopDoSources0  (in CoreFoundation) + 556  [0x7fff834aef0c]
    + ! : |   +   ! :   1 ???  (in XUL)  load address 0x10b1db000 + 0x21550aa  [0x10d3300aa]
    + ! : |   +   ! :     1 -[NSEvent _postAtStart:]  (in AppKit) + 44  [0x7fff91cbcfba]
    + ! : |   +   ! :       1 -[NSEvent _eventRefInternal]  (in AppKit) + 61  [0x7fff91c4a7ea]
    + ! : |   +   ! :         1 CreateEventWithCGEvent  (in HIToolbox) + 7636  [0x7fff90630c73]
    + ! : |   +   ! :           1 SetEventPlatformEvent  (in HIToolbox) + 45  [0x7fff90631a76]
    + ! : |   +   ! :             1 CFRetain  (in CoreFoundation) + 0  [0x7fff8342c520]
    + ! : |   +   ! 2 __CFRunLoopRun  (in CoreFoundation) + 1109  [0x7fff834ae4e5]
    + ! : |   +   !   1 mach_port_insert_member  (in libsystem_kernel.dylib) + 23  [0x7fff9771d9fc]
    + ! : |   +   !   | 1 _kernelrpc_mach_port_insert_member_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f12]
    + ! : |   +   !   1 mach_port_insert_member  (in libsystem_kernel.dylib) + 6  [0x7fff9771d9eb]
    + ! : |   +   10 CFRunLoopRunSpecific  (in CoreFoundation) + 271  [0x7fff834ade0f]
    + ! : |   +   ! 10 __CFRunLoopDoObservers  (in CoreFoundation) + 391  [0x7fff834cef37]
    + ! : |   +   !   10 __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__  (in CoreFoundation) + 23  [0x7fff834cefc7]
    + ! : |   +   !     10 FlushAllBuffers(__CFRunLoopObserver*, unsigned long, void*)  (in HIToolbox) + 229  [0x7fff9062d71d]
    + ! : |   +   !       8 FlushWindowObject(WindowData*, void**, unsigned char)  (in HIToolbox) + 771  [0x7fff9062dd4e]
    + ! : |   +   !       : 8 HIView::Render(unsigned int, CGContext*)  (in HIToolbox) + 54  [0x7fff90617c10]
    + ! : |   +   !       :   8 HIView::DrawComposited(short, OpaqueGrafPtr*, __HIShape const*, unsigned int, HIView*, CGContext*)  (in HIToolbox) + 1031  [0x7fff9061801d]
    + ! : |   +   !       :     8 HIView::RecursiveDrawComposited(__HIShape const*, __HIShape const*, unsigned int, HIView*, CGContext*, unsigned char, double)  (in HIToolbox) + 1293  [0x7fff90618869]
    + ! : |   +   !       :       8 HIView::RecursiveDrawComposited(__HIShape const*, __HIShape const*, unsigned int, HIView*, CGContext*, unsigned char, double)  (in HIToolbox) + 557  [0x7fff90618589]
    + ! : |   +   !       :         8 HIView::SendDraw(short, OpaqueGrafPtr*, __HIShape const*, CGContext*)  (in HIToolbox) + 337  [0x7fff90618c07]
    + ! : |   +   !       :           8 SendEventToEventTargetWithOptions  (in HIToolbox) + 43  [0x7fff905fbaab]
    + ! : |   +   !       :             8 SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)  (in HIToolbox) + 404  [0x7fff905fbc48]
    + ! : |   +   !       :               8 DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)  (in HIToolbox) + 1231  [0x7fff905fc7be]
    + ! : |   +   !       :                 8 HIMenuBarView::DrawingDelegateHandler(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)  (in HIToolbox) + 249  [0x7fff90619041]
    + ! : |   +   !       :                   8 HIMenuBarView::DrawWithoutCustomization(short, __HIShape const*, CGContext*)  (in HIToolbox) + 82  [0x7fff906190a2]
    + ! : |   +   !       :                     3 HIMenuBarView::DrawSelf(short, __HIShape const*, CGContext*)  (in HIToolbox) + 559  [0x7fff9061965b]
    + ! : |   +   !       :                     | 2 HIMenuBarView::DrawOnce(CGRect, CGRect, bool, bool, CGContext*)  (in HIToolbox) + 1713  [0x7fff90619e09]
    + ! : |   +   !       :                     | + 2 HIMenuBarView::DrawTextTitle(MenuData*, CGRect const*, __CFString const*, unsigned short, CGContext*, bool, bool)  (in HIToolbox) + 403  [0x7fff9061e8a5]
    + ! : |   +   !       :                     | +   2 HIThemeDrawTextBox  (in HIToolbox) + 491  [0x7fff9061f2b9]
    + ! : |   +   !       :                     | +     2 DataEngine::DrawTextBox(void const*, CGRect const*, HIThemeTextInfo*, CGContext*)  (in HIToolbox) + 1437  [0x7fff9061f86b]
    + ! : |   +   !       :                     | +       2 ___ZN10DataEngine11DrawTextBoxEPKvPK6CGRectP15HIThemeTextInfoP9CGContext_block_invoke  (in HIToolbox) + 262  [0x7fff9061fb5d]
    + ! : |   +   !       :                     | +         2 TCoreTextEngine::DrawThemeTextBox(THIThemeTextInfo*, CGRect const&, unsigned int, CGContext*)  (in HIToolbox) + 2333  [0x7fff90620545]
    + ! : |   +   !       :                     | +           2 _HIThemeCUIDrawStyledGlyphsAtPositions  (in HIToolbox) + 88  [0x7fff90620dc0]
    + ! : |   +   !       :                     | +             2 CUIDrawStyledGlyphsAtPositions  (in CoreUI) + 172  [0x7fff8711ac89]
    + ! : |   +   !       :                     | +               2 CUIRenderer::DrawStyledGlyphsAtPositions(CGContext*, __CFDictionary const*, __CTFont const*, unsigned short const*, CGPoint const*, unsigned long, double)  (in CoreUI) + 2165  [0x7fff87119609]
    + ! : |   +   !       :                     | +                 1 -[CUITextEffectStack drawGlyphs:inContext:usingFont:atPositions:count:lineHeight:inBounds:atScale:]  (in CoreUI) + 1792  [0x7fff87143a8e]
    + ! : |   +   !       :                     | +                 ! 1 CTFontDrawGlyphsAtPositions  (in CoreText) + 278  [0x7fff96c58ed6]
    + ! : |   +   !       :                     | +                 !   1 DrawSbixGlyphsAtPositions(TFont const*, __CFData const*, unsigned short const*, CGPoint const*, unsigned long, CGContext*, CGAffineTransform, CGAffineTransform)  (in CoreText) + 2937  [0x7fff96c59a8c]
    + ! : |   +   !       :                     | +                 !     1 draw_glyphs15847  (in CoreGraphics) + 836  [0x7fff97cdfbcd]
    + ! : |   +   !       :                     | +                 !       1 ripc_DrawGlyphs  (in libRIP.A.dylib) + 1929  [0x7fff8f3c91eb]
    + ! : |   +   !       :                     | +                 !         1 draw_glyph_bitmaps  (in libRIP.A.dylib) + 1789  [0x7fff8f3c9961]
    + ! : |   +   !       :                     | +                 !           1 render_glyphs  (in libRIP.A.dylib) + 401  [0x7fff8f3c9b50]
    + ! : |   +   !       :                     | +                 !             1 render_glyph_list  (in libRIP.A.dylib) + 460  [0x7fff8f3c9e45]
    + ! : |   +   !       :                     | +                 !               1 RIPLayerBltGlyph  (in libRIP.A.dylib) + 7751  [0x7fff8f3cbca9]
    + ! : |   +   !       :                     | +                 !                 1 argb32_mark  (in CoreGraphics) + 3630  [0x7fff9782e7f9]
    + ! : |   +   !       :                     | +                 1 -[CUITextEffectStack drawGlyphs:inContext:usingFont:atPositions:count:lineHeight:inBounds:atScale:]  (in CoreUI) + 1800  [0x7fff87143a96]
    + ! : |   +   !       :                     | +                   1 CGContextEndTransparencyLayer  (in CoreGraphics) + 67  [0x7fff9785f92e]
    + ! : |   +   !       :                     | +                     1 ripc_EndLayer  (in libRIP.A.dylib) + 1423  [0x7fff8f3cc2d3]
    + ! : |   +   !       :                     | +                       1 RIPLayerBltImage  (in libRIP.A.dylib) + 1185  [0x7fff8f3c6491]
    + ! : |   +   !       :                     | +                         1 argb32_image  (in CoreGraphics) + 2441  [0x7fff9784cd41]
    + ! : |   +   !       :                     | +                           1 argb32_mark  (in CoreGraphics) + 23827  [0x7fff978336de]
    + ! : |   +   !       :                     | 1 HIMenuBarView::DrawOnce(CGRect, CGRect, bool, bool, CGContext*)  (in HIToolbox) + 1216  [0x7fff90619c18]
    + ! : |   +   !       :                     |   1 _HIThemeDrawAppleMenuTitle  (in HIToolbox) + 531  [0x7fff9061d282]
    + ! : |   +   !       :                     |     1 _HIThemeCUIDrawWithRenderer  (in HIToolbox) + 174  [0x7fff9061dee6]
    + ! : |   +   !       :                     |       1 _HIThemeCUIDrawWithOptions  (in HIToolbox) + 81  [0x7fff9061df52]
    + ! : |   +   !       :                     |         1 CUIDraw  (in CoreUI) + 175  [0x7fff8711a992]
    + ! : |   +   !       :                     |           1 CUIRenderer::Draw(CGRect, CGContext*, __CFDictionary const*, __CFDictionary const**)  (in CoreUI) + 2341  [0x7fff87118065]
    + ! : |   +   !       :                     |             1 CUICoreThemeRenderer::DrawMenuTitle(CUIDescriptor const*, CUIReturnInfo&)  (in CoreUI) + 850  [0x7fff8718d238]
    + ! : |   +   !       :                     |               1 CUIRenderer::DrawImage(CGRect, long, CUIDescriptor const*) const  (in CoreUI) + 7338  [0x7fff8712998c]
    + ! : |   +   !       :                     |                 1 CGContextDrawImage  (in CoreGraphics) + 51  [0x7fff9783af98]
    + ! : |   +   !       :                     |                   1 CGContextDrawImageWithOptions  (in CoreGraphics) + 571  [0x7fff9783b1ef]
    + ! : |   +   !       :                     |                     1 ripc_DrawImage  (in libRIP.A.dylib) + 1151  [0x7fff8f3c3d0a]
    + ! : |   +   !       :                     |                       1 RIPLayerBltImage  (in libRIP.A.dylib) + 1185  [0x7fff8f3c6491]
    + ! : |   +   !       :                     |                         1 argb32_image  (in CoreGraphics) + 3121  [0x7fff9784cfe9]
    + ! : |   +   !       :                     |                           1 argb32_image_mark  (in CoreGraphics) + 1632  [0x7fff978508c2]
    + ! : |   +   !       :                     |                             1 argb32_sample_ARGB32  (in CoreGraphics) + 2475  [0x7fff978543ee]
    + ! : |   +   !       :                     3 HIMenuBarView::DrawSelf(short, __HIShape const*, CGContext*)  (in HIToolbox) + 705  [0x7fff906196ed]
    + ! : |   +   !       :                     | 2 HIMenuBarView::DrawOnce(CGRect, CGRect, bool, bool, CGContext*)  (in HIToolbox) + 1713  [0x7fff90619e09]
    + ! : |   +   !       :                     | + 1 HIMenuBarView::DrawTextTitle(MenuData*, CGRect const*, __CFString const*, unsigned short, CGContext*, bool, bool)  (in HIToolbox) + 63  [0x7fff9061e751]
    + ! : |   +   !       :                     | + ! 1 _CopyMenuTitleAsCFString(MenuData*, __CFString const**)  (in HIToolbox) + 82  [0x7fff905ff126]
    + ! : |   +   !       :                     | + !   1 CFRetain  (in CoreFoundation) + 27  [0x7fff8342c53b]
    + ! : |   +   !       :                     | + 1 HIMenuBarView::DrawTextTitle(MenuData*, CGRect const*, __CFString const*, unsigned short, CGContext*, bool, bool)  (in HIToolbox) + 403  [0x7fff9061e8a5]
    + ! : |   +   !       :                     | +   1 HIThemeDrawTextBox  (in HIToolbox) + 491  [0x7fff9061f2b9]
    + ! : |   +   !       :                     | +     1 DataEngine::DrawTextBox(void const*, CGRect const*, HIThemeTextInfo*, CGContext*)  (in HIToolbox) + 1437  [0x7fff9061f86b]
    + ! : |   +   !       :                     | +       1 ___ZN10DataEngine11DrawTextBoxEPKvPK6CGRectP15HIThemeTextInfoP9CGContext_block_invoke  (in HIToolbox) + 262  [0x7fff9061fb5d]
    + ! : |   +   !       :                     | +         1 TCoreTextEngine::DrawThemeTextBox(THIThemeTextInfo*, CGRect const&, unsigned int, CGContext*)  (in HIToolbox) + 180  [0x7fff9061fcdc]
    + ! : |   +   !       :                     | 1 HIMenuBarView::DrawOnce(CGRect, CGRect, bool, bool, CGContext*)  (in HIToolbox) + 1216  [0x7fff90619c18]
    + ! : |   +   !       :                     |   1 _HIThemeDrawAppleMenuTitle  (in HIToolbox) + 531  [0x7fff9061d282]
    + ! : |   +   !       :                     |     1 _HIThemeCUIDrawWithRenderer  (in HIToolbox) + 174  [0x7fff9061dee6]
    + ! : |   +   !       :                     |       1 _HIThemeCUIDrawWithOptions  (in HIToolbox) + 81  [0x7fff9061df52]
    + ! : |   +   !       :                     |         1 CUIDraw  (in CoreUI) + 175  [0x7fff8711a992]
    + ! : |   +   !       :                     |           1 CUIRenderer::Draw(CGRect, CGContext*, __CFDictionary const*, __CFDictionary const**)  (in CoreUI) + 2341  [0x7fff87118065]
    + ! : |   +   !       :                     |             1 CUICoreThemeRenderer::DrawMenuTitle(CUIDescriptor const*, CUIReturnInfo&)  (in CoreUI) + 850  [0x7fff8718d238]
    + ! : |   +   !       :                     |               1 CUIRenderer::DrawImage(CGRect, long, CUIDescriptor const*) const  (in CoreUI) + 7338  [0x7fff8712998c]
    + ! : |   +   !       :                     |                 1 CGContextDrawImage  (in CoreGraphics) + 51  [0x7fff9783af98]
    + ! : |   +   !       :                     |                   1 CGContextDrawImageWithOptions  (in CoreGraphics) + 571  [0x7fff9783b1ef]
    + ! : |   +   !       :                     |                     1 ripc_DrawImage  (in libRIP.A.dylib) + 1151  [0x7fff8f3c3d0a]
    + ! : |   +   !       :                     |                       1 RIPLayerBltImage  (in libRIP.A.dylib) + 1185  [0x7fff8f3c6491]
    + ! : |   +   !       :                     |                         1 argb32_image  (in CoreGraphics) + 3121  [0x7fff9784cfe9]
    + ! : |   +   !       :                     |                           1 argb32_image_mark  (in CoreGraphics) + 8310  [0x7fff978522d8]
    + ! : |   +   !       :                     2 HIMenuBarView::DrawSelf(short, __HIShape const*, CGContext*)  (in HIToolbox) + 609  [0x7fff9061968d]
    + ! : |   +   !       :                       1 CopyWindowImageRect  (in HIToolbox) + 47  [0x7fff90620e26]
    + ! : |   +   !       :                       + 1 CGWindowContextCreate  (in CoreGraphics) + 83  [0x7fff97826ac7]
    + ! : |   +   !       :                       +   1 CGSSessionCopyCurrentSessionProperties  (in CoreGraphics) + 141  [0x7fff978279f0]
    + ! : |   +   !       :                       +     1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   !       :                       +       1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   !       :                       1 CopyWindowImageRect  (in HIToolbox) + 92  [0x7fff90620e53]
    + ! : |   +   !       :                         1 CopyWindowImageRectToContext  (in HIToolbox) + 242  [0x7fff90620f6a]
    + ! : |   +   !       :                           1 CGContextCopyWindowContentsToRect  (in CoreGraphics) + 146  [0x7fff9785fb5b]
    + ! : |   +   !       :                             1 ripc_DrawWindowContents  (in libRIP.A.dylib) + 1434  [0x7fff8f3cc920]
    + ! : |   +   !       :                               1 CGSImageDataLockDevice  (in CoreGraphics) + 1178  [0x7fff97860131]
    + ! : |   +   !       :                                 1 img_data_lock  (in CoreGraphics) + 8852  [0x7fff9783eddf]
    + ! : |   +   !       :                                   1 img_alphamerge_read  (in CoreGraphics) + 535  [0x7fff97840ca2]
    + ! : |   +   !       :                                     1 img_colormatch_read  (in CoreGraphics) + 582  [0x7fff97840f72]
    + ! : |   +   !       :                                       1 CGColorTransformConvertData  (in CoreGraphics) + 381  [0x7fff9784c190]
    + ! : |   +   !       :                                         1 CGCMSConverterConvertData  (in CoreGraphics) + 91  [0x7fff9781f086]
    + ! : |   +   !       :                                           1 convert_icc  (in CoreGraphics) + 2281  [0x7fff9781f97e]
    + ! : |   +   !       :                                             1 vImageConvert_AnyToAny  (in vImage) + 1875  [0x7fff8c5e7f93]
    + ! : |   +   !       :                                               1 AnyToAnyBlock  (in vImage) + 1287  [0x7fff8c5e8817]
    + ! : |   +   !       :                                                 1 DoMatrix  (in vImage) + 285  [0x7fff8c5d974d]
    + ! : |   +   !       :                                                   1 vImageMatrixMultiply_Planar16S  (in vImage) + 3921  [0x7fff8c4f1491]
    + ! : |   +   !       :                                                     1 vMatrixMultiply_Planar16S_34_avx2  (in vImage) + 2188  [0x7fff8c6347ec]
    + ! : |   +   !       2 FlushWindowObject(WindowData*, void**, unsigned char)  (in HIToolbox) + 1007  [0x7fff9062de3a]
    + ! : |   +   !         2 MenuBarInstance::SetServerBounds()  (in HIToolbox) + 37  [0x7fff9062355d]
    + ! : |   +   !           2 GetActiveDisplay  (in HIToolbox) + 34  [0x7fff9062106b]
    + ! : |   +   !             2 CGSCopyActiveMenuBarDisplayIdentifier  (in CoreGraphics) + 185  [0x7fff978613eb]
    + ! : |   +   !               2 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +   !                 2 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +   4 CFRunLoopRunSpecific  (in CoreFoundation) + 328  [0x7fff834ade48]
    + ! : |   +     4 __CFRunLoopDoObservers  (in CoreFoundation) + 391  [0x7fff834cef37]
    + ! : |   +       4 __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__  (in CoreFoundation) + 23  [0x7fff834cefc7]
    + ! : |   +         4 CA::Transaction::observer_callback(__CFRunLoopObserver*, unsigned long, void*)  (in QuartzCore) + 71  [0x7fff98a6f863]
    + ! : |   +           4 CA::Transaction::commit()  (in QuartzCore) + 508  [0x7fff98a63fd4]
    + ! : |   +             2 CA::Context::commit_transaction(CA::Transaction*)  (in QuartzCore) + 2460  [0x7fff98a64c10]
    + ! : |   +             : 2 CA::Transaction::run_commit_handlers(CATransactionPhase)  (in QuartzCore) + 85  [0x7fff98a64e59]
    + ! : |   +             :   2 __39+[_NSCGSTransaction currentTransaction]_block_invoke  (in AppKit) + 34  [0x7fff91bf104a]
    + ! : |   +             :     2 NSCGSTransactionRunPreCommitActions_  (in AppKit) + 31  [0x7fff91bf1075]
    + ! : |   +             :       2 NSCGSTransactionRunPreCommitActionsForOrder_  (in AppKit) + 298  [0x7fff91bf11b2]
    + ! : |   +             :         1 __70-[NSCGSWindow(NSCGSWindowOrderingGroup) orderGroupFrontConditionally:]_block_invoke  (in AppKit) + 83  [0x7fff91c30699]
    + ! : |   +             :         | 1 -[NSCGSWindow(NSCGSWindowOrderingGroup) orderingGroup]  (in AppKit) + 80  [0x7fff91bec466]
    + ! : |   +             :         |   1 CGSCopyWindowGroup  (in CoreGraphics) + 304  [0x7fff9786f1e7]
    + ! : |   +             :         |     1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +             :         |       1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +             :         1 __NSCGSWindowBackingStoreMark__block_invoke  (in AppKit) + 960  [0x7fff91c2feda]
    + ! : |   +             :           1 lock_device  (in AppKit) + 64  [0x7fff91c66f97]
    + ! : |   +             :             1 CGSDeviceLock  (in CoreGraphics) + 39  [0x7fff9782cf6e]
    + ! : |   +             :               1 CGSWindowSynchronizeBacking  (in CoreGraphics) + 151  [0x7fff97822507]
    + ! : |   +             :                 1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + ! : |   +             :                   1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + ! : |   +             1 CA::Context::commit_transaction(CA::Transaction*)  (in QuartzCore) + 160  [0x7fff98a64314]
    + ! : |   +             : 1 CA::Transaction::run_commit_handlers(CATransactionPhase)  (in QuartzCore) + 85  [0x7fff98a64e59]
    + ! : |   +             :   1 __37+[NSDisplayCycle currentDisplayCycle]_block_invoke  (in AppKit) + 941  [0x7fff91bfd5d6]
    + ! : |   +             :     1 ___NSWindowGetDisplayCycleObserver_block_invoke6365  (in AppKit) + 476  [0x7fff9228241b]
    + ! : |   +             :       1 -[NSWindow displayIfNeeded]  (in AppKit) + 232  [0x7fff91bfdc3c]
    + ! : |   +             :         1 -[NSView displayIfNeeded]  (in AppKit) + 1950  [0x7fff91bfe3f5]
    + ! : |   +             :           1 -[NSView _displayRectIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:]  (in AppKit) + 2449  [0x7fff91c02feb]
    + ! : |   +             :             1 -[NSThemeFrame _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]  (in AppKit) + 334  [0x7fff91c04be0]
    + ! : |   +             :               1 -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]  (in AppKit) + 838  [0x7fff91c053fb]
    + ! : |   +             :                 1 -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]  (in AppKit) + 2862  [0x7fff91c6008a]
    + ! : |   +             :                   1 -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]  (in AppKit) + 2862  [0x7fff91c6008a]
    + ! : |   +             :                     1 -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]  (in AppKit) + 2862  [0x7fff91c6008a]
    + ! : |   +             :                       1 -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]  (in AppKit) + 1873  [0x7fff91c5fcad]
    + ! : |   +             :                         1 -[NSView _drawRect:clip:]  (in AppKit) + 2414  [0x7fff91c07816]
    + ! : |   +             :                           1 CGContextSaveGState  (in CoreGraphics) + 32  [0x7fff97828c94]
    + ! : |   +             :                             1 CGGStackSave  (in CoreGraphics) + 77  [0x7fff97828d02]
    + ! : |   +             :                               1 malloc  (in libsystem_malloc.dylib) + 42  [0x7fff84bb60cc]
    + ! : |   +             :                                 1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x3a96  [0x10a9d7a96]
    + ! : |   +             1 CA::Context::commit_transaction(CA::Transaction*)  (in QuartzCore) + 2416  [0x7fff98a64be4]
    + ! : |   +               1 CA::Transaction::run_deferred_visibility_layer_calls()  (in QuartzCore) + 0  [0x7fff98a6da60]
    + ! : |   1 ReceiveNextEventCommon  (in HIToolbox) + 288  [0x7fff906246df]
    + ! : |     1 GetCurrentEventTime  (in HIToolbox) + 13  [0x7fff9062d9bc]
    + ! : |       1 mach_absolute_time  (in libsystem_kernel.dylib) + 0  [0x7fff97718333]
    + ! : 1 _DPSNextEvent  (in AppKit) + 632  [0x7fff91aa5c43]
    + ! : | 1 -[NSDate timeIntervalSinceNow]  (in CoreFoundation) + 0  [0x7fff834b4680]
    + ! : 1 _DPSNextEvent  (in AppKit) + 1794  [0x7fff91aa60cd]
    + ! : | 1 -[NSApplication(NSWindowCache) _findWindowUsingCache:]  (in AppKit) + 84  [0x7fff91aadf6c]
    + ! : |   1 -[NSRecursiveLock lock]  (in Foundation) + 0  [0x7fff83009465]
    + ! : 1 _DPSNextEvent  (in AppKit) + 1906  [0x7fff91aa613d]
    + ! : | 1 _NSHandleCarbonMenuEvent  (in AppKit) + 411  [0x7fff91c31180]
    + ! : 1 _DPSNextEvent  (in AppKit) + 3718  [0x7fff91aa6851]
    + ! 1 -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:]  (in AppKit) + 746  [0x7fff91aa534a]
    + !   1 -[NSEvent _initWithCGSEvent:eventRef:]  (in AppKit) + 536  [0x7fff91c313a5]
    + !     1 -[NSApplication _wantsDeviceDependentEventModifierFlags]  (in AppKit) + 0  [0x7fff91c31e6f]
    + 12 PR_WaitCondVar  (in libnss3.dylib) + 253  [0x10b0b638d]
    + ! 12 _pthread_cond_wait  (in libsystem_pthread.dylib) + 767  [0x7fff89e17728]
    + !   12 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7fff9771edb6]
    + 10 ???  (in <unknown binary>)  [0x10aee5290]
    + ! 10 ???  (in XUL)  load address 0x10b1db000 + 0x21555b6  [0x10d3305b6]
    + !   6 ???  (in XUL)  load address 0x10b1db000 + 0x215467a  [0x10d32f67a]
    + !   : 2 -[NSApplication sendEvent:]  (in AppKit) + 8280  [0x7fff91c340a4]
    + !   : | 1 _NXShowKeyAndMain  (in AppKit) + 169  [0x7fff91dc6330]
    + !   : | + 1 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 66  [0x7fff82ffcf5a]
    + !   : | +   1 _CFXNotificationPost  (in CoreFoundation) + 693  [0x7fff834817e5]
    + !   : | +     1 -[_CFXNotificationRegistrar find:object:observer:enumerator:]  (in CoreFoundation) + 1922  [0x7fff83482592]
    + !   : | +       1 ___CFXNotificationPost_block_invoke  (in CoreFoundation) + 50  [0x7fff834c5782]
    + !   : | +         1 _CFXRegistrationPost  (in CoreFoundation) + 407  [0x7fff834c5a17]
    + !   : | +           1 ___CFXRegistrationPost_block_invoke  (in CoreFoundation) + 63  [0x7fff834c5a9f]
    + !   : | +             1 ???  (in XUL)  load address 0x10b1db000 + 0x216cb73  [0x10d347b73]
    + !   : | +               1 -[NSMenu _setMenuName:]  (in AppKit) + 931  [0x7fff91a6e9e3]
    + !   : | +                 1 -[NSApplication setMainMenu:]  (in AppKit) + 1755  [0x7fff91a78267]
    + !   : | +                   1 -[NSMenu _setMenuName:]  (in AppKit) + 521  [0x7fff91a6e849]
    + !   : | +                     1 -[NSCarbonMenuImpl _menuLostMainMenuStatus]  (in AppKit) + 441  [0x7fff91f4db8a]
    + !   : | +                       1 DeleteMenu  (in HIToolbox) + 110  [0x7fff907a4d3e]
    + !   : | +                         1 DeleteMenuPriv(MenuData*, short, bool)  (in HIToolbox) + 142  [0x7fff907a4ddc]
    + !   : | +                           1 AXNotificationHIObjectNotifyForObject  (in HIToolbox) + 70  [0x7fff90638816]
    + !   : | +                             1 AXUIElementCreateWithHIObjectAndIdentifier  (in HIToolbox) + 26  [0x7fff9069ec27]
    + !   : | +                               1 AXUIElementCreateWithHIObjectAndData  (in HIToolbox) + 45  [0x7fff9069fb7e]
    + !   : | +                                 1 __CFDataInit  (in CoreFoundation) + 805  [0x7fff83449eb5]
    + !   : | +                                   1 malloc  (in libsystem_malloc.dylib) + 42  [0x7fff84bb60cc]
    + !   : | +                                     1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x3a96  [0x10a9d7a96]
    + !   : | 1 _NXShowKeyAndMain  (in AppKit) + 184  [0x7fff91dc633f]
    + !   : |   1 _NXSendWindowNotification  (in AppKit) + 252  [0x7fff91bdd971]
    + !   : |     1 -[NSWindow becomeKeyWindow]  (in AppKit) + 1425  [0x7fff91bddf44]
    + !   : |       1 -[NSNotificationCenter postNotificationName:object:userInfo:]  (in Foundation) + 66  [0x7fff82ffcf5a]
    + !   : |         1 _CFXNotificationPost  (in CoreFoundation) + 693  [0x7fff834817e5]
    + !   : |           1 -[_CFXNotificationRegistrar find:object:observer:enumerator:]  (in CoreFoundation) + 1922  [0x7fff83482592]
    + !   : |             1 ___CFXNotificationPost_block_invoke  (in CoreFoundation) + 50  [0x7fff834c5782]
    + !   : |               1 _CFXRegistrationPost  (in CoreFoundation) + 407  [0x7fff834c5a17]
    + !   : |                 1 ___CFXRegistrationPost_block_invoke  (in CoreFoundation) + 63  [0x7fff834c5a9f]
    + !   : |                   1 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__  (in CoreFoundation) + 12  [0x7fff834c5b0c]
    + !   : |                     1 -[NSToolTipManager windowDidBecomeKeyNotification:]  (in AppKit) + 197  [0x7fff91be067e]
    + !   : |                       1 -[NSEnumerator countByEnumeratingWithState:objects:count:]  (in CoreFoundation) + 56  [0x7fff83487ba8]
    + !   : |                         1 -[__NSFastEnumerationEnumerator nextObject]  (in CoreFoundation) + 165  [0x7fff834a38d5]
    + !   : |                           1 -[NSConcreteMapTable countByEnumeratingWithState:objects:count:]  (in Foundation) + 123  [0x7fff83061548]
    + !   : |                             1 readPointerAt  (in Foundation) + 7  [0x7fff8300a754]
    + !   : 1 -[NSApplication sendEvent:]  (in AppKit) + 198  [0x7fff91c32112]
    + !   : | 1 objc_msgSend  (in libobjc.A.dylib) + 46  [0x7fff912184ee]
    + !   : 1 -[NSApplication sendEvent:]  (in AppKit) + 4883  [0x7fff91c3335f]
    + !   : | 1 -[NSWorkspaceNotificationCenter addObserver:selector:name:object:]  (in AppKit) + 86  [0x7fff91a63853]
    + !   : |   1 -[NSWorkspaceNotificationCenter _addOrRemoveObserver:forName:isAdding:]  (in AppKit) + 283  [0x7fff91a63993]
    + !   : |     1 -[NSWorkspaceNotificationCenter _createSubsystemIfNecessary:]  (in AppKit) + 55  [0x7fff91a63ab6]
    + !   : |       1 createActiveSpaceSubsystem  (in AppKit) + 38  [0x7fff91ab41fc]
    + !   : |         1 CGSRegisterConnectionNotifyProc  (in CoreGraphics) + 58  [0x7fff9780f198]
    + !   : |           1 CGSInternalRegisterConnectionNotifyProc  (in CoreGraphics) + 907  [0x7fff9780f55b]
    + !   : |             1 CGSConnectionNotifier::notify() const  (in CoreGraphics) + 511  [0x7fff9780f87f]
    + !   : |               1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + !   : |                 1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + !   : 1 -[NSApplication sendEvent:]  (in AppKit) + 6476  [0x7fff91c33998]
    + !   : | 1 -[NSApplication setWindowsNeedUpdate:]  (in AppKit) + 381  [0x7fff91a96b61]
    + !   : |   1 CFRunLoopAddObserver  (in CoreFoundation) + 152  [0x7fff83497c48]
    + !   : |     1 __CFRunLoopFindMode  (in CoreFoundation) + 0  [0x7fff8347cf40]
    + !   : 1 -[NSApplication sendEvent:]  (in AppKit) + 8200  [0x7fff91c34054]
    + !   :   1 -[NSApplication _findKeyWindowConsideringSpacesWithOriginatingDisplayHint:isAppleEventPending:makeKey:]  (in AppKit) + 145  [0x7fff91dc5fce]
    + !   :     1 -[NSApplication _bestKeyWindowCandidateOnScreen:]  (in AppKit) + 197  [0x7fff91c8983a]
    + !   :       1 -[NSWindow isOnActiveSpace]  (in AppKit) + 22  [0x7fff91cec11e]
    + !   :         1 -[NSWindow _isInSomeVisibleSpace]  (in AppKit) + 115  [0x7fff91cb5658]
    + !   :           1 +[NSCGSWindow(NSCGSSpace) isAnyWindowOnAVisibleSpace:]  (in AppKit) + 630  [0x7fff920819c0]
    + !   :             1 CGSCopyBestManagedDisplayForRect  (in CoreGraphics) + 402  [0x7fff978ede6d]
    + !   :               1 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff977183b3]
    + !   :                 1 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff97718f72]
    + !   4 -[NSApplication run]  (in AppKit) + 893  [0x7fff91a99e53]
    + !     4 -[NSAutoreleasePool drain]  (in Foundation) + 153  [0x7fff8300e7ca]
    + !       4 _CFAutoreleasePoolPop  (in CoreFoundation) + 50  [0x7fff8346dbc2]
    + !         4 (anonymous namespace)::AutoreleasePoolPage::pop(void*)  (in libobjc.A.dylib) + 477  [0x7fff9121db3b]
    + !           4 objc_object::sidetable_release(bool)  (in libobjc.A.dylib) + 242  [0x7fff9121f288]
    + !             3 -[NSEvent dealloc]  (in AppKit) + 226  [0x7fff91bf1a91]
    + !             | 2 object_dispose  (in libobjc.A.dylib) + 30  [0x7fff9121ecd7]
    + !             | + 1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x279b  [0x10a9d679b]
    + !             | + 1 free  (in libsystem_malloc.dylib) + 0  [0x7fff84bb8e98]
    + !             | 1 object_dispose  (in libobjc.A.dylib) + 22  [0x7fff9121eccf]
    + !             |   1 objc_destructInstance  (in libobjc.A.dylib) + 109  [0x7fff9121ed4d]
    + !             |     1 _object_remove_assocations  (in libobjc.A.dylib) + 140  [0x7fff912245ae]
    + !             |       1 std::__1::__hash_iterator<std::__1::__hash_node<std::__1::__hash_value_type<unsigned long, objc_references_support::ObjectAssociationMap*>, void*>*> std::__1::__hash_table<std::__1::__hash_value_type<unsigned long, objc_references_support::ObjectAssociationMap*>, std::__1::__unordered_map_hasher<unsigned long, std::__1::__hash_value_type<unsigned long, objc_references_support::ObjectAssociationMap*>, objc_references_support::DisguisedPointerHash, true>, std::__1::__unordered_map_equal<unsigned long, std::__1::__hash_value_type<unsigned long, objc_references_support::ObjectAssociationMap*>, objc_references_support::DisguisedPointerEqual, true>, objc_references_support::ObjcAllocator<std::__1::__hash_value_type<unsigned long, objc_references_support::ObjectAssociationMap*> > >::find<unsigned long>(unsigned long const&)  (in libobjc.A.dylib) + 101  [0x7fff91230f57]
    + !             1 -[NSEvent dealloc]  (in AppKit) + 195  [0x7fff91bf1a72]
    + !               1 ReleaseEvent  (in HIToolbox) + 229  [0x7fff905fa3ff]
    + !                 1 CFRelease  (in CoreFoundation) + 1104  [0x7fff83433d80]
    + !                   1 objc_destructInstance  (in libobjc.A.dylib) + 109  [0x7fff9121ed4d]
    + !                     1 _os_lock_handoff_lock  (in libsystem_platform.dylib) + 23  [0x7fff8e0adc2c]
    + 10 ???  (in XUL)  load address 0x10b1db000 + 0x2131ad4  [0x10d30cad4]
    + ! 10 -[NSAppearance _drawInRect:context:options:]  (in AppKit) + 127  [0x7fff91bf9cde]
    + !   10 -[NSCompositeAppearance _callCoreUIWithBlock:]  (in AppKit) + 183  [0x7fff91a60e91]
    + !     10 __44-[NSAppearance _drawInRect:context:options:]_block_invoke  (in AppKit) + 64  [0x7fff91bf9d25]
    + !       10 CUIDraw  (in CoreUI) + 175  [0x7fff8711a992]
    + !         10 CUIRenderer::Draw(CGRect, CGContext*, __CFDictionary const*, __CFDictionary const**)  (in CoreUI) + 2341  [0x7fff87118065]
    + !           3 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 2016  [0x7fff87197132]
    + !           : 3 -[CUIThemeFacet drawInFrame:alpha:operation:isFocused:context:]  (in CoreUI) + 160  [0x7fff87179d46]
    + !           :   3 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 208  [0x7fff8717b9f9]
    + !           :     3 -[CUIThemeFacet _drawSpecificRenditionKey:rendition:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 476  [0x7fff8717bbe4]
    + !           :       3 -[CUIThemeFacet drawGradientInFrame:angle:alpha:operation:isFocused:keyAdjustment:context:]  (in CoreUI) + 767  [0x7fff8717aea7]
    + !           :         3 -[CUIThemeGradient drawInRect:angle:withContext:]  (in CoreUI) + 173  [0x7fff8717f368]
    + !           :           3 -[CUIThemeGradient drawFromPoint:toPoint:options:withContext:]  (in CoreUI) + 252  [0x7fff8717f5d9]
    + !           :             3 CGContextDrawShading  (in CoreGraphics) + 63  [0x7fff97886d7f]
    + !           :               3 ripc_DrawShading  (in libRIP.A.dylib) + 17702  [0x7fff8f3c25e5]
    + !           :                 3 RIPLayerBltShade  (in libRIP.A.dylib) + 1366  [0x7fff8f3c30fa]
    + !           :                   3 argb32_shade  (in CoreGraphics) + 570  [0x7fff978ae566]
    + !           :                     2 argb32_image_mark  (in CoreGraphics) + 8374,8359  [0x7fff97852318,0x7fff97852309]
    + !           :                     1 argb32_image_mark  (in CoreGraphics) + 8345  [0x7fff978522fb]
    + !           :                       1 DAplusdDA2127  (in CoreGraphics) + 142  [0x7fff97a59baa]
    + !           2 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 2840  [0x7fff8719746a]
    + !           : 1 CUICoreThemeRenderer::DrawWindowTitlebarSeparator(CUIDescriptor const*)  (in CoreUI) + 86  [0x7fff87197978]
    + !           : | 1 +[CUIThemeFacet assetExistsForRenditionKey:fromTheme:]  (in CoreUI) + 138  [0x7fff87178ca2]
    + !           : |   1 -[CUIStructuredThemeStore _canGetRenditionWithKey:isFPO:lookForSubstitutions:]  (in CoreUI) + 47  [0x7fff871a79aa]
    + !           : 1 CUICoreThemeRenderer::DrawWindowTitlebarSeparator(CUIDescriptor const*)  (in CoreUI) + 464  [0x7fff87197af2]
    + !           :   1 -[CUIThemeFacet drawInFrame:isFocused:context:]  (in CoreUI) + 137  [0x7fff87179c32]
    + !           :     1 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:isFocused:isFlipped:]  (in CoreUI) + 163  [0x7fff8717b91a]
    + !           :       1 -[CUIThemeFacet _drawSpecificRenditionKey:rendition:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 292  [0x7fff8717bb2c]
    + !           :         1 DrawThreePartElementFromRenditionWithOperation  (in CoreUI) + 233  [0x7fff87173697]
    + !           :           1 DrawThreePartImageWithOperation  (in CoreUI) + 2520  [0x7fff8717407e]
    + !           :             1 CGContextRestoreGState  (in CoreGraphics) + 32  [0x7fff97829ffc]
    + !           :               1 CGGStackRestore  (in CoreGraphics) + 59  [0x7fff9782a059]
    + !           :                 1 ???  (in libmozglue.dylib)  load address 0x10a9d4000 + 0x279b  [0x10a9d679b]
    + !           1 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 1558  [0x7fff87196f68]
    + !           : 1 -[CUIThemeFacet drawInFrame:isFocused:context:]  (in CoreUI) + 137  [0x7fff87179c32]
    + !           :   1 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:isFocused:isFlipped:]  (in CoreUI) + 163  [0x7fff8717b91a]
    + !           :     1 -[CUIThemeFacet _drawSpecificRenditionKey:rendition:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 594  [0x7fff8717bc5a]
    + !           :       1 DrawOnePartElementFromRenditionWithOperation  (in CoreUI) + 993  [0x7fff87172e78]
    + !           :         1 _CUITileImageWithOperation  (in CoreUI) + 365  [0x7fff8717658e]
    + !           :           1 CGContextDrawImages  (in CoreGraphics) + 204  [0x7fff97870e5d]
    + !           :             1 ripc_DrawImages  (in libRIP.A.dylib) + 4347  [0x7fff8f3ce01d]
    + !           :               1 RIPLayerBltImage  (in libRIP.A.dylib) + 1185  [0x7fff8f3c6491]
    + !           :                 1 ripl_Mark  (in libRIP.A.dylib) + 23  [0x7fff8f3c64f2]
    + !           :                   1 argb32_image  (in CoreGraphics) + 2441  [0x7fff9784cd41]
    + !           :                     1 argb32_mark  (in CoreGraphics) + 19951  [0x7fff978327ba]
    + !           :                       1 blt_pattern_blend_XXXX32  (in CoreGraphics) + 540  [0x7fff978756e5]
    + !           1 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 2568  [0x7fff8719735a]
    + !           : 1 CUICoreThemeRenderer::DrawWindowBottomBar(CUIDescriptor const*)  (in CoreUI) + 849  [0x7fff8718cad5]
    + !           :   1 -[CUIThemeFacet drawInFrame:isFocused:context:]  (in CoreUI) + 137  [0x7fff87179c32]
    + !           :     1 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:isFocused:isFlipped:]  (in CoreUI) + 163  [0x7fff8717b91a]
    + !           :       1 -[CUIThemeFacet _drawSpecificRenditionKey:rendition:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 476  [0x7fff8717bbe4]
    + !           :         1 -[CUIThemeFacet drawGradientInFrame:angle:alpha:operation:isFocused:keyAdjustment:context:]  (in CoreUI) + 767  [0x7fff8717aea7]
    + !           :           1 -[CUIThemeGradient drawInRect:angle:withContext:]  (in CoreUI) + 173  [0x7fff8717f368]
    + !           :             1 -[CUIThemeGradient drawFromPoint:toPoint:options:withContext:]  (in CoreUI) + 252  [0x7fff8717f5d9]
    + !           :               1 CGContextDrawShading  (in CoreGraphics) + 63  [0x7fff97886d7f]
    + !           :                 1 ripc_DrawShading  (in libRIP.A.dylib) + 17702  [0x7fff8f3c25e5]
    + !           :                   1 RIPLayerBltShade  (in libRIP.A.dylib) + 1366  [0x7fff8f3c30fa]
    + !           :                     1 argb32_shade  (in CoreGraphics) + 570  [0x7fff978ae566]
    + !           :                       1 argb32_image_mark  (in CoreGraphics) + 1518  [0x7fff97850850]
    + !           1 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 2771  [0x7fff87197425]
    + !           : 1 -[CUIThemeFacet drawInFrame:isFocused:context:]  (in CoreUI) + 137  [0x7fff87179c32]
    + !           :   1 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:isFocused:isFlipped:]  (in CoreUI) + 51  [0x7fff8717b8aa]
    + !           :     1 -[CUIThemeFacet _renditionForSpecificKey:]  (in CoreUI) + 103  [0x7fff87176f9b]
    + !           :       1 -[CUIStructuredThemeStore _canGetRenditionWithKey:isFPO:lookForSubstitutions:]  (in CoreUI) + 1072  [0x7fff871a7dab]
    + !           :         1 CFRelease  (in CoreFoundation) + 1397  [0x7fff83433ea5]
    + !           :           1 _os_lock_spin_lock  (in libsystem_platform.dylib) + 12  [0x7fff8e0ad7d6]
    + !           1 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 2990  [0x7fff87197500]
    + !           : 1 -[CUIThemeFacet drawInFrame:isFocused:context:]  (in CoreUI) + 137  [0x7fff87179c32]
    + !           :   1 -[CUIThemeFacet _drawSpecificRenditionKey:inFrame:context:isFocused:isFlipped:]  (in CoreUI) + 163  [0x7fff8717b91a]
    + !           :     1 -[CUIThemeFacet _drawSpecificRenditionKey:rendition:inFrame:context:alpha:operation:isFocused:isFlipped:]  (in CoreUI) + 710  [0x7fff8717bcce]
    + !           :       1 DrawNinePartElementFromRenditionWithOperation  (in CoreUI) + 484  [0x7fff871747cf]
    + !           :         1 objc_object::sidetable_release(bool)  (in libobjc.A.dylib) + 242  [0x7fff9121f288]
    + !           :           1 -[_CUINineImagePieces dealloc]  (in CoreUI) + 241  [0x7fff87172540]
    + !           :             1 object_dispose  (in libobjc.A.dylib) + 22  [0x7fff9121eccf]
    + !           :               1 objc_destructInstance  (in libobjc.A.dylib) + 124  [0x7fff9121ed5c]
    + !           :                 1 objc_object::sidetable_clearDeallocating()  (in libobjc.A.dylib) + 94  [0x7fff9121ede4]
    + !           :                   1 objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::find(DisguisedPtr<objc_object> const&)  (in libobjc.A.dylib) + 35  [0x7fff9121ee63]
    + !           :                     1 bool objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::LookupBucketFor<DisguisedPtr<objc_object> >(DisguisedPtr<objc_object> const&, std::__1::pair<DisguisedPtr<objc_object>, unsigned long> const*&) const  (in libobjc.A.dylib) + 86  [0x7fff912355c8]
    + !           1 CUICoreThemeRenderer::DrawWindowFrameStandardNew(CUIDescriptor const*)  (in CoreUI) + 3069  [0x7fff8719754f]
    + !             1 -[CUIThemeFacet renditionMetricsWithKeyAdjustment:]  (in CoreUI) + 125  [0x7fff8717befe]
    + !               1 -[CUIRenditionKey setValuesFromKeyList:]  (in CoreUI) + 280  [0x7fff8719cbd9]
    + !                 1 CUIRenditionKeySetValueForAttribute  (in CoreUI) + 190  [0x7fff871c4a31]
    + 9 ???  (in XUL)  load address 0x10b1db000 + 0x213a611  [0x10d315611]
    + ! 8 -[NSColorSpaceColor colorUsingColorSpaceName:device:]  (in AppKit) + 132  [0x7fff91b89397]
    + ! : 6 convertColorToColorSpace  (in AppKit) + 84  [0x7fff91b89678]
    + ! : | 2 convertColorToColorSpaceNamed  (in AppKit) + 388  [0x7fff91a95779]
    + ! : | + 2 CGColorTransformConvertColor  (in CoreGraphics) + 287  [0x7fff9781d2f1]
    + ! : | +   2 create_color  (in CoreGraphics) + 85  [0x7fff97809de5]
    + ! : | +     2 CGTypeCreateInstance  (in CoreGraphics) + 46  [0x7fff97809c1f]
    + ! : | +       2 _CFRuntimeCreateInstance  (in CoreFoundation) + 301  [0x7fff8342846d]
    + ! : | +         2 malloc_zone_malloc  (in libsystem_malloc.dylib) + 71  [0x7fff84bb75a1]
    + ! : | +           1 szone_malloc  (in libsystem_malloc.dylib) + 0  [0x7fff84bb75d3]
    + ! : | +           1 szone_malloc_should_clear  (in libsystem_malloc.dylib) + 292  [0x7fff84bb7705]
    + ! : | +             1 tiny_malloc_from_free_list  (in libsystem_malloc.dylib) + 32  [0x7fff84bb86dc]
    + ! : | 2 convertColorToColorSpaceNamed  (in AppKit) + 478  [0x7fff91a957d3]
    + ! : | + 1 CFRelease  (in CoreFoundation) + 1104  [0x7fff83433d80]
    + ! : | + ! 1 objc_destructInstance  (in libobjc.A.dylib) + 124  [0x7fff9121ed5c]
    + ! : | + !   1 objc_object::sidetable_clearDeallocating()  (in libobjc.A.dylib) + 94  [0x7fff9121ede4]
    + ! : | + !     1 objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::find(DisguisedPtr<objc_object> const&)  (in libobjc.A.dylib) + 35  [0x7fff9121ee63]
    + ! : | + !       1 bool objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::LookupBucketFor<DisguisedPtr<objc_object> >(DisguisedPtr<objc_object> const&, std::__1::pair<DisguisedPtr<objc_object>, unsigned long> const*&) const  (in libobjc.A.dylib) + 98  [0x7fff912355d4]
This happens with all  messages, not only message with attachments?
Severity: normal → major
Flags: needinfo?(bugzilla)
Keywords: perf
Automated Google searches never have attachments, just text plus HTML maybe CSS. 
So the bug is not at all requiring attachments to appear.
I have not noticed it with other mail that might have attachments as I use that gmail account only for reading the search results plus as a backup channel and test facility.



Would you like some of the debug log info I collected in 2015/6 when the same issues were first looked at by me (and continued  ever since)?
These are of the form (but not at same time or even when the bug was in progress):
1146348  17:05:28.996539    creating protocol instance to retry queued url:imap://***@imap.gmail.com:993/select>/INBO
1146352  17:05:28.996694    retrying url:imap://***@imap.gmail.com:993/select>/INBO
1147221  17:15:12.253820    exceeded connection cache limit:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147222  17:15:12.253830    queuing url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147223  17:15:12.253838    considering playing queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147224  17:15:12.253845    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147226  17:15:12.253883    exceeded connection cache limit:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147227  17:15:12.253890    failed creating protocol instance to play queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147228  17:15:12.254397    considering playing queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147229  17:15:12.254417    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1147231  17:15:12.254501    playing queued url:imap://***@imap.gmail.com:993/select>/[Gmail]/Sent Mai
1157905  17:15:13.660123    queuing url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157906  17:15:13.660128    considering playing queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157907  17:15:13.660132    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157909  17:15:13.660155    failed creating protocol instance to play queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157910  17:15:13.666145    considering playing queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157911  17:15:13.666161    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157913  17:15:13.666196    playing queued url:imap://***@imap.gmail.com:993/fetch>UID>/[Gmail]/Sent Mail>797
1157920  17:15:13.789266    exceeded connection cache limit:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1157921  17:15:13.789272    queuing url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1157922  17:15:13.789278    considering playing queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1157923  17:15:13.789282    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1157926  17:15:13.789313    exceeded connection cache limit:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1157927  17:15:13.789317    failed creating protocol instance to play queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1160355  17:15:14.032920    considering playing queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1160356  17:15:14.032937    creating protocol instance to play queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1160359  17:15:14.033000    playing queued url:imap://***@imap.gmail.com:993/folderstatus>/gmail mb
1162587  17:34:35.511578    creating protocol instance to retry queued url:imap://***@imap.gmail.com:993/select>/INBO
1162589  17:34:35.511921    retrying url:imap://***@imap.gmail.com:993/select>/INBO
1162922  18:03:51.609452    85596800:imap.gmail.com:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPE
1162926  18:03:51.610188    85596800:imap.gmail.com:NA:ProcessCurrentURL:imap://***@imap.gmail.com:993/select%3E/INBOX: = currentUr
1162943  18:06:21.793819    85596800:imap.gmail.com:NA:TellThreadToDie: close socket connectio.
1162945  18:06:21.795363    85596800:imap.gmail.com:NA:ProcessCurrentURL: aborting queued url




And log data:
1886780608[100355240]: SMTP entering state: 5
1886780608[100355240]: SMTP Send: RCPT TO:<cwinte@gmail.com>
1886780608[100355240]: SMTP entering state: 0
1886780608[100355240]: SMTP Response: 250 <cwinte@gmail.com> recipient ok
1886780608[100355240]: SMTP entering state: 6
1886780608[100355240]: SMTP Send: DATA
1886780608[100355240]: SMTP entering state: 0
1886780608[100355240]: SMTP Response: 354 enter mail, end with "." on a line by itself
1886780608[100355240]: SMTP entering state: 7
1886780608[100355240]: SMTP entering state: 8
1886780608[100355240]: SMTP Send: .
1886780608[100355240]: SMTP entering state: 0
1886780608[100355240]: SMTP Response: 250 dqxl1r00B104WgN01qxlF5 mail accepted for delivery
1886780608[100355240]: SMTP entering state: 9
1886780608[100355240]: SMTP Send: QUIT
1886780608[100355240]: SMTP entering state: 0
1886780608[100355240]: SMTP entering state: 0
1886780608[100355240]: SMTP Response: 221 know-smtprelay-10-imp bizsmtp closing connection
1886780608[100355240]: SMTP entering state: 10
1886780608[100355240]: SMTP entering state: 12
1886780608[100355240]: SMTP connection error quitting 804b0002, ignoring 

And also stream data:
6  15:37:57.803543    18962000:imap.gmail.com:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
8  15:37:57.803606    18962000:imap.gmail.com:NA:ProcessCurrentURL:imap://***@imap.gmail.com:993/select%3E/INBOX: = currentUrl
10  15:37:58.100947    18962000:imap.gmail.com:NA:CreateNewLineFromSocket: * OK Gimap ready for requests from 86.26.104.46 x9mb426702283wmf
11  15:37:58.101192    18962000:imap.gmail.com:NA:SendData: 1 capability
16  15:37:58.122555    18962000:imap.gmail.com:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4rev1 UNSELECT IDLE NAMESPACE QUOTA ID XLIST CHILDREN X-GM-EXT-1 XYZZY SASL-IR AUTH=XOAUTH2 AUTH=PLAIN AUTH=PLAIN-CLIENTTOKEN AUTH=OAUTHBEARER AUTH=XOAUTH
18  15:37:58.124972    18962000:imap.gmail.com:NA:CreateNewLineFromSocket: 1 OK Thats all she wrote! x9mb426702283wmf
42  15:37:58.479440    18962000:imap.gmail.com:NA:SendData: Logging suppressed for this command (it probably contained authentication information)
353  15:37:59.524644    18962000:imap.gmail.com:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4rev1 UNSELECT IDLE NAMESPACE QUOTA ID XLIST CHILDREN X-GM-EXT-1 UIDPLUS COMPRESS=DEFLATE ENABLE MOVE CONDSTORE ESEARCH UTF8=ACCEPT LIST-EXTENDED LIST-STATUS APPENDLIMIT=35882577
355  15:37:59.524763    18962000:imap.gmail.com:NA:CreateNewLineFromSocket: 2 OK *** authenticated (Success)
357  15:37:59.526001    18962000:imap.gmail.com:A:SendData: 3 namespace
359  15:37:59.645075    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * NAMESPACE (("" "/")) NIL NIL
361  15:37:59.645970    18962000:imap.gmail.com:A:CreateNewLineFromSocket: 3 OK Success
362  15:37:59.645983    18962000:imap.gmail.com:A:SendData: 4 COMPRESS DEFLATE
376  15:37:59.765247    18962000:imap.gmail.com:A:CreateNewLineFromSocket: 4 OK Success
377  15:37:59.765303    18962000:imap.gmail.com:A:SendData: 5 ID ("name" "Thunderbird" "version" "45.1.1")
458  15:37:59.885267    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * ID ("name" "GImap" "vendor" "Google, Inc." "support-url" "https://support.google.com/mail" "version" "gmail_imap_160726.11_p0" "remote-host" "86.26.104.46")
460  15:37:59.885326    18962000:imap.gmail.com:A:CreateNewLineFromSocket: 5 OK Success
461  15:37:59.886065    18962000:imap.gmail.com:A:SendData: 6 xlist "" "%"
463  15:38:00.010708    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Deleted Items"
465  15:38:00.010749    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Drafts"
467  15:38:00.010767    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren \Inbox) "/" "Inbox"
469  15:38:00.010786    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Junk E-mail"
471  15:38:00.010803    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Notes"
473  15:38:00.010818    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Sent Items"
475  15:38:00.010834    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "Templates"
477  15:38:00.010849    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasChildren \Noselect) "/" "[Gmail]"
479  15:38:00.010865    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasChildren \Noselect) "/" "[Imap]"
481  15:38:00.010881    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasNoChildren) "/" "gmail mbx"
483  15:38:00.010914    18962000:imap.gmail.com:A:CreateNewLineFromSocket: * XLIST (\HasChildren) "/" "vmail"
485  15:38:00.010929    18962000:imap.gmail.com:A:CreateNewLineFromSocket: 6 OK Success

Trouble is that I am full time on other tasks at present and back then was looking into a number of problems with a number of ISP connections so there are multiple streams of data in some logs that I only processed as far as I needed at the time. I no longer have the overall notes on what I was doing when & why, nor is it obvious where a spin event was although I have files with some Thunderbird state dumps or traces when this bug was seen and might be able to find some corresponding detail logs.

Or I could set up a specific set of logs now and just capture the exact event. I can't promise how soon I could get that done.
Flags: needinfo?(bugzilla)
Attached file comboSort_Gmail_only
Combines shell>top reports on TB activity level with processed summary of gmail interactions. Plus js stack dumps at end (though a different cause). Data 4 to 5 Dec 2015when I was first looking into this issue...
Attached file smpl lo+hi combo.xlsx
Here is an event on 5 Dec 2015 where TB went to 18% CPU while doing very little and slow downloading a similar gmail (I suppose).
I have XL file with comparison of a normal activity sampling (from Activity Monitor) and during the hiCPU/bug-issue window,
 the 2 are laid out beside each other to compare where the stack dived off deeper etc.
May not be relevant, may be the exact issue!
Let's see what someone else has to say before collecting more data.  
However, please briefly describe how these "google search" html emails are generated.
Flags: needinfo?(bugzilla)
These are emails generated by saved searches on google. However I suspect that any plain text email of a similar size would cause the same issues, I will see if I can create one... and post info about that soon. Thanks !
Flags: needinfo?(bugzilla)
A bit more on these typical gmail search emails. I get 2 types, half are relatively short, 50kb and 5 to 10 items of news. These load very fast.
The longer ones may be 150-200kb and 40-70 items. I think there is a fixed payload of the css and common code whatever google add. IF TB has recently been restarted these load fine, if it has run more than a day or so then it will likely go into the slow mode... The cursor spins and cpu use shoots up for the duration.

Side note: I'd love to find a way to apply my own styles over their structure as the heads take too much space. Have looked a bit at dev tools in Mozilla Firefox etc but not got close yet!
Self testing is not straightforward. I also use this gmail account to stop and filter copies of my mail in and out. Rules on gmail servers relocate 99% of my mail to and from me with an archival tag system I set up years ago. This means very little remains in my in box. So if I send an email to that account from another email system of mine it sees that as from me and puts it in a sent mail folder (since I did send it, but with another ISP account) - for my long term archival records.
So the test messages arrive in that Sent "folder" on gmail and even 244k of plain text displays in a flash.
So it seems it is not size.

Now I don't know if it google doing something extra but when I use TB to read and mark these search summaries from google (on their gmail system) when I click delete they do seem to fully disappear. I can't find them... 
(Interestingly if I do the same after reading them on the phone or iPad using Mail the option is not delete but "archive", they still seems to evaporate!) I cannot see any rule of mine running on gmail servers that would cause this "delete google search results" behaviour.

THOUGHT as there are rules running on gmail servers when and how do they announce mail as arriving? Only once it has passed all the filter rules I assume.

JUST NOTICED after click on the TB gmail inbox there was a 20-30s delay with TB cursors spinning waiting to eventually show there was no mail at all in the gmail inbox. (I do not hide read items or anything, just all mail moved or deleted). TB cpu usage was 15-18% which is high as it gets on my machine. What could TB be doing? Via webmail gmail was happily showing no mail in the inbox, no issues. The 4 test mails I sent myself were already tucked away with the "Sent" label in gmail account.

SUMMARY at present I cannot replicate the bug at will as I have no copy of the google search mails and a large text file does not seem to cause the bug. Maybe it is TB reading an emails code/html/css and hitting difficulties. I assumed it just downloaded (done), then displayed it(done). I never see these mails arrive bit by bit.
I wait with spinner, 10-20s, then it displays fast (under 1s).
from net traffic I know the problem emails come in at 1kb per second or less during these problems, lots of little packets and pauses
There are complications arising from the different ways iOS, Mail, webmail and TB each name and use tags within gmail accounts for folders/junk/spam/archival/deleted_items/sent/sent_items etc. 
I have, over the years, been trying to harmonise and collate mail in a consistent way as far as I can despite these issues.
It is not simple to deal with I'm sure!


Oh, more accurately, it is "Google Alerts" I am using. I have found just one old one from 2015 so far in the "archives"
Looking at the imap log snippet in comment 3 above, it looks like tb can't find a non-busy free connection to use. By default there are 5 connections (see advanced server setting and make sure it is set to at least 5 for your gmail account).

Also, you mention in comment 10 that you see lot of small packets. I have only seen disabling this help for multi-megabyte messages but tb has a feature called "chunking" where a large message is chopped into smaller 64k "chunks" when fetched. This feature, which is on by default, can cause a big slow down fetching messages. You might try turning it off by going to the config editor (advanced preferenced) and setting mail.server.default.fetch_by_chunks to false and restarting tb. However you say in comment 1 that the problem messages are 100-200k so the chunking shouldn't be a problem for that size messages, but disabling it is worth a try (and, in my opinion, it really is a useless feature for the most part).

Sorry, I'm not real familiar with apple jargon. Is a "spin dump" basically a crash or lock-up of tb?

Also, have you possibly accessed the same emails on a non-apple device and see the same problem? (There is only a small amount of tb/mozilla code that is unique to osx AFAIK.)

I only have an old macbook air running an old osx version that is limping along that I can fire up to do a test. Can you attach to this bug one of the "bad" emails when the problem occurs so I can see if I can duplicate the problem?
Hi Gene,
Spin dump is where OS detects bad operating conditions of apps, in this case too many wakes (e.g. like 260 per second) over a period, it profiles the stack and thread states similar to the manual one as shown in my listing #2 starting 

"When I say data read at fault I mean that polling the data is slow (bandwidth is fine) but TB is only asking slowly or having security or other issues make it slow. Here is a sample while spinning back in July I have on hand:
Path:            /Applications/Thunderbird.app/Contents/MacOS/thunderbird
Load Address:    0x10a9cb000
Identifier:      org.mozilla.thunderbird"

The app itself keeps running, the well informed user should be aware what is going on (I aspire to that!).

I had looked at max connections and read about problems with that some years ago, just checking I have it at 2 so will try 5. I thought I had set it high but maybe I read a warn to try it low. I should have tried out all those options back in 2015/6 but vague on it now!   Went looking and yeah, seeing advice/comments like:
        "Unable to connect to your IMAP server.
        You may have exceeded the maximum number of connections to this server.
        If so use the Advanced IMAP Server Settings dialog to reduce the 
        number of cached connections."
That REDUCE does sound counter intuitive!

I think a fire up and test will not see the issue as it only appears after lots of TB exercise, typically 24+ hours before it appears so if I restart every day I will not see it often. I had that automated but it was a pain if I was not around at the time etc as it needed to check I was OK to quite & restart TB.
However I do want to isolate a causative email, reproducible sequence.
         

Looking at stack frames going 50-100 deep on same call in draw-bits type routines I guessed back in 2015 there was some fault and recursion in code doing the spinning wait icons...
I just went to look in TB and had another 30s wait with spin icons while gmail Inbox worked out there was no mail at all. I took a quick sample of the process threads... Will post this app sample for anyone who knows the architecture well enough to read it!
The shape of the listing has changed from what it was years ago I think... 
This delay is a new symptom to me, but similar feel and maybe cause...
This is a sample from activity monitor while TB took 30s to check the gmail inbox was still empty :-(
It dives off in some code areas that the normal state (will upload next) does not and looks much flatter.
when TB not in a spin!
Have updated to 5 connections (from 2) and turned off chunking, will see how it performs...
Just had a quick look and all the new code is running XUL descriptions of UI, and the low level display code looks rewritten so it is perhaps elsewhere I should be looking since the app still works, same behaviour re these emails and yet the code is re-engineered so much.

Just had another long wait for empty inbox, almost no data ( a few k) being exchanged over internet to gmail-imap.l.google.com in all that time. SO the connections and chunking seem not implicated.
I don't see any reference to "mail" or "imap" in any of the dumps you have provided. So it appears that they are showing mostly the mozilla code that tb uses for ui and graphical purposes. I really don't know anything about that code so others should probably look at your attachments and determine if they look normal or not.

Ok, thanks for defintion on spin dump. Also, I assume when you say it takes tb 30s to check new email you are seeing the "beachball" spinning for 30s. I don't know how many emails you have in the inbox but when a mailbox (folder) is accessed tb often fetches the flags for each email. If there are many thousands of emails there the fetch could take a while depending on network speed. You say the inbox is "empty" but not sure if you mean there are no emails there or if there are no *new* emails. What happens when you access the gmail "All Mail" folder (assuming you are subscribed to it)? All Mail will have a lot of emails in it unless you have deleted most of them.

To check this, maybe you could attach an imap log showing the activity that occurs while "spinning" on a folder, Inbox or whatever mailbox has a problem. Details on how to do this can be found by google on "thunderbird imap log". Would be curious to know if tb is having problems obtaining a connection like you showed in the previous log you did in comment 3.

Some ISPs only allow a fixed number of imap connection from a given address. That's why in some cases you might see a pop-up error about too many connections. I don't think google has this restriction so setting it 5 is OK, at least I've never seen a problem with gmail at 5.

Also, the chunking won't have an effect until you receive a huge email. So it's too soon to say whether having it disabled helps or not.
It's not the MacOS coloured beachball but TB's own blue tail chasing spinner that I see.
There are zero mails in that inbox, new or old - read or unread, as seen with TB or webmail access. I'm a bit unsure about the reality in this case since gmail is more of a db with tags etc so there might be some scanning although I believe that is done within gmail server and it processes queries and presents email data for the relevant "folder/group". There are only 2200 mails even in the All Mail group, the recent month or two of old emails that I have purged of spam etc.

And note that it I quit and restart TB it seems to processes fast without delays...
I'm on UK time and suspect we have a time lag! I can set up to do the logging but it will be 15hours from now before I can have expect results.

Back in 2015/6 there were definite associated tx to and from gmail servers, which I processed and abbreviated dull chunks of to just a "." for "keeping alive checks" or "emailmsg" where I could see whole start, body,end sequences.

This latest 30s with empty Inbox is new to me, certainly seems to be almost no IP traffic to google - just a few kb.

OK I've sat up after midnight and dug a bit...
imap gmail just before GMT00:09:55 on 6DEC:
/Users/colinwinuser/imap.log
2018-12-06 00:09:04.291637 UTC - [35352:Unnamed thread 0x12ba84680]: I/IMAP 0x12922a800:imap.virginmedia.com:S-INBOX:CreateNewLineFromSocket: + idling
2018-12-06 00:09:46.141001 UTC - [35352:Main Thread]: D/IMAP proposed url = INBOX folder for connection INBOX has To Wait = FALSE can run = TRUE
2018-12-06 00:09:46.141361 UTC - [35352:Unnamed thread 0x12ba84c70]: I/IMAP 0x12d6d6000:imap.gmail.com:S-INBOX:SendData: DONE

#note time gap here, then it seem to enumerate the mail box properties and abilities normally

2018-12-06 00:10:04.279854 UTC - [35352:Unnamed thread 0x12ba84c70]: D/IMAP ReadNextLine [stream=0x13048e030 nb=0 needmore=1]
2018-12-06 00:10:04.279872 UTC - [35352:Unnamed thread 0x12ba84c70]: I/IMAP 0x12d6d6000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: clearing IMAP_CONNECTION_IS_OPEN - rv = 804b000e
2018-12-06 00:10:04.280454 UTC - [35352:Unnamed thread 0x12ba84c70]: I/IMAP 0x12d6d6000:imap.gmail.com:S-INBOX:TellThreadToDie: close socket connection
2018-12-06 00:10:04.280466 UTC - [35352:Unnamed thread 0x12ba84c70]: I/IMAP 0x12d6d6000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: (null)
2018-12-06 00:10:04.281333 UTC - [35352:Main Thread]: I/IMAP creating protocol instance to retry queued url:imap://xxx@gmail.com@imap.gmail.com:993/select>/INBOX
...
50 lines or so then ends up with
...
2018-12-06 00:10:04.935243 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:A:CreateNewLineFromSocket: * OK [HIGHESTMODSEQ 3468593]
2018-12-06 00:10:04.935250 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=0 needmore=1]
2018-12-06 00:10:04.935253 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=45 needmore=0]
2018-12-06 00:10:04.935256 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:A:CreateNewLineFromSocket: 5 OK [READ-WRITE] INBOX selected. (Success)
2018-12-06 00:10:04.935447 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:SendData: 6 getquotaroot "INBOX"
2018-12-06 00:10:04.969800 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=24 needmore=0]
2018-12-06 00:10:04.969807 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: * QUOTAROOT "INBOX" ""
2018-12-06 00:10:04.969820 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=39 needmore=0]
2018-12-06 00:10:04.969822 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: * QUOTA "" (STORAGE 4880634 15728640)
2018-12-06 00:10:04.969894 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=14 needmore=0]
2018-12-06 00:10:04.969898 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: 6 OK Success
2018-12-06 00:10:04.974650 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:SendData: 7 IDLE
2018-12-06 00:10:05.004910 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x11c26f7c0 nb=10 needmore=0]
2018-12-06 00:10:05.004955 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b9d800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: + idling
then on to other tasks...
In that time gap nothing seemed to happen and I just inserted the space and note in log, the TB spinner spun, cpu was fairly busy doing it. Looks like the UI busy, no IMAP tx?
Also no other syslog error (e.g. console) until Safari 2s later:
Dec  6 00:09:07 ··· Safari[2016]: tcp_connection_.......

I am watching imap and syslog interleaved in lnav.
Next morning same behaviour. 
I synched click onto the gmail Inbox carefully for exact minute 09:54:00 and there was then the blue tail chasing wait icon on top left of window tab and the rotating blue/white quarters mouse pointer for 24 seconds or so. The Imap log showed more or less nothing done in the first 23 secs, it then proceeds normally completing in 0.5s...
Just the start:

09:54:00.308662 UTC - [35352:Main Thread]: D/IMAP proposed url = INBOX folder for connection INBOX has To Wait = FALSE can run = TRUE
09:54:00.309084 UTC - [35352:Unnamed thread 0x1257d2d90]: I/IMAP 0x11d38e000:imap.gmail.com:S-INBOX:SendData: DONE
09:54:23.562194 UTC - [35352:Unnamed thread 0x1257d2d90]: D/IMAP ReadNextLine [stream=0x11a5cd450 nb=0 needmore=1]
09:54:23.562210 UTC - [35352:Unnamed thread 0x1257d2d90]: I/IMAP 0x11d38e000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: clearing IMAP_CONNECTION_IS_OPEN - rv = 804b000e
09:54:23.562945 UTC - [35352:Unnamed thread 0x1257d2d90]: I/IMAP 0x11d38e000:imap.gmail.com:S-INBOX:TellThreadToDie: close socket connection
09:54:23.562956 UTC - [35352:Unnamed thread 0x1257d2d90]: I/IMAP 0x11d38e000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: (null)
09:54:23.563645 UTC - [35352:Main Thread]: I/IMAP creating protocol instance to retry queued url:imap://xxx@gmail.com@imap.gmail.com:993/select>/INBOX
09:54:23.563956 UTC - [35352:Main Thread]: I/IMAP retrying  url:imap://xxx@gmail.com@imap.gmail.com:993/select>/INBOX
09:54:23.563989 UTC - [35352:Unnamed thread 0x1257d4a10]: D/IMAP ImapThreadMainLoop entering [this=0x126d9d000]
09:54:23.564624 UTC - [35352:Main Thread]: I/IMAP 0x126d9d000:imap.gmail.com:NA:SetupWithUrlCallback: clearing IMAP_CONNECTION_IS_OPEN
09:54:23.564641 UTC - [35352:Unnamed thread 0x1257d2d90]: D/IMAP ImapThreadMainLoop leaving [this=0x11d38e000]
09:54:23.564701 UTC - [35352:Unnamed thread 0x1257d4a10]: I/IMAP 0x126d9d000:imap.gmail.com:NA:ProcessCurrentURL: entering
09:54:23.564709 UTC - [35352:Unnamed thread 0x1257d4a10]: I/IMAP 0x126d9d000:imap.gmail.com:NA:ProcessCurrentURL:imap://xxx%40gmail%2Ecom@imap.gmail.com:993/select%3E/INBOX:  = currentUrl
09:54:23.649133 UTC - [35352:Unnamed thread 0x1257d4a10]: D/IMAP ReadNextLine [stream=0x1252dfa00 nb=69 needmore=0]
09:54:23.649143 UTC - [35352:Unnamed thread 0x1257d4a10]: I/IMAP 0x126d9d000:imap.gmail.com:NA:CreateNewLineFromSocket: * OK Gimap ready for requests from 81.109.252.215 n12mb172786491edb
09:54:23.649895 UTC - [35352:Unnamed thread 0x1257d4a10]: I/IMAP 0x126d9d000:imap.gmail.com:NA:SendData: 1 capability
Might the tcp details help? I can set logging for that too I think
I suspect there is some time-out clearing of connection that must elapse before the behaviour can recur
(and dimly recall discussion about keep-alive/polling options in 2015??)
OK just got one of the emails that have been at the root of all this.
++++++++++++++++++++++++++++++
It took around 2 minutes 30s from when I clicked on it! In fact I was just believing I failed to click it!!
203kb email, will upload it
seems 5100 lines of data transfer in 157secs, about 4 per second only.

end other ISP...
10:34:52.754703 UTC - [35352:Unnamed thread 0x12ba82410]: D/IMAP ReadNextLine [stream=0x11a7d8700 nb=10 needmore=0]
10:34:52.754712 UTC - [35352:Unnamed thread 0x12ba82410]: I/IMAP 0x128469000:imap.virginmedia.com:S-WIP to do/WPTC todo:CreateNewLineFromSocket: + idling


Start gmail inbox:

10:34:52.789430 UTC - [35352:Main Thread]: D/IMAP proposed url = [Gmail]/Sent Mail folder for connection INBOX has To Wait = FALSE can run = FALSE
10:34:52.789517 UTC - [35352:Unnamed thread 0x1257d2410]: I/IMAP 0x10a74b800:imap.gmail.com:A:SendData: 10 logout
10:34:52.789635 UTC - [35352:Unnamed thread 0x12682ba10]: D/IMAP ImapThreadMainLoop entering [this=0x126b92000]
10:34:52.790979 UTC - [35352:Main Thread]: I/IMAP 0x126b92000:imap.gmail.com:NA:SetupWithUrlCallback: clearing IMAP_CONNECTION_IS_OPEN
10:34:52.791009 UTC - [35352:Unnamed thread 0x1257d2410]: I/IMAP 0x10a74b800:imap.gmail.com:A:TellThreadToDie: close socket connection
10:34:52.791016 UTC - [35352:Unnamed thread 0x1257d2410]: D/IMAP ImapThreadMainLoop leaving [this=0x10a74b800]
10:34:52.791063 UTC - [35352:Unnamed thread 0x12682ba10]: I/IMAP 0x126b92000:imap.gmail.com:NA:ProcessCurrentURL: entering
10:34:52.791071 UTC - [35352:Unnamed thread 0x12682ba10]: I/IMAP 0x126b92000:imap.gmail.com:NA:ProcessCurrentURL:imap://xxx%40gmail%2Ecom@imap.gmail.com:993/folderstatus%3E/%5BGmail%5D/Sent%20Mail:  = currentUrl
10:34:52.903126 UTC - [35352:Unnamed thread 0x12682ba10]: D/IMAP ReadNextLine [stream=0x1252e0f80 nb=69 needmore=0]
10:34:52.903135 UTC - [35352:Unnamed thread 0x12682ba10]: I/IMAP 0x126b92000:imap.gmail.com:NA:CreateNewLineFromSocket: * OK Gimap ready for requests from 81.109.252.215 k79mb115499302wmd
10:34:52.903429 UTC - [35352:Unnamed thread 0x12682ba10]: I/IMAP 0x126b92000:imap.gmail.com:NA:SendData: 1 capability
10:34:52.926633 UTC - [35352:Unnamed thread 0x12682ba10]: D/IMAP ReadNextLine [stream=0x1252e0f80 nb=173 needmore=0]
does setup then 11300 lines of ReadNextLine & CreateNewLineFromSocket pairs
.
.
.
ENDS AS..


10:37:25.657081 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=20 needmore=0]
10:37:25.657082 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: </td></tr></table>
10:37:25.657099 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=14 needmore=0]
10:37:25.657101 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: <![endif]-->
10:37:25.657103 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=27 needmore=0]
10:37:25.657104 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket:   </div>  </body> </html>
10:37:25.657106 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=34 needmore=0]
10:37:25.657107 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: --0000000000003ee0ab057c579d33--
10:37:25.657180 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=3 needmore=0]
10:37:25.657184 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: )
10:37:25.657187 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
10:37:25.657586 UTC - [35352:Main Thread]: D/IMAP Updating stored message size from 208070, new size 208070
10:37:25.657711 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=15 needmore=0]
10:37:25.657714 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: 18 OK Success
10:37:25.712839 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:SendData: 19 IDLE
10:37:25.740781 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=10 needmore=0]
10:37:25.740787 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: + idling
10:37:27.673956 UTC - [35352:Main Thread]: D/IMAP proposed url = INBOX folder for connection INBOX has To Wait = FALSE can run = TRUE
10:37:27.674454 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:SendData: DONE
10:37:27.696425 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=33 needmore=0]
10:37:27.696434 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: 19 OK IDLE terminated (Success)
10:37:27.696515 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering
10:37:27.696748 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxx%40gmail%2Ecom@imap.gmail.com:993/addmsgflags%3EUID%3E/INBOX%3E19782%3E1:  = currentUrl
10:37:27.697218 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:SendData: 20 uid store 19782 +Flags (\Seen)
10:37:28.016784 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=37 needmore=0]
10:37:28.016793 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: * 2 FETCH (FLAGS (\Seen) UID 19782)
10:37:28.016914 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=37 needmore=0]
10:37:28.016918 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: * 2 FETCH (UID 19782 FLAGS (\Seen))
10:37:28.016995 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=0 needmore=1]
Looking at the time in microsecs of every 400th transfer line there is variation and one huge jump which is actually 2minutes 5.391 secs (we only see the .391s in my list) but note transfers after faster after this delay :
6655
2200
2328
1631
8620
1197
1315
1774
1881
906
1591
2237
1119
391034
19327
4987
814
893
825
774
971
711
767
745
801
778
828
I'll go look at this break in transfer point next...
Ummm, looks like the whole email gets sent (but not displayed as I never saw it), then the 2 minute delay, then it gets sent again and then shown (when I lost faith in first click and clicked on it a second time). The Inbox was showing 2 unread Google Alerts 47k and 203k, no other emails at all.

I tried the second in list first, 203k, as that is normally the failure where the small one typically performs OK.

[
Evidence first head line in the email is sent:

10:35:20.226884 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: t:20px"> <span itemprop=3D"name">Remodelling Japan&#39;s climate policy</sp=

then again:

10:37:25.653969 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: t:20px"> <span itemprop=3D"name">Remodelling Japan&#39;s climate policy</sp=
]
This is consistent with each mail being sent relatively quickly

I could post the entire send of this one mail (x2) but just this sequence is 11,600 lines 1.8Mb
I think the interesting point is the end of receive where something gets lost or has timed out?



This point seems to show the first receive ending OK, going idle then swapping to another account after 2 minutes to poll that:


10:35:51.570893 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: 12 OK Success
10:35:51.570917 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:SendData: 13 UID fetch 19783:* (FLAGS)
10:35:51.623248 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=32 needmore=0]
10:35:51.623258 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: * 2 FETCH (UID 19782 FLAGS ())
10:35:51.623277 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=15 needmore=0]
10:35:51.623280 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: 13 OK Success
10:35:51.627168 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:SendData: 14 IDLE
10:35:51.648221 UTC - [35352:Unnamed thread 0x1257d4420]: D/IMAP ReadNextLine [stream=0x1250eedf0 nb=10 needmore=0]
10:35:51.648228 UTC - [35352:Unnamed thread 0x1257d4420]: I/IMAP 0x119832000:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: + idling
10:37:03.911693 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x125706780 nb=17 needmore=0]
10:37:03.911778 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:CreateNewLineFromSocket: * OK Still here
10:37:03.912124 UTC - [35352:Main Thread]: D/IMAP proposed url = INBOX folder for connection WIP to do/WPTC todo has To Wait = FALSE can run = FALSE
10:37:03.912143 UTC - [35352:Main Thread]: D/IMAP proposed url = INBOX folder for connection INBOX has To Wait = FALSE can run = TRUE
10:37:03.912331 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:SendData: DONE
10:37:03.959367 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x125706780 nb=60 needmore=0]
10:37:03.959379 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:CreateNewLineFromSocket: 1785 OK Idle completed (120.166 + 120.149 + 120.165 secs).
10:37:03.959458 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:ProcessCurrentURL: entering
10:37:03.959719 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:ProcessCurrentURL:imap://xxx%40ntlworld%2Ecom@imap.virginmedia.com:993/select%3E/INBOX:  = currentUrl
10:37:03.960140 UTC - [35352:Unnamed thread 0x1257d22e0]: I/IMAP 0x126b93800:imap.virginmedia.com:S-INBOX:SendData: 1786 noop
10:37:04.002912 UTC - [35352:Unnamed thread 0x1257d22e0]: D/IMAP ReadNextLine [stream=0x125706780 nb=46 needmore=0]
If you want to try this email I suggest I send it to you as an email... is there a way to PM me your email without widely advertising it? (I have hidden mine to xxx above where I spot it). That way it arrives in a normal manner even if your ISP may be have differently, 

but hopefully someone with a gmail account??
Most TB hangs reading mails do NOT result in spin dump level delay (just to be clear) here are the last ones since I cleared my logs...
thunderbird_2018-11-08-120350_Colins-MBP115.wakeups_resource.diag
thunderbird_2018-11-18-233056_Colins-MBP115.wakeups_resource.diag
thunderbird_2018-11-19-140647_Colins-MBP115.wakeups_resource.diag
thunderbird_2018-11-28-094851_Colins-MBP115.cpu_resource.diag
thunderbird_2018-11-28-122217_Colins-MBP115.wakeups_resource.diag
thunderbird_2018-12-04-135522_Colins-MBP115.wakeups_resource.diag
But some do and many have a very long delay that is unsettling and maybe points to deeper problems.
I haven't read everything you wrote above but looks like good info. I think you asked for my gmail address to send the test msg. It is gd.smth@gmail.com  (the 'i' is really not there, not a typo). 

Looks like when you click on Inbox tb has lost the connection to gmail. The error code is NS_ERROR_NET_TIMEOUT. 

More to come...
Are you saying that the large gmail email is fetched twice? Are you also saying that the other account (virginmedia) appears to be blocking the 2nd fetch of the large message? It appears that the viginmedia account goes into IDLE for a while and it sends a normal "* OK Still here" untagged response. Then tb stops IDLE (sends DONE) and polls for new mail, probably because the "check for new mail" timer has expired and goes back to IDLE. All this is normal, but then the gmail message is fetched again which is not normal (even if you click on the get new mail again redundantly).

If this is true then I probably need to see the full log, at least from when the first fetch finishes and when then 2nd fetch of the same message starts again. If activities of the other account are in between them that is OK. Please post the minimally edited log file that shows this as an attachment. Feel free to add annotations inside the log file to explain what you were doing at various times if you can (mark them with unique preamble like "cwinte: I clicked get new mail here".

Also, If possible, OK to go ahead and send the large message to my gmail so I can see what happens here.  Thanks.
Yes, I'm 99% sure fetched twice though ui never displayed it. There was a timeout I think, but after the virgin media mailboxes had been checked, so not blocked by the virginmedia account. 
I am unused to looking at the logs so you will probably make a better job of it, have tools etc maybe. I'll pass you a copy of the full log file and will forward the email in question. I do not have absolute timing notes of what I did when but I think the iMap log shows the sequence and gaps. TBH I'm not sure if I clicked just as the timeout ended or did something that was causative.
My hazy recollection is that I waited about 2mins, went from the large gmail email to the virginmedia account next to see if that produced action (maybe when the vm mailboxes were enumerated), then wen to the gmail email again... SO with that rough sequence I think it might be better for me not to annotate in case I mislead and foul up the evidence!!

I think that it is odd that cpu goes relatively high during these timeouts, and that I can get long timeouts even when the gmail Inbox is totally empty. All these are mentioned above.

And thank YOU. I have been intending to get to grips with or contribute something to the issue that has been lurking for some years!
Do your mailboxes (folders) have offline storage? If you don't know what I mean then you probably do since having a local storage of all your emails is the default. I do see the 2 minutes gap and where you went to vm account and then back to gmail. I see this line before tb re-fetched the large email:

10:37:25.434192 UTC - [35352:Main Thread]: W/IMAP ReadFromMemCache size mismatch for imap://xxx%40gmail%2Ecom@imap.gmail.com:993/fetch%3EUID%3E/INBOX%3E19782: message 208070, cache 0
 
This may indicate a problem reading from memory cache if you don't have offline file storage. The size mismatch may be causing the re-fetch, not sure. Also, when with just memory cache usage (no offline storage) a issue I have observed is that sometimes the same message is fetched twice. 

The memory cache is used to store recently viewed message when you don't store them to the file. The offline storage files are located in you profile area under folder ImapMail. If a folder has offline storage you will see two files <foldername>.msf and <foldername>. The <foldername> file (no extension) is the offline storage and contain the text for each email in the folder.

You may also know that the offline storage can be enable/disabled on a per folder basis using the tb gui. 

I never received the gmail alert message you said you would forward. Of course, I did receive the email containing the log.
Last first. I sent both log and the larger email at the same time and did receive a copy of the large  email (by cc) myself though it did not exhibit any problems when I looked at it. 
It did arrive 330k or so, 50% bigger than what I forwarded. That seems odd, though I have not extracted the 2 files to find the differences - a bit extra header is needed but that should be a few k surely. In fact I also forwarded this received email to you as well, I assume that also did not arrive.
Maybe it was slow to arrive as this am I see (from last night, about 10pm GMT you are on PST -8? so 2pm yesterday pm?):

             This is a Return Receipt for the mail that you sent to gd.smth@gmail.com.

              Note: This Return Receipt only acknowledges that the message was displayed
              on the recipient's computer. There is no guarantee that the recipient has
              read or understood the message contents

I'll try forwarding it from the gmail web mail interface again.


There are msf files corresponding to my imap folder structure and other than header only files can be accessed when I am offline.

If the size mismatch is involved it would need to be consistent (for that type of file) since I see this bug daily for years now.

I have no idea if refetch is normally happening when I get the bug and have not examined old 2015/6 logs for that sort of duplication, it seems quite a demanding task!

It is also not an explanation for the 25s delays when click on empty gmail Inbox. Personally I suspect some poor logic/handshaking where one end of server/client closes (or some other state change) the connection and it takes another timeout to get a link back up. Might TCP logs help there??

Under account prefs Message synch opts for Keep all messages in all folders on this computer
Not all regardless of age, but most recent 20 days & not larger than 170kb

This last could be significant? It is these larger messages I get the delay on however the delays & slow download from gmail seems worse than should be expected when I get 20Mb/s plus download rates, unless google are doing heavy throttling... Actually reading the imap log it looks like the email, once it started, was transferred in 36ms so that is 5.6MBs (56mb/s) which is fine.
The second send was similar at 34.5ms. I checked the content and content looks like the expected email (at 10:37:25).

Could the error message you mention (/fetch%3EUID%3E/INBOX%3E19782: message 208070, cache 0) imply that TB thought it had cached the message but failed to complete that. i.e. it logged the email in a list of done but did not complete the saving action. 
I nearly had a complete log of disk and file opens at the time, but I only started an hour later rather than having it running at the time - shame! Another project I'm doing recently...
Perhaps that is where the bug lies, in the saving and logging of messages (probably non-atomic so the message noting and its content saving are not transacted as one thing?). 

Though the regularity of this problem makes me think it must repeatably produce this action, maybe once some other bug has had time to occur (since the behaviour is not normally seen just after a restart of TB and requires some hours of running).

I also wonder about the threading architecture (but know nothing). I would expect the transfer of mail to be handed out to threads and the UI carries on YET I see the spin (blue/white quartered circle mouse pointer) even if briefly when I click on almost any online mailbox (gmail or virginmedia). I can't explain why it needs to do that and the transition in and out of the spin state must cause yet further complication.

Last fact to bear in mind: these slow transfers (or threading/locking) issues are accompanied by higher cpu use and/or many sleep&wakes (enough to trigger the OS running a spin dump for either wakes or cpu use). These might point to a runaway loop or poor execution of multi-thread inter-process design/intent type bug??
Sorry, I *did* receive the sample google alerts but they were in gmail's Spam folder.

Opening them on the system I am currently using (a Chromebook with small flash drive, 16G or 32G, not sure, running  tb on linux via crouton app) they open with no noticeable delay. I have offline storage turned off due to the minimal disk on this laptop. 

With your storage set to 170k limit of course these larger emails will only be cached to memory, so that explains why we see the "read from memory cache" line in your log. There is something you can do to maybe hurry up the problem:

Go to Preferences | Advanced | Network and Disk Space. Once there you can click the "Clear Now" button. This will actually remove anything from the RAM memory cache even though it only mentions disk space.  Then access a large google alert email and see if it is slow (i.e., spins a long time).

Another thing to try is copy a large google alert email to a folder that tb is not checked for new mail and does not receive new mail. Then open a small email in a different folder and click the "Clear Now" button in preferences again. Now wait at least 30m. The 30m is the time the tb uses to determine when a quiet connection has timed out and should be re-established. Now try to access the large google alert email in its folder. This may duplicate the problem you see. What may happen is the tb tries to use the idle connection but it is reported as timed-out. So tb tries to establish a new connection that must be authenticated and is maybe taking a while and is why you see the spin and delay. The same may happen even when accessing Inbox after an idle interval, as you have noticed.

Once you have tried this you may also want to reduce, just for testing, the timeout value that tb uses. You can go to Preference | Advanced | General and access the Config Editor. You can change the value mail.server.serverX.timeout from the default of 29 (seconds) to a smaller value so you don't have to wait >30m for the timeout. If you change this be sure to restart tb for it to take effect. Note also the you will have to determine the value of X by looking at other items under mail.server to determine which is the appropriate server/account number corresponding to gmail. Then you can repeat the test of the previous paragraph without having to wait so long. (Be sure to set it back to 29  and restart tb when you are done.)

If you do these test, be sure to record the imap log so we have a record of what happened.

I am charging up my macbook air and will try this on it ASAP.
Also, as you mention, it might help to see a tcp/ip level packet trace of what is happening when the problem occurs. I use a program called wireshark to do this but you may have something else as an OSX app that works the same, so that would be fine.
I charged-up and booted my mba running "Mavericks" with tb 52.8.0 64-bit and see absolutely no problems accessing the emails you sent me. I even reduced the timeout down from 29 to 5 minutes and let it sit idle for at least 45 minutes and see no problems. I don't even see the spinning icon but only a quick "Downloading" message at the bottom status area when I open one of the emails, even after clearing memory cache. I am running with no offline store so tb only caches to ram.

Updated to tb 60.3.3 and see no problems either. I will post more if I see anything bad.
With the 170k limit I assumed this means only download the "header" for such files, but that header is stored to disc. I thought I had seen this from time to time when out and about with no internet and click on a mail but to get a you are offline type result where smaller unread etc mails are available. But I could easily be wrong on that belief!

Logging TCP - I have used Wireshark which seems to be wrapped in a nice UI now (used to require X-11 I thought) but I am rather treading water here. 

However having setup I was lucky to start wireshark collecting TCP and go to TB and click on the previously viewed gmail mailbox, nothing new to get and 5 previous mails (one of which you saw) that I have left there...
 
TB did a mouseptr spin and tab spinner from around 9:38:30 to 9:39:28 (this was my first test run of setup and I was not really ready to note times so take above times as maybe & approx.)

In Wireshark I capture all TCP and filter to port 993 which is the TLS port for gmail, look around and guess/decide that the google server of interest looks like 74.125.71.109, it is @google and the data arrival times look right...

OUTWARD First packet is 9:37:47 TLSv1.2 with 32 encrypted bytes (BEFORE MY CLICK?? I thought, but maybe click was back then?)
0.3 secs later start a set of TCP retransmissions to the same destination, these gradually slow down starting out 3 per sec, then 2 sec, 3 sec, 10 sec gaps so there are 15 of them over a 79 sec interval
Finally a [RST,ACK] sent at 39:17

IMAP Level: virginmedia account enumerating mailboxes up to 9:37:56 but no imap going on with gmail until 9:39:17 when (date trim & truncated to width of my console window, xxx instead of my id)
09:39:17.599240 UTC - [63839:thread 0x12a1a9d90]: D/IMAP ReadNextLine [stream=0x125c053a0 nb=0 needmore=1
09:39:17.599254 UTC - [63839:thread 0x12a1a9d90]: I/IMAP 0x12a54a800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: clearing I
09:39:17.600025 UTC - [63839:thread 0x12a1a9d90]: I/IMAP 0x12a54a800:imap.gmail.com:S-INBOX:TellThreadToDie: close socket conne
09:39:17.600038 UTC - [63839:thread 0x12a1a9d90]: I/IMAP 0x12a54a800:imap.gmail.com:S-INBOX:CreateNewLineFromSocket: (null)
09:39:17.600813 UTC - [63839:Main]: I/IMAP creating protocol instance to retry queued url:imap://xxx@gmail.com@imap.gmail.com:993
09:39:17.601052 UTC - [63839:Main]: I/IMAP retrying  url:imap://xxx@gmail.com@imap.gmail.com:993/select>/INBOX

This seems to be reseting (I was suspicious of the  xxx@gmail.com@imap.gmail.com:993 but seems that is correct format used)

Well loads of data but I thought I'd give a flavour of that first burst, need to clarify what I did/should capture etc too!
When I have sorted myself clearer on this I will set up to do the steps you suggested with all data collecting going on!
Another thing to try is copy a large google ...
Once you have tried this you may also want to reduce...

NB I do not seem to have any replies in my TCP capture but maybe I captured only dest 933 (would be only to gmail?)
Maybe I should just catch all, but not sure if that might be opening gates to wide - don't know how long I'll run it all.
If the port numbers each end are stable I can probably do both ends without too much angst.
Can you help with the basics of "the connection and timeouts" in A TB context? If I look at open connects out of TB then I see 
lsof -p63839|grep IPv AT 9:13
thunderbi 63839    17u    IPv4 0xa18b21df0a4738df    0t0   TCP 192.168.10.199:61787->imap.virginmedia.com:imaps (ESTABLISHED)  62.254.26.223:993
thunderbi 63839    39u    IPv4 0xa18b21df1ab16fe7    0t0   TCP 192.168.10.199:62025->wo-in-f109.1e100.net:imaps (ESTABLISHED)  74.125.133.109:993
thunderbi 63839    41u    IPv4 0xa18b21df2388afe7    0t0   TCP 192.168.10.199:61774->imap.virginmedia.com:imaps (ESTABLISHED) 
thunderbi 63839    44u    IPv4 0xa18b21df257dafe7    0t0   TCP 192.168.10.199:61951->wn-in-f109.1e100.net:imaps (ESTABLISHED)  62.254.26.223:933 virginmedia
thunderbi 63839    45u    IPv4 0xa18b21df257914ff    0t0   TCP 192.168.10.199:61953->wn-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    65u    IPv4 0xa18b21df257d14ff    0t0   TCP 192.168.10.199:62026->lhr35s01-in-f10.1e100.net:https (ESTABLISHED) 172.217.23.10 google

and a later 14:00 run
thunderbi 63839    17u    IPv4 0xa18b21df0a4738df    0t0   TCP 192.168.10.199:61787->imap.virginmedia.com:imaps (ESTABLISHED)
thunderbi 63839    30u    IPv4 0xa18b21df1ba40fe7    0t0   TCP 192.168.10.199:63134->wa-in-f108.1e100.net:imaps (ESTABLISHED) 64.233.184.108
thunderbi 63839    33u    IPv4 0xa18b21deea51e1d7    0t0   TCP 192.168.10.199:63021->wo-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    36u    IPv4 0xa18b21df1ba3ec07    0t0   TCP 192.168.10.199:63032->wo-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    41u    IPv4 0xa18b21df2388afe7    0t0   TCP 192.168.10.199:61774->imap.virginmedia.com:imaps (ESTABLISHED)

Some servers have been swapped, maybe when I restarted TB or maybe at a timeout/disconnect/or google load levelling type event.
Should I expect some of those wo-in-f109.1e100.net:imaps (ESTABLISHED)to change state after 30 minutes or some other time?

Logic to me at top level of observations is that if I quit and re-start TB all seems fine, no delays, so establishing connects is no problem.
SO maybe problems are around client & server agreeing when the link is down and clean restarting? I assume one side gives up first... and there are TB "Check for new every X mins? 
   I have X=10 mins on some gmail accounts but 29minutes on the account that gives the problem. IS that worryingly long or close to gmail/lower level timeouts? My logic was that I only receive a small number per day and they are never urgent. But link stability is more important than saving a few cpu cycles!
 
Also idle settings for connections too? The problem account checks for Immediate server notifications when messages arrive. Presumably this is push type services (as available on iOS Mail too), could that complicate the issues?

For tests is it beneficial to change these settings (e.g. work around) or continue to deeper issues (the hi cpu and delays during "bug" phases)?
A little later, 14:32, with no TB restart connections & servers are:
thunderbi 63839    16u  IPv4 0xa18b21dee64466ef    0t0   TCP 192.168.10.199:63378->wq-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    19u  IPv4 0xa18b21df1f5b7df7    0t0   TCP 192.168.10.199:63412->wb-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    32u  IPv4 0xa18b21df1e28fdf7    0t0   TCP 192.168.10.199:63375->wq-in-f108.1e100.net:imaps (ESTABLISHED)
Google like to cycle the server and presumably this reflects in the connect states. It also challenges me how to select the right in and out links for capture! TB device numbers have also remapped (the virgin services remain on the same posts and devices 17u & 41u [column 3 previous report], I removed from the above to leave 3 gmail.)
I have been ignoring TB mail pretty much and not clicking any gmail areas though have been looking at account configurations.
Virgin are much smaller scale, plus I check account every 5mins in account settings in addition to allow Immediate notifications. so other aspects being equal I would expect this to preform better.

As an aside I did have issues with Dovecote servers at Virgin when some of the auto-spam measures were being rolled out, eventual settings changes at ISP fixed that. (Some other servers were marking my mail as spam based on blacklists/virgin data). May be of interest!
Yes, setting up to record activity with wireshark can be difficult especially with TLS and also the compression that tb/gmail uses that also obfuscates the transactions. I typically turn off the compression in tb config editor and use stunnel server running locally so tb just connects without tls (plaintext between tb and stunnel server, then stunnel handles the tls and connects to gmail or whatever). I give each account (imap server) its own port on stunnel so I can separate in wireshark the network activity of the accounts. Then I monitor with wireshark the data between tb and stunnel which is not encrypted, filtering on the target account's stunnel port. (Not sure if stunnel is available on OSX.)

Anyhow, I left the macbook air running overnight and I still don't see a problem today accessing the 3 large emails I received from you. No delays or spinning cursor. I did set up the gmail account with all tb defaults. Therefore it checks for new emails every 10m and uses imap IDLE (immediate notification of new mail). You mention that you set the check for new mail to 29m for the problem gmail account. This is very close to the default timeout that tb uses when finding a connection to use when you click on a folder or email. You might want to reduce this down to to maybe 20m or even just go back to the default of 10m. 

But even at that, setting up a new connection, due to tb's perception that the connection has timed out and should be dropped, shouldn't take a noticeable time on a fast network like you are on.
I am unsure if it is best to try and get to the reason and detail of this problem (there is someone to use the information and fix) or just learn a bit and work around it.
I have been trying 5minute checks for emails for 6 hours and not yet seen any problems but have mostly been getting logs and tools setup. Not a great approach to change to 5mins maybe as I'm still hazy on the reproducibility and the relation between the two seemingly related problems 
1. spin-wait for empty gmail Inbox
2. long timeout, possible retransmission too, of large google alerts over 200kb of html
I hope to swap back to 29mins to see what happens then... but maybe only worth doing if this is helping kill a bug.


I've been collating tcp,map and syslog together into nav which is working well with lots of filters to take out chaff. Shame is that the compact tcpdump output is much less readable on things like retransmission than Wireshark so I'm reading across both until I get used to the patterns in tcpdump. Looks like there are lots of (nearly all) retransmits at present having just recently restarted new log files and new TB start....

Filtering out unwanted TCP has required knowing which ip and port pairs are in action and it seems to be ever shifting sands.
**** The google sever names seem to change a lot although the ip behind the name may often NOT change. 
**** I don't get what that implies or if it might cause problems for TB. I guess both ends should close and reopen connections around any load shifting but maybe it causes errors? 

My notes on IP add over last 10 hours (I added IP for the names using dig):

14:00 run
thunderbi 63839    30u IPv4 0xa18b21df1ba40fe7    0t0   TCP 192.168.10.199:63134->wa-in-f108.1e100.net:imaps (ESTABLISHED) 64.233.184.108
thunderbi 63839    33u IPv4 0xa18b21deea51e1d7    0t0   TCP 192.168.10.199:63021->wo-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    36u IPv4 0xa18b21df1ba3ec07    0t0   TCP 192.168.10.199:63032->wo-in-f109.1e100.net:imaps (ESTABLISHED)
at 14:32:22 with no TB restart:
lsof -p63839|grep IPv
thunderbi 63839    16u IPv4 0xa18b21dee64466ef    0t0   TCP 192.168.10.199:63378->wq-in-f108.1e100.net:imaps (ESTABLISHED) 74.125.140.108
thunderbi 63839    19u IPv4 0xa18b21df1f5b7df7    0t0   TCP 192.168.10.199:63412->wb-in-f109.1e100.net:imaps (ESTABLISHED) 66.102.1.109
thunderbi 63839    32u IPv4 0xa18b21df1e28fdf7    0t0   TCP 192.168.10.199:63375->wq-in-f108.1e100.net:imaps (ESTABLISHED) 74.125.140.108
14:53:46 Sat Dec 08  xterm-256color  ~
$ lsof -p63839|grep IPv
thunderbi 63839    16u    IPv4 0xa18b21df1baa0fe7   0t0  TCP 192.168.10.199:63688->wa-in-f108.1e100.net:imaps (ESTABLISHED) 92.242.132.24
thunderbi 63839    19u    IPv4 0xa18b21df1e290fe7   0t0  TCP 192.168.10.199:63663->wm-in-f109.1e100.net:imaps (ESTABLISHED) 64.233.166.109
thunderbi 63839    32u    IPv4 0xa18b21dee64466ef   0t0  TCP 192.168.10.199:63603->wo-in-f109.1e100.net:imaps (ESTABLISHED) 92.242.132.24
15:54:28 Sat Dec 08  xterm-256color  ~
$ lsof -p63839|grep IPv
thunderbi 63839    16u    IPv4 0xa18b21df18e27fe7   0t0  TCP 192.168.10.199:63812->wa-in-f108.1e100.net:imaps (ESTABLISHED) 92.242.132.24
thunderbi 63839    19u    IPv4 0xa18b21df1ba9ec07   0t0  TCP 192.168.10.199:63897->wb-in-f109.1e100.net:imaps (ESTABLISHED) 92.242.132.24
thunderbi 63839    32u    IPv4 0xa18b21df1bacb4ff   0t0  TCP 192.168.10.199:63878->wb-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    36u    IPv4 0xa18b21df1e28fdf7   0t0  TCP 192.168.10.199:63879->lhr26s04-in-f234.1e100.net:https (ESTABLISHED)
16:39:50 Sat Dec 08  xterm-256color  ~
$ lsof -p63839|grep IPv
thunderbi 63839    16u    IPv4 0xa18b21df1c7fcdf7   0t0  TCP 192.168.10.199:64046->wo-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    19u    IPv4 0xa18b21df1e290fe7   0t0  TCP 192.168.10.199:64034->wm-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    32u    IPv4 0xa18b21df0a4741d7   0t0  TCP 192.168.10.199:64047->lhr25s10-in-f170.1e100.net:https (ESTABLISHED)
16:43:00 after click cwinte inbox
thunderbi 63839    16u    IPv4 0xa18b21df1c7fcdf7   0t0  TCP 192.168.10.199:64046->wo-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    19u    IPv4 0xa18b21df1e290fe7   0t0  TCP 192.168.10.199:64034->wm-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    32u    IPv4 0xa18b21df0a4741d7   0t0  TCP 192.168.10.199:64047->lhr25s10-in-f170.1e100.net:https (ESTABLISHED) 92.242.132.24
thunderbi 63839    44u    IPv4 0xa18b21df1f5b74ff   0t0  TCP 192.168.10.199:64049->wo-in-f108.1e100.net:imaps (ESTABLISHED) 92.242.132.24

18:40:39 Sat Dec 08  lsof -p63839|grep IPv|grep -v virgin
thunderbi 63839    16u    IPv4 0xa18b21df0a4738df   0t0  TCP 192.168.10.199:64630->wa-in-f108.1e100.net:imaps (ESTABLISHED) 92.242.132.24
thunderbi 63839    19u    IPv4 0xa18b21df257d54ff   0t0  TCP 192.168.10.199:64649->wa-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    35u    IPv4 0xa18b21df18801df7   0t0  TCP 192.168.10.199:64651->wa-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    39u    IPv4 0xa18b21df1e290fe7   0t0  TCP 192.168.10.199:64623->wa-in-f108.1e100.net:imaps (ESTABLISHED)

19:01:54 Sat Dec 08   lsof -p63839|grep IPv|grep -v virgin
thunderbi 63839    16u    IPv4 0xa18b21df0a472fe7   0t0  TCP 192.168.10.199:64743->wo-in-f109.1e100.net:imaps (ESTABLISHED) 92.242.132.24
thunderbi 63839    19u    IPv4 0xa18b21df16dfd6ef   0t0  TCP 192.168.10.199:64741->wo-in-f109.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    34u    IPv4 0xa18b21df16dfdfe7   0t0  TCP 192.168.10.199:64742->lhr25s13-in-f10.1e100.net:https (ESTABLISHED) 216.58.204.74 google
thunderbi 63839    35u    IPv4 0xa18b21df18801df7   0t0  TCP 192.168.10.199:64651->wa-in-f108.1e100.net:imaps (ESTABLISHED) 64.233.184.108
thunderbi 63839    39u    IPv4 0xa18b21df1e2906ef   0t0  TCP 192.168.10.199:64752->wo-in-f109.1e100.net:imaps (ESTABLISHED)
midnight
$ lsof -p63839|grep IPv|grep -v virgin
thunderbi 63839    16u    IPv4 0xa18b21def26ed1d7  0t0   TCP 192.168.10.199:65404->wn-in-f108.1e100.net:imaps (ESTABLISHED)
thunderbi 63839    19u    IPv4 0xa18b21df0a472fe7  0t0   TCP 192.168.10.199:65406->wn-in-f108.1e100.net:imaps (ESTABLISHED)
one name wn-in-f108.1e100.net @74.125.71.108

00:45:00 restart TB
thunderbi 80179 45u IPv4 0xa18b21df1ba40fe7 0t0 TCP 192.168.10.199:49195->wr-in-f108.1e100.net:imaps (ESTABLISHED) 108.177.15.108
thunderbi 80179 46u IPv4 0xa18b21df2387a1d7 0t0 TCP 192.168.10.199:49211->wa-in-f109.1e100.net:imaps (ESTABLISHED) 64.233.184.109
thunderbi 80179 81u IPv4 0xa18b21df18422c07 0t0 TCP 192.168.10.199:49159->wq-in-f109.1e100.net:imaps (ESTABLISHED) 74.125.140.109
thunderbi 80179 90u IPv4 0xa18b21df257d4c07 0t0 TCP 192.168.10.199:49212->lhr35s10-in-f10.1e100.net:https (ESTABl) 216.58.206.42
Your config with tunnels sounds good and cures much of my checking which port/IP is which plus avoiding the TLS hides. Extra pain as they are very shifty as noted above. Never setup tunnels system but will have a look if I continue to dig at this (I love a new area to explore).

Is there a possible OAuth vs OAuth2 difference with TB? I'm sure I read people had issues around the change-over by Gmail on that....
Looks like I have options...
brew search tunnel
==> Formulae
ctunnel          httptunnel       proxytunnel      ptunnel          stunnel          tcptunnel        tunnel           udptunnel

==> Casks
homebrew/cask/ssh-tunnel-manager

Any suggestions is my best starter kit for the tasks at hand?
Attached file stunnel.conf
The only tunnel app I have used is stunnel and it works well for me. Attached is an example config file that resides (on linux) at /etc/stunnel/stunnel.conf.

You can customize it for your own use and have as many accounts as you need. I always put each server/account on a different local port like 130, 131, etc. You can use any port that is available that you want. Stunnel then handles the TLS and forwards the connection from the local port to the servers TLS port, typically 993.

To run stunnel I just do this in a terminal:

sudo stunnel /etc/stunnel/stunnel.conf

Then in tb you have to reconfigured your server settings some, for example for gmail I have:

Servername: localhost  Port 130
User Name: same as before
Connection security: none
Auth method: OAuth2 (which is same as before)
All the rest, same as before.

Then restart tb. It may re-ask for the password and complain about junk/spam settings that you can ignore probably.

In wire shark you then just have to filter like this:

tcp.port==130

and record the packets using the buttons. This will show everything as raw data.

You have to tell wshark that port 130 is imap since it is non-standard and won't know this without a hint. You do this by selecting a packet and with the menu item

Analyze | Decode As... then in the list find "IMAP" and select it and click OK.

Now you can filter like this and just see the IMAP related stuff for just gmail:

tcp.port==130 && imap

As I mention, you probably want to turn off imap compression too, so you can actually read the imap data:

In tb's config editor mail.server.default.use_compress_deflate set to false and restart tb.

Oh yeah, I forgot to mention that in wireshark you have to choose the correct "interface" for the local ports, which on linux is call localhost or "lo" or 127.0.0.1. You don't want to record data on your ethernet or wifi interface which will be encrypted by stunnel.
That is brilliant info! Many thanks... will have a go

    meanwhile looks all clear with 5min polling on the gmail account. 
    Worth now going back to the 29min polling to see if recurrence of problems?

Started this next morning, laptop left on over night with logging running not slept etc. 
Started up Wireshark for clearer display of possible retransmits etc then 11:29:00 click gmail Inbox, no spinner, no delay, had header of a 205k alert so clicked that 11:29:57-ish appeared very fast no spin signs.
Following is interleaved tcpdump and map logs together with any syslog (thanks to nav):
clean into gmail at 11:29 but was already live previously (though untouched overnight):
11:28:34.610510 IP 173.194.76.108.993 > 192.168.10.199.50061: flg[P.], seq 1183:1232, ack 1255, win 244, options [nop,nop,TS val 1992523034 ecr 235209044], lengt
11:28:34.610559 IP 192.168.10.199.50061 > 173.194.76.108.993: flg[.], ack 1232, win 4094, options [nop,nop,TS val 235209073 ecr 1992523034], len 0
2018-12-09 11:28:34.983978 UTC-[80179:Main thrd]: D/IMAP proposed url = gmail mbx folder for connection INBOX has To Wait = FALSE can run = FALSE    
11:28:34.985831 IP 192.168.10.199.50061 > 173.194.76.108.993: flg[P.], seq 1255:1303, ack 1232, win 4096, options [nop,nop,TS val 235209446 ecr 1992523034], leng
2018-12-09 11:28:34.985154 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:ProcessCurrentURL: entering                     
2018-12-09 11:28:34.985178 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:ProcessCurrentURL:imap://cwinte%40gmail%2Ecom@imap.gmail.co
2018-12-09 11:28:34.985677 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:SendData: 8 STATUS "gmail mbx" (UIDNEXT MESSAGES UNSEEN REC
11:28:35.009769 IP 173.194.76.108.993 > 192.168.10.199.50061: flg[P.], seq 1232:1284, ack 1303, win 244, options [nop,nop,TS val 1992523433 ecr 235209446], lengt
11:28:35.009809 IP 192.168.10.199.50061 > 173.194.76.108.993: flg[.], ack 1284, win 4094, options [nop,nop,TS val 235209469 ecr 1992523433], len 0 
2018-12-09 11:28:35.390604 UTC-[80179:Main thrd]: D/IMAP proposed url = Junk E-mail folder for connection INBOX has To Wait = FALSE can run = FALSE  
2018-12-09 11:28:35.391506 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:ProcessCurrentURL: entering                     
2018-12-09 11:28:35.391515 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:ProcessCurrentURL:imap://cwinte%40gmail%2Ecom@imap.gmail.co
2018-12-09 11:28:35.391856 UTC-[80179: thrd 0x124bc1550]: I/IMAP 0x11c8ab000:imap.gmail.com:A:SendData: 9 STATUS "Junk E-mail" (UIDNEXT MESSAGES UNSEEN R
11:28:35.392006 IP 192.168.10.199.50061 > 173.194.76.108.993: flg[P.], seq 1303:1352, ack 1284, win 4096, options [nop,nop,TS val 235209851 ecr 1992523433], leng
11:28:35.415100 IP 173.194.76.108.993 > 192.168.10.199.50061: flg[P.], seq 1284:1340, ack 1352, win 244, options [nop,nop,TS val 1992523839 ecr 235209851], lengt
11:28:35.415129 IP 192.168.10.199.50061 > 173.194.76.108.993: flg[.], ack 1340, win 4094, options [nop,nop,TS val 235209874 ecr 1992523839], len 0 
2018-12-09 11:29:00.849754 UTC-[80179:Main thrd]: D/IMAP proposed url = INBOX folder for connection INBOX has To Wait = FALSE can run = TRUE
11:29:00.850431 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[P.], seq 1661:1698, ack 2145, win 4096, options [nop,nop,TS val 235235287 ecr 2591365603], leng
2018-12-09 11:29:00.850291 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:SendData: DONE                            
11:29:00.875465 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[.], ack 1698, win 244, options [nop,nop,TS val 2591529196 ecr 235235287], len 0  
11:29:00.948990 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2145:2184, ack 1698, win 244, options [nop,nop,TS val 2591529269 ecr 235235287], lengt
11:29:00.948993 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2184:2214, ack 1698, win 244, options [nop,nop,TS val 2591529269 ecr 235235287], lengt
11:29:00.949048 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2184, win 4094, options [nop,nop,TS val 235235385 ecr 2591529269], len 0 
11:29:00.949065 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2214, win 4093, options [nop,nop,TS val 235235385 ecr 2591529269], len 0 
2018-12-09 11:29:00.949407 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering               
2018-12-09 11:29:00.949624 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://cwinte%40gmail%2Ecom@imap.gm
11:29:00.950367 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[P.], seq 1698:1743, ack 2214, win 4096, options [nop,nop,TS val 235235386 ecr 2591529269], leng
2018-12-09 11:29:00.950227 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:SendData: 17 check                        
11:29:00.977687 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[.], ack 1743, win 244, options [nop,nop,TS val 2591529298 ecr 235235386], len 0  
11:29:01.049465 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2214:2253, ack 1743, win 244, options [nop,nop,TS val 2591529370 ecr 235235386], lengt
11:29:01.049495 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2253, win 4094, options [nop,nop,TS val 235235484 ecr 2591529370], len 0 
11:29:01.049900 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[P.], seq 1743:1782, ack 2253, win 4096, options [nop,nop,TS val 235235484 ecr 2591529370], leng
2018-12-09 11:29:01.049797 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:SendData: 18 getquotaroot "INBOX"         
11:29:01.077851 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[.], ack 1782, win 244, options [nop,nop,TS val 2591529398 ecr 235235484], len 0  
11:29:01.149802 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2253:2294, ack 1782, win 244, options [nop,nop,TS val 2591529470 ecr 235235484], lengt
11:29:01.149843 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2294, win 4094, options [nop,nop,TS val 235235582 ecr 2591529470], len 0 
11:29:01.150307 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[P.], seq 1782:1821, ack 2294, win 4096, options [nop,nop,TS val 235235582 ecr 2591529470], leng
2018-12-09 11:29:01.150243 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:SendData: 19 UID fetch 19794:* (FLAGS)    
11:29:01.179541 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[.], ack 1821, win 244, options [nop,nop,TS val 2591529500 ecr 235235582], len 0  
11:29:01.264144 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2294:2332, ack 1821, win 244, options [nop,nop,TS val 2591529584 ecr 235235582], lengt
11:29:01.264188 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2332, win 4094, options [nop,nop,TS val 235235694 ecr 2591529584], len 0 
11:29:01.264502 IP 74.125.133.109.993 > 192.168.10.199.50036: flg[P.], seq 2332:2371, ack 1821, win 244, options [nop,nop,TS val 2591529584 ecr 235235582], lengt
11:29:01.264533 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[.], ack 2371, win 4094, options [nop,nop,TS val 235235694 ecr 2591529584], len 0 
11:29:01.270303 IP 192.168.10.199.50036 > 74.125.133.109.993: flg[P.], seq 1821:1860, ack 2371, win 4096, options [nop,nop,TS val 235235700 ecr 2591529584], leng
2018-12-09 11:29:01.270201 UTC-[80179: thrd 0x124bc1c70]: I/IMAP 0x12484e000:imap.gmail.com:S-INBOX:SendData: 20 IDLE

This all looks fine to me, proving no other problems in mac or chain from me to gmail.
I meant to mention that in the above interval there was no sight of any re-transmissions in Wireshark (which had been common previously). I should perhaps also explain the above listing is tcpdump of TCP excluding virginmedia IPs and then lnav hides CreateNewLineFromSocket and ReadNextLine giving a compact summary of the meaningful.

I DO still see a brief (1/2 sec?) spinner if I click on an empty mailbox (like drafts, templates) but Wshark not showing rexmit etc.
 
Just re-ran that click Templates and got a LONG spin for over 30s, it continued while I clicked on empty Drafts and back to Templates. Eventually stopped when I went to virginmedia mailbox. When analysing I noted virgin boxes had recently enumerated 87 secs previous to my click on templates so was very "fresh"...

So there is still something I find inexplicable even though actual mail is arriving better.

LNAV logs:
Dec  9 12:10:13 ··· kernel[0]: en0: promiscuous mode enable succeeded *WIRESHARK ON
12:10:30.418655 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS val 237719316 ecr 565731229], length
12:10:30.418130 UTC - [80179:Main Thread]: D/IMAP proposed url = Templates folder for connection INBOX has To Wait = FALSE can run = FALSE
12:10:30.418145 UTC - [80179:Main Thread]: D/IMAP proposed url = Templates folder for connection Drafts has To Wait = FALSE can run = FALSE
12:10:30.418156 UTC - [80179:Main Thread]: D/IMAP proposed url = Templates folder for connection Templates has To Wait = FALSE can run = TRUE
2018-12-09 12:10:30.418550 UTC - [80179:Unnamed thread 0x12b564970]: I/IMAP 0x127ae2000:imap.gmail.com:S-Templates:SendData: DONE
12:10:30.891711 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS 
12:10:30.935331 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS 
12:10:31.764494 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS 
12:10:33.221098 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS 
12:10:35.935132 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS 
12:10:40.945803 UTC - [80179:Main Thread]: D/IMAP proposed url =   virgin mailbox
12:10:40.946858 UTC - [80179:Main Thread]: D/IMAP proposed url =   virgin...  INBOX has To Wait = FALSE can run = FALSE
12:10:41.165771 IP 192.168.10.199.50221 > 74.125.71.109.993: Flags [P.], seq 1366:1403, ack 1645, win 4096, options [nop,nop,TS

Wireshark showed 2 TLS and a large proportion of retransmits, screen shot here...
https://www.dropbox.com/s/pzpaexssa0lr6td/wireshark12_10Dec8ReXmt.tiff?dl=0
Is it maybe significant that the gmail imap IP address and server names change so much? For instance that long spin above I think co-incided with a change of IP. 

I was seeing 64.233.167.109 until 12:07 last line in LNAV
12:07:40.052 IP192.168.10.199.50255 > 64.233.167.109.993: flg[.], ack 1562, win 4094, opt[nop,nop,TS val 237549296
then 
IP 74.125.71.109 in the long spin test of empty mailboxes at 12:10
I was not running wireshark until a little later but wonder how TB would have known about the change, nothing to advertise it in my LNAV continuous trace.

Might this be the source of the problems?
And might stunnel handle this change better/differently? 
Seems a change would be external and invisible to TB going via stunnel
I don't think the change in the gmail server IP address is a problem. When tb makes a connection the destination ip address has to stay the same while that connection is good. I'm sure Gmail/google won't just change it while your tcp/ip/tls/imap session is in progress. If that happened it would greatly confusing tb which will quickly drop the connection. When tb makes another connection (i.e., you click on folder you haven't visited in a while) the mail.gmail.com address may resolve to a different ip address and that is OK. Even when tb has 5 connections to gmail account at the same time all can be to different ip address for the same server url.

Stunnel just moves the tls/ssl functionality external to tb so it really shouldn't be any different. I suspect both tb and stunnel use very similar tls code probably based on OpenSSL but not sure.

When you click on Templates you saw a 30s or so spin? And in wireshark you see a bunch of retransmissions? Then it looks like tb drops the connection. Googling for "wireshark tcp retransmission" it says there may be a wiring problem that is preventing the receiving end from "ack'ing" a data packet. It suggests pinging the destination to see if there are lost packets. So try doing the ping command to the gmail server using the mail.gmail.com url (not the ip address) and see if there are lost packets. You might do this several times so you try the various ip addresses that mail.gmail.com resolves to. Maybe just one ip has an occasional problem.

Here, on linux and osx I only see a short "spin" icon when I click on a folder but not when I open an email in the folder. And the spin is always very short.
Was that "wiring" timing in para 3? I am seeing this pattern in Wireshark repeatedly where 993<>my_port goes into retransmits over increasing time gaps covering 30-35 secs and finally a RST,ACK which I guess is a reset. The regular occurrence of this pattern makes it seem unlikely this is some sort of rare timing issue.
There is too much other data to easily pick up the change after the reset as I can't ascertain which connections serve which account. (Well only by a prod of an account at a known time, and spot the traffic - that is slow to do and feels a poor way to progress).

AS I have connections to 3 distinct gmail accounts plus others it is awkward to clarify which is which among the gmail transfers. I have looked for a way to take one account offline in some way, but without account deletion as there are 30,000 emails in some. 
I guess I could increase the time between polls but maybe there is a better way? 
Or maybe make a whole new installation of TB with just the one account, even on a backup older laptop though my that would be missing lots of brew etc tools and config that are on my main machine. Is there a clean safe way to make a new TB installation that is partitioned off and will not touch my existing files and setup?
I've put other gmail accounts as not immediate delivery and no scheduled checking. I hope that just leaves the one I am watching interacting. 
Every 15mins it seems, even when "inactive", the TCP in Wireshark shows a regular block of the retransmits, then RST, then a new syn,syn-ack,ack then TLS Client hello and new port & interaction phase begins. The IP address at gmail also changes at this time.
I will email you this cap as the file is not too large!
There are RSTs at 14:45:08, 14:52:22, 15:00:11, 15:10:43, 15:12:19, 15:20:48 (view filter tcp.flags.reset==1)
I can't see anything that looks like a warning that gmail is about to swap server, the re-xmit looks like the first thing to me.

Some of the RST events seem to feature a longer TLS exchange starting with info=Encrypted alert...
You may already have worked this out but to isolate an account you can start tb from a terminal like this:

> thunderbird --ProfileManager

Then you can select existing profile(s) or create a new profile with just the problem gmail account using the gui that pops up.

Tb does not seem to have a way to "disable" an account. I noticed that the Evolution email client (linux only?) has an option to disable selected accounts so that they are offline while all other accounts are active. So with it you can disable all but one account without needing a new setup (profile) like tb requires. With tb you can only set *all* accounts offline, which doesn't help when you need to isolate and troubleshoot a single account.
Thanks for that, did not know and useful!

This am (12th) I had just 10am reset monitoring and restarted TB, 18mins later at 10:18:36 I had a first 30s spin wait while looking at my normal virginmedia main account, just clicked on a different mailbox having read, replied&sent, then deleted and (command-Z0 undeleted a mail. I think it was the undelete that may have been last since I found myself wondering what it was not coming back... However the timing look like the undelete may have been timed with a second spin wait on virginmedia account at 10:19:15 to 10:19:37
I thought I did not get the spin waits on this non gmail account but luckily Wireshark caught it all and in both cases it was the exact same pattern of growing delays between retransmissions then a RST reset and new login. In this account case there is never any change of ip address. This is my first certain noting of this event but it may have occurred before when I was moving rapidly and not really noticing what exactly was causal. In fact I had been excluding this from filters and views mostly.

So now I go looking I see them every 30mins when the system is quiet (I am elsewhere), this account is still set for push mails and check every 5 mins. All I have looked at display the spacing retrans and RST, then re-start sequences. I was not there to witness the cursor.

I had just been mulling what I had learnt over last week and if I was getting anywhere and helping anything.
It seems like, here , these reset and religions are fairly normal. AND I do not see why they are correct behaviour. If either party wants some sort of reset there should be a way to notify to close and reopen then stream (if that is the right term. 

The TB client locking the UI also seems wrong, even if a stream is going down shouldn't that be handled in a separate thread and just report in to UI that it is retrying. Probably in the progress bar where we see opening mailbox, logging in, sending data etc...

When I am active there have been resets which look more as I would expect. Many (at least) of these are initiated from the server end, sometimes several in a minute or so and often with TLS Alerts or similar. Afraid I do not have time to go digging at random as I do not know what I am looking for but can supply the capture file...

Is there any other TB state logging that should be enabled to assist? I have a faint recollection that there is something but ideally could be told what we need?

In hope!
Have you just tried ping like I suggested (example below)? 

(xenial)gene@localhost:~$ ping mail.google.com    
PING googlemail.l.google.com (64.233.185.83) 56(84) bytes of data.
64 bytes from yb-in-f83.1e100.net (64.233.185.83): icmp_seq=1 ttl=41 time=32.7 ms
64 bytes from yb-in-f83.1e100.net (64.233.185.83): icmp_seq=2 ttl=41 time=28.8 ms
64 bytes from yb-in-f83.1e100.net (64.233.185.83): icmp_seq=3 ttl=41 time=21.3 ms

(xenial)gene@localhost:~$ ping mail.google.com
PING googlemail.l.google.com (64.233.185.19) 56(84) bytes of data.
64 bytes from yb-in-f19.1e100.net (64.233.185.19): icmp_seq=1 ttl=41 time=32.9 ms
64 bytes from yb-in-f19.1e100.net (64.233.185.19): icmp_seq=2 ttl=41 time=21.5 ms
64 bytes from yb-in-f19.1e100.net (64.233.185.19): icmp_seq=3 ttl=41 time=21.5 ms

Note the different ip address each time with the same url. Tb will see the same thing when it connects. You can leave it running for 30 minutes or more and see if here is a glitch at some point (lost packets, huge delay etc.)

Also, tb definitely does threading very well. Each of the 5 connections for an account has its own thread so if you click on another folder in the account it will handled by its own thread (if not all 5 are busy). And even if all 5 are busy in account A, if you click on a folder in account B, there are 5 more separate threads there to handle your request. So unless your network is basically down and nothing is going in/out, a spin wait at account A folder A1 should not affect access to account B folder B1. Of course, this assumes you keep the default advanced server setting of 5 connections per account and don't reduce it.
I did do some pinging, but not for extended periods in one command as I assume that will do one dns lookup and then keep to that one server. 
Maybe both tests give info e.g. if one server can go down/give errors while repeating (name resolve and 30 pings) works fine 
or whatever...
Needs a small control script to do the loop of short tests and -c count,  or is there a better way?

Why not ask for imap.gmail.com? [both the IPs below are in the ranges I have observed in recent days.]
ping  -i5 imap.gmail.com receives:
PING gmail-imap.l.google.com (74.125.133.109)

while ping -i5 mail.google.com receives:
PING googlemail.l.google.com (216.58.204.69): 56 data bytes

It has all looked very regular so far, 20ms +- a few ms
Blocks: tb-gmailWIP
Some wobbles shown by google...
I'm using a bash shell function to loop command
function doloop { echo Logging to doloop.log, remember to fg  ^C...;jobs;export cmd="$1 $2 $3 $4 $5 $6 $7"; echo Running  $cmd>doloop.log; bash -c 'while [ 0 ]; do date>>doloop.log;$cmd>>doloop.log;sleep 10; done' & }
Then
doloop ping -t20 -n -i3 -c6 mail.google.com

Summary low std deviations other than one brief period:

grep -e "^PING" -e "^round"  doloop.log
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 16.311/18.772/22.596/1.974 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 16.797/18.056/21.124/1.545 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 17.973/29.212/75.492/20.952 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 17.162/18.204/20.548/1.152 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 17.700/18.341/18.768/0.340 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 17.831/148.231/655.005/253.413 ms    <<<<<<<<<<< THIS ONE
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 18.160/91.215/168.180/71.429 ms
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
round-trip min/avg/max/stddev = 17.831/36.905/124.261/39.081 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes          <<changeover
round-trip min/avg/max/stddev = 16.457/17.344/18.245/0.649 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.320/18.726/23.004/2.056 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.582/17.788/19.696/0.996 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 17.060/17.410/17.852/0.333 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.902/17.529/19.180/0.773 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.605/17.810/19.867/1.132 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.706/18.379/21.281/1.521 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.906/20.207/21.914/1.681 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 17.163/18.373/19.615/0.767 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
round-trip min/avg/max/stddev = 16.629/17.667/18.841/0.895 ms
PING googlemail.l.google.com (216.58.204.69): 56 data bytes

The wobble:
round-trip min/avg/max/stddev = 17.700/18.341/18.768/0.340 ms
Thu 13 Dec 2018 13:59:04 GMT
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
64 bytes from 216.58.208.165: icmp_seq=0 ttl=55 time=17.831 ms
64 bytes from 216.58.208.165: icmp_seq=1 ttl=55 time=19.421 ms
64 bytes from 216.58.208.165: icmp_seq=2 ttl=55 time=20.557 ms
Request timeout for icmp_seq 3                                         <<<<<<<<<<< THIS ONE
64 bytes from 216.58.208.165: icmp_seq=4 ttl=55 time=655.005 ms     <<<<<<<<<<< THIS ONE
64 bytes from 216.58.208.165: icmp_seq=5 ttl=55 time=28.343 ms

--- googlemail.l.google.com ping statistics ---
6 packets transmitted, 5 packets received, 16.7% packet loss
round-trip min/avg/max/stddev = 17.831/148.231/655.005/253.413 ms
Thu 13 Dec 2018 13:59:33 GMT
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
64 bytes from 216.58.208.165: icmp_seq=0 ttl=55 time=21.297 ms
64 bytes from 216.58.208.165: icmp_seq=1 ttl=55 time=168.180 ms    <<<<<<<<<<< a bit more
64 bytes from 216.58.208.165: icmp_seq=2 ttl=55 time=20.086 ms
64 bytes from 216.58.208.165: icmp_seq=3 ttl=55 time=160.491 ms    <<<<<<<<<<< a bit more
64 bytes from 216.58.208.165: icmp_seq=4 ttl=55 time=18.160 ms
64 bytes from 216.58.208.165: icmp_seq=5 ttl=55 time=159.077 ms    <<<<<<<<<<< a bit more
In loop test, as above, 18 server changes in 1hr15:
$ awk '/^PING/{if(ip!=$3){print $0;ip=$3}}' doloop.log
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
PING googlemail.l.google.com (216.58.214.5): 56 data bytes
PING googlemail.l.google.com (216.58.206.37): 56 data bytes
PING googlemail.l.google.com (216.58.213.69): 56 data bytes
PING googlemail.l.google.com (216.58.206.69): 56 data bytes
PING googlemail.l.google.com (216.58.206.133): 56 data bytes
PING googlemail.l.google.com (216.58.213.101): 56 data bytes
PING googlemail.l.google.com (216.58.206.69): 56 data bytes
PING googlemail.l.google.com (216.58.204.5): 56 data bytes
PING googlemail.l.google.com (172.217.23.5): 56 data bytes
PING googlemail.l.google.com (216.58.198.165): 56 data bytes
PING googlemail.l.google.com (216.58.206.101): 56 data bytes
PING googlemail.l.google.com (216.58.214.5): 56 data bytes
PING googlemail.l.google.com (172.217.23.5): 56 data bytes
PING googlemail.l.google.com (216.58.204.69): 56 data bytes
PING googlemail.l.google.com (216.58.198.165): 56 data bytes

0&ttys002-bash=935 !4136#1341 15:12:35 Thu Dec 13 xterm-256color  ~
$ head doloop.log 
Running ping -t20 -n -i3 -c6 mail.google.com
Thu 13 Dec 2018 13:56:59 GMT
PING googlemail.l.google.com (216.58.208.165): 56 data bytes
64 bytes from 216.58.208.165: icmp_seq=0 ttl=55 time=22.596 ms
64 bytes from 216.58.208.165: icmp_seq=1 ttl=55 time=17.817 ms
64 bytes from 216.58.208.165: icmp_seq=2 ttl=55 time=16.311 ms
64 bytes from 216.58.208.165: icmp_seq=3 ttl=55 time=19.129 ms
64 bytes from 216.58.208.165: icmp_seq=4 ttl=55 time=19.212 ms
64 bytes from 216.58.208.165: icmp_seq=5 ttl=55 time=17.565 ms
One long run ping...
Mostly 16-20ms with a group of longer times 160-333 ms plus 1 time out, within 1 minute:
64 bytes from 216.58.206.69: icmp_seq=958 ttl=55 time=20.681 ms
64 bytes from 216.58.206.69: icmp_seq=959 ttl=55 time=19.939 ms
64 bytes from 216.58.206.69: icmp_seq=960 ttl=55 time=16.757 ms
64 bytes from 216.58.206.69: icmp_seq=961 ttl=55 time=18.381 ms
^C
--- googlemail.l.google.com ping statistics ---
962 packets transmitted, 961 packets received, 0.1% packet loss
round-trip min/avg/max/stddev = 16.183/30.233/333.334/34.235 ms


In the looping log, of 215 tests (over 1hr30) there were 
41 with stddev > 10ms and within that
2 significantly longer than all others in list of 41 high values.
Just 2 timeouts among the 1290 packets.
I estimate the median stddev of all 215 groups is below 2ms.
round-trip min/avg/max/stddev = 17.973/29.212/75.492/20.952 ms
round-trip min/avg/max/stddev = 17.831/148.231/655.005/253.413 ms       <<<<OUTLIER
round-trip min/avg/max/stddev = 18.160/91.215/168.180/71.429 ms
round-trip min/avg/max/stddev = 17.831/36.905/124.261/39.081 ms
round-trip min/avg/max/stddev = 17.030/41.913/97.156/29.229 ms
round-trip min/avg/max/stddev = 20.417/90.338/163.927/69.618 ms
round-trip min/avg/max/stddev = 19.089/74.071/139.106/53.375 ms
round-trip min/avg/max/stddev = 20.022/43.630/81.930/23.923 ms
round-trip min/avg/max/stddev = 12.696/30.170/63.344/19.366 ms
round-trip min/avg/max/stddev = 13.370/34.248/57.211/19.753 ms
round-trip min/avg/max/stddev = 16.501/34.540/120.941/38.643 ms
round-trip min/avg/max/stddev = 17.548/44.827/77.549/27.347 ms
round-trip min/avg/max/stddev = 10.658/36.033/74.942/23.527 ms
round-trip min/avg/max/stddev = 11.792/28.949/55.218/17.618 ms
round-trip min/avg/max/stddev = 14.430/19.863/42.519/10.211 ms
round-trip min/avg/max/stddev = 14.368/41.714/80.579/28.207 ms
round-trip min/avg/max/stddev = 17.835/90.269/178.137/72.572 ms
round-trip min/avg/max/stddev = 17.559/37.252/70.430/20.277 ms
round-trip min/avg/max/stddev = 17.076/35.206/118.173/37.115 ms
round-trip min/avg/max/stddev = 16.355/34.665/66.028/20.378 ms
round-trip min/avg/max/stddev = 16.299/89.416/169.889/72.688 ms
round-trip min/avg/max/stddev = 16.715/26.858/59.148/15.025 ms
round-trip min/avg/max/stddev = 17.200/89.233/164.291/71.138 ms
round-trip min/avg/max/stddev = 16.964/68.166/116.674/47.143 ms
round-trip min/avg/max/stddev = 23.724/40.444/60.782/12.613 ms
round-trip min/avg/max/stddev = 16.915/56.916/98.570/37.378 ms
round-trip min/avg/max/stddev = 16.771/103.734/255.227/92.845 ms
round-trip min/avg/max/stddev = 20.079/34.772/100.036/29.215 ms
round-trip min/avg/max/stddev = 9.962/34.734/89.748/34.223 ms
round-trip min/avg/max/stddev = 9.846/90.394/172.229/79.870 ms
round-trip min/avg/max/stddev = 9.183/42.674/84.387/32.555 ms
round-trip min/avg/max/stddev = 17.363/27.662/50.451/12.897 ms
round-trip min/avg/max/stddev = 18.377/33.614/102.643/30.880 ms
round-trip min/avg/max/stddev = 15.842/31.924/65.313/18.461 ms
round-trip min/avg/max/stddev = 16.372/43.425/173.426/58.146 ms
round-trip min/avg/max/stddev = 16.185/37.991/79.777/28.921 ms
round-trip min/avg/max/stddev = 15.778/43.285/75.496/27.587 ms
round-trip min/avg/max/stddev = 15.927/74.272/134.963/57.610 ms
round-trip min/avg/max/stddev = 15.381/54.973/96.510/37.164 ms
round-trip min/avg/max/stddev = 14.092/40.288/73.809/26.696 ms
round-trip min/avg/max/stddev = 13.996/160.074/885.082/324.234 ms       <<<<OUTLIER
round-trip min/avg/max/stddev = 10.061/24.240/90.711/29.738 ms
round-trip min/avg/max/stddev = 9.480/16.247/45.211/12.961 ms

To me this says the servers run pretty consistently with the occasional 
(around 1 per 1000) delay above 0.5s or timeout....
they seem to change server every 4m30 approx. Maybe server selected at random as one time in my list of 30 was a double period of 9 mins, so maybe same server reselected... 
Times of first pings with different server:
Thu 13 Dec 2018 13:56:59 GMT PING googlemail.l.google.com (216.58.208.165): 56 data bytes
Thu 13 Dec 2018 14:00:23 GMT PING googlemail.l.google.com (216.58.204.69): 56 data bytes
Thu 13 Dec 2018 14:04:59 GMT PING googlemail.l.google.com (216.58.214.5): 56 data bytes
Thu 13 Dec 2018 14:09:34 GMT PING googlemail.l.google.com (216.58.206.37): 56 data bytes
Thu 13 Dec 2018 14:14:10 GMT PING googlemail.l.google.com (216.58.213.69): 56 data bytes
Thu 13 Dec 2018 14:19:10 GMT PING googlemail.l.google.com (216.58.206.69): 56 data bytes
Thu 13 Dec 2018 14:23:46 GMT PING googlemail.l.google.com (216.58.206.133): 56 data bytes
Thu 13 Dec 2018 14:28:22 GMT PING googlemail.l.google.com (216.58.213.101): 56 data bytes
Thu 13 Dec 2018 14:32:57 GMT PING googlemail.l.google.com (216.58.206.69): 56 data bytes
Thu 13 Dec 2018 14:37:33 GMT PING googlemail.l.google.com (216.58.204.5): 56 data bytes
Thu 13 Dec 2018 14:42:33 GMT PING googlemail.l.google.com (172.217.23.5): 56 data bytes
Thu 13 Dec 2018 14:47:09 GMT PING googlemail.l.google.com (216.58.198.165): 56 data bytes
Thu 13 Dec 2018 14:51:45 GMT PING googlemail.l.google.com (216.58.206.101): 56 data bytes
Thu 13 Dec 2018 14:56:20 GMT PING googlemail.l.google.com (216.58.214.5): 56 data bytes
OK time to review this one?
Gmails swapping of servers is noted but does not seem implicated in the problem.
gmail server response has been checked and DOES have drops and slowness >0.5s at times (order of 1 per 1000 connects).

With TB set to ask for gmail at 5 min intervals I see occasional spins and waits for 30s. These are typified by 35s of TCP retransmissions, then a reset and a new login/stream connection. There are many other unseen instances of identical network events, unseen because I was not using TB at the time. These network reset interactions also happen with other non-gmail servers.

With TB set to 29 minute collections (which I am back to examining  again having got a feel for the 5 minute situation) I see more significant delay issues, so far as I know only/mainly gmail account. My very first click on an empty inbox in gmail gave a 1m10s (2x the typical 35s) during which the UI showed the spin icons and was unresponsive. I believe these events typically use relatively high cpu, they have sometimes caused the OS to take a spin dump analysis of high cpu or excess wakes. 

Are these events of further use and interest?
Should either or both be separated out continued with a clean start and this initial investigation closed?

I continue to believe there is some issue/bug here AND I now have a deeper understanding and a sort of work-around!
I finally saw something like you described but not on OSX (*). On linux I clicked onto Inbox of a non gmail account and the spinner remained active for an abnormally long time. I clicked on another folder of the same account and it responded fine (minimal spin) and went back to Inbox and it was still spinning. Then went to other folders that were OK and back to Inbox and it kept spinning. Did this a few times with the same result. Eventually, the click on Inbox showed no spin. I guess the time elapsed was about a minute or so before Inbox was not spinning. Also, during this time the "progress" indicator along the bottom was moving.

I wasn't recording with wireshark or making an imap log when this happened so I have no clue as to what caused the spin on non-gmail Inbox. 

Other than maybe one lost packet I don't see anything wrong with the pings you show above. 

Since you see this a lot more than I do in your environment, would it be possible to record and attach the imap log of what is going one when you see the spin? In addition, a full wireshark trace during this time might be helpful. We need to see what exactly happens before the spin starts and how it gets out of it. Otherwise, I can't think of anything thing else to try.

(*) I still haven't seen any problems running latest tb 60.* on MBA.
If you produce a wireshark trace you will need to use the stunnel technique I describe above due to the TLS encryption. Of course, this isn't necessary if you only record the imap log using the methods described here: https://wiki.mozilla.org/MailNews:Logging
I had an unusual event night 14-15th that took down 3 apps, no dumps made. I can no longer run Wireshark since then despite updating to latest version. Am looking into that!
I have found that virginmedia do have events and oddities on their IMAp server responses too, so collecting fuller detail on that. They also change servers at times and today are operating with a different range NL-LEASEWEB-20120124 that seem provided by RIPE in Holland who seem to be their super-ISP internet ranges provider. 
(that is surely not the right terminology from me, but may be good enough)

I already have some suitable logs, collected in LNAV with output of tcpdump:::: but it is 250 lines or so for a 2 minute multiple reset event. There are 3 types of logs interleaved, they can be distinguished by the format of the date/time

Dec 15 14:04:16            a syslog line from MacOS, not many of these in sample
14:06:34.107190 IP         a tcpdump line
2018-12-15 14:02:53.703204 UTC      a Thunderbird map logging line
They are also bracketed on the left into groups by source...
14:02:26 having just read and deleted 3 small emails in xxxxxx gmail went to the 265kb Urb Transp, long wait "downloading..." (no spinner seen???). Then the deleted emails appeared to come back and then one by one went away again and the email displayed... 
[So TB was replaying my actions once it had a live connection again?]
No wireshark as it will not run at present, did have tcpdump & imap in LNAV.
You do need q wide display, maybe cut and paste into a wide window?

circa 14:02 in LNAV traces:
─14:02:08.582144 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757569362 ecr 433453434]│
┌2018-12-15 14:02:08.582036 UTC - [80456:Unnamed thread 0x12239fb40]: I/IMAP 0x126e77800:imap.gmail.com:S-INBOX:SendData: DONE                                │
│2018-12-15 14:02:08.582316 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19809>9           │
│2018-12-15 14:02:08.582320 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:08.582322 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:08.582343 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
┌14:02:08.709348 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757569488 ecr 433453434]│
│14:02:08.868549 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757569646 ecr 433453434]│
│14:02:09.241900 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757570014 ecr 433453434]│
└14:02:09.782173 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757570550 ecr 433453434]│
┌2018-12-15 14:02:10.625641 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>1           │
│2018-12-15 14:02:10.625646 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX┤
│2018-12-15 14:02:10.625648 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf┤
└2018-12-15 14:02:10.625666 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/┤
┌14:02:10.662194 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757571422 ecr 433453434]┤
│14:02:12.230290 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757572966 ecr 433453434]┤
└14:02:14.419872 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757575118 ecr 433453434]┤
┌2018-12-15 14:02:18.212350 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>1           │
│2018-12-15 14:02:18.212357 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:18.212361 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
│2018-12-15 14:02:18.212392 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
│2018-12-15 14:02:18.212766 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>9           │
│2018-12-15 14:02:18.212772 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:18.212775 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:18.212836 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
─14:02:18.623685 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757579222 ecr 433453434]│
┌2018-12-15 14:02:20.249907 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>1           │
│2018-12-15 14:02:20.249946 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:20.249950 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:20.249983 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/┤
─14:02:22.770054 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757583326 ecr 433453434]┤
┌2018-12-15 14:02:24.420030 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>1           ┤
│2018-12-15 14:02:24.420035 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX┤
│2018-12-15 14:02:24.420037 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf┤
│2018-12-15 14:02:24.420058 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/┤
2018-12-15 14:02:24.420340 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>9           │
│2018-12-15 14:02:24.420343 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:24.420345 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
│2018-12-15 14:02:24.420362 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
│2018-12-15 14:02:24.423547 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19812                   │
│2018-12-15 14:02:24.423551 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:24.423554 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:24.423571 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
┌14:02:26.913072 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757587430 ecr 433453434]│
│14:02:31.020117 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757591534 ecr 433453434]│
│14:02:35.125825 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757595639 ecr 433453434]│
└14:02:39.231262 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [P.], seq 1333:1373, ack 4501, win 4096, options [nop,nop,TS val 757599743 ecr 433453434]│
─Dec 15 14:02:41 --- last message repeated 2 times ---                                                                                                        ┤
─14:02:43.370587 IP 192.168.10.199.55286 > 108.177.15.108.993: Flags [R.], seq 1373, ack 4501, win 4096, length 0                                             ┤
┌2018-12-15 14:02:43.371684 UTC - [80456:Unnamed thread 0x12239fb40]: I/IMAP 0x126e77800:imap.gmail.com:S-INBOX:TellThreadToDie: close socket connection      ┤
│2018-12-15 14:02:43.372084 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to retry queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsg┤
│2018-12-15 14:02:43.372234 UTC - [80456:Main Thread]: I/IMAP retrying  url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19809>1         ┤
│2018-12-15 14:02:43.372714 UTC - [80456:Main Thread]: I/IMAP 0x111116000:imap.gmail.com:NA:SetupWithUrlCallback: clearing IMAP_CONNECTION_IS_OPEN            ┤
|2018-12-15 14:02:43.372771 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:NA:ProcessCurrentURL: entering                        │
└2018-12-15 14:02:43.372777 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:NA:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@imap.│
┌14:02:43.389998 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [S], seq 2236663962, win 65535, options [mss 1460,nop,wscale 5,nop,nop,TS val 757603866 e│
│14:02:43.412156 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [S.], seq 3536274599, ack 2236663963, win 60192, options [mss 1380,sackOK,TS val 22040530│
│14:02:43.412194 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1, win 4104, options [nop,nop,TS val 757603888 ecr 2204053076], length 0        │
│14:02:43.413314 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1:556, ack 1, win 4104, options [nop,nop,TS val 757603889 ecr 2204053076], leng│
│14:02:43.440580 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 556, win 240, options [nop,nop,TS val 2204053105 ecr 757603889], length 0       │
│14:02:43.440841 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1:148, ack 556, win 240, options [nop,nop,TS val 2204053105 ecr 757603889], len│
│14:02:43.440873 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 148, win 4099, options [nop,nop,TS val 757603915 ecr 2204053105], length 0      │
│14:02:43.441131 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 556:607, ack 148, win 4099, options [nop,nop,TS val 757603915 ecr 2204053105], │
│14:02:43.462801 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 148:246, ack 607, win 240, options [nop,nop,TS val 2204053127 ecr 757603915], l│
│14:02:43.462850 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 246, win 4096, options [nop,nop,TS val 757603937 ecr 2204053127], length 0      │
└14:02:43.463606 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 607:650, ack 246, win 4096, options [nop,nop,TS val 757603937 ecr 2204053127], ┤
─2018-12-15 14:02:43.463465 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:NA:SendData: 1 capability                             ┤
┌14:02:43.488702 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 246:493, ack 650, win 240, options [nop,nop,TS val 2204053153 ecr 757603937], l┤
│14:02:43.488753 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 493, win 4088, options [nop,nop,TS val 757603962 ecr 2204053153], length 0      ┤
└14:02:43.647307 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 650:928, ack 493, win 4096, options [nop,nop,TS val 757604114 ecr 2204053153], ┤
─2018-12-15 14:02:43.647166 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:NA:SendData: Logging suppressed for this command (it p│
┌14:02:43.712275 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 928, win 244, options [nop,nop,TS val 2204053377 ecr 757604114], length 0       │
│14:02:43.778165 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 493:787, ack 928, win 244, options [nop,nop,TS val 2204053442 ecr 757604114], l│
│14:02:43.778193 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 787, win 4086, options [nop,nop,TS val 757604242 ecr 2204053442], length 0      │
└14:02:43.778634 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 928:977, ack 787, win 4096, options [nop,nop,TS val 757604242 ecr 2204053442], │
─2018-12-15 14:02:43.778560 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:A:SendData: 3 COMPRESS DEFLATE                        │
┌14:02:43.800121 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 977, win 244, options [nop,nop,TS val 2204053464 ecr 757604242], length 0       │
│14:02:43.801288 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 787:830, ack 977, win 244, options [nop,nop,TS val 2204053465 ecr 757604242], l│
│14:02:43.801319 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 830, win 4094, options [nop,nop,TS val 757604264 ecr 2204053465], length 0      │
└14:02:43.801581 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 977:1058, ack 830, win 4096, options [nop,nop,TS val 757604264 ecr 2204053465],│
─2018-12-15 14:02:43.801495 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:A:SendData: 4 ID ("name" "Thunderbird" "version" "60.3│
┌14:02:43.831681 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 830:1010, ack 1058, win 244, options [nop,nop,TS val 2204053493 ecr 757604264],│
│14:02:43.831721 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1010, win 4090, options [nop,nop,TS val 757604294 ecr 2204053493], length 0     │
└14:02:43.832539 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1058:1111, ack 1010, win 4096, options [nop,nop,TS val 757604294 ecr 2204053493┤
─2018-12-15 14:02:43.832443 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:A:SendData: 5 select "INBOX"                          ┤
┌14:02:43.899483 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1111, win 244, options [nop,nop,TS val 2204053564 ecr 757604294], length 0      ┤
│14:02:44.368805 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1010:1297, ack 1111, win 244, options [nop,nop,TS val 2204054033 ecr 757604294]┤
│14:02:44.368809 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1297:1343, ack 1111, win 244, options [nop,nop,TS val 2204054033 ecr 757604294]┤
│14:02:44.368859 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1297, win 4087, options [nop,nop,TS val 757604824 ecr 2204054033], length 0     ┤
│14:02:44.368881 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1343, win 4085, options [nop,nop,TS val 757604824 ecr 2204054033], length 0     │
└14:02:44.369574 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1111:1161, ack 1343, win 4096, options [nop,nop,TS val 757604824 ecr 2204054033│
─2018-12-15 14:02:44.369422 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 6 getquotaroot "INBOX"              │
┌14:02:44.396365 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1161, win 244, options [nop,nop,TS val 2204054060 ecr 757604824], length 0      │
│14:02:44.398604 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1343:1433, ack 1161, win 244, options [nop,nop,TS val 2204054063 ecr 757604824]│
│14:02:44.398650 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1433, win 4093, options [nop,nop,TS val 757604852 ecr 2204054063], length 0     │
└14:02:44.399392 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1161:1219, ack 1433, win 4096, options [nop,nop,TS val 757604852 ecr 2204054063│
─2018-12-15 14:02:44.399247 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 7 UID fetch 1:* (FLAGS)             │
┌14:02:44.448194 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1433:1515, ack 1219, win 244, options [nop,nop,TS val 2204054112 ecr 757604852]│
│14:02:44.448198 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1515:1553, ack 1219, win 244, options [nop,nop,TS val 2204054112 ecr 757604852]│
│14:02:44.448253 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1515, win 4093, options [nop,nop,TS val 757604901 ecr 2204054112], length 0     │
│14:02:44.448268 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1553, win 4092, options [nop,nop,TS val 757604901 ecr 2204054112], length 0     │
└14:02:44.450630 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1219:1423, ack 1553, win 4096, options [nop,nop,TS val 757604903 ecr 2204054112┤
─2018-12-15 14:02:44.450412 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 8 UID fetch 19809:19811 (UID X-GM-MS┤
┌14:02:44.514354 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1423, win 249, options [nop,nop,TS val 2204054179 ecr 757604903], length 0      ┤
│14:02:44.575094 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1553:1648, ack 1423, win 249, options [nop,nop,TS val 2204054235 ecr 757604903]┤
│14:02:44.575140 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 1648, win 4093, options [nop,nop,TS val 757605026 ecr 2204054235], length 0     ┤
│14:02:44.575552 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 1648:2342, ack 1423, win 249, options [nop,nop,TS val 2204054235 ecr 757604903]┤
—14:02:44.575579 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2342, win 4074, options [nop,nop,TS val 757605026 ecr 2204054235], length 0     │
┌2018-12-15 14:02:44.575988 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:OPEN Size: 44945: Begin Message Downloa│
│2018-12-15 14:02:44.576104 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stre│
│2018-12-15 14:02:44.576279 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:OPEN Size: 44146: Begin Message Downloa│
│2018-12-15 14:02:44.576361 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stre│
│2018-12-15 14:02:44.576668 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:OPEN Size: 33420: Begin Message Downloa│
│2018-12-15 14:02:44.576761 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stre│
│2018-12-15 14:02:44.588248 UTC - [80456:Main Thread]: I/IMAP queuing url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19811                   │
│2018-12-15 14:02:44.588251 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:44.588253 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:44.588265 UTC - [80456:Main Thread]: I/IMAP failed creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/│
─14:02:44.589212 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1423:1487, ack 2342, win 4096, options [nop,nop,TS val 757605040 ecr 2204054235│
─2018-12-15 14:02:44.589092 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 9 uid store 19809 +Flags (\Seen)    ┤
┌14:02:44.610737 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1487, win 249, options [nop,nop,TS val 2204054275 ecr 757605040], length 0      ┤
│14:02:44.637973 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2342:2380, ack 1487, win 249, options [nop,nop,TS val 2204054302 ecr 757605040]┤
└14:02:44.638018 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2380, win 4094, options [nop,nop,TS val 757605088 ecr 2204054302], length 0     ┤
┌2018-12-15 14:02:44.638998 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX┤
│2018-12-15 14:02:44.639006 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf┤
2018-12-15 14:02:44.639070 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19809>9    │
└2018-12-15 14:02:44.639862 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
─14:02:44.640517 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1487:1537, ack 2380, win 4096, options [nop,nop,TS val 757605090 ecr 2204054302│
┌2018-12-15 14:02:44.640001 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
└2018-12-15 14:02:44.640371 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 10 uid store 19809 +Flags (\Seen \De│
┌14:02:44.705992 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1537, win 249, options [nop,nop,TS val 2204054369 ecr 757605090], length 0      │
│14:02:45.089029 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2380:2447, ack 1537, win 249, options [nop,nop,TS val 2204054753 ecr 757605090]│
└14:02:45.089080 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2447, win 4093, options [nop,nop,TS val 757605531 ecr 2204054753], length 0     │
┌2018-12-15 14:02:45.101090 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:45.101097 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
│2018-12-15 14:02:45.101145 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>1    │
│2018-12-15 14:02:45.101860 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
└2018-12-15 14:02:45.101944 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@┤
─14:02:45.102215 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1537:1581, ack 2447, win 4096, options [nop,nop,TS val 757605544 ecr 2204054753┤
─2018-12-15 14:02:45.102116 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 11 uid store 19810 +Flags (\Seen)   ┤
┌14:02:45.123824 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1581, win 249, options [nop,nop,TS val 2204054788 ecr 757605544], length 0      ┤
│14:02:45.670139 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2447:2495, ack 1581, win 249, options [nop,nop,TS val 2204055334 ecr 757605544]┤
│14:02:45.670179 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2495, win 4094, options [nop,nop,TS val 757606107 ecr 2204055334], length 0     ┤
14:02:45.670329 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2495:2535, ack 1581, win 249, options [nop,nop,TS val 2204055334 ecr 757605544]│
└14:02:45.670349 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2535, win 4094, options [nop,nop,TS val 757606107 ecr 2204055334], length 0     │
┌2018-12-15 14:02:45.679170 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:45.679175 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
│2018-12-15 14:02:45.679225 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>1    │
│2018-12-15 14:02:45.679627 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
└2018-12-15 14:02:45.679770 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
─14:02:45.680532 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1581:1620, ack 2535, win 4096, options [nop,nop,TS val 757606117 ecr 2204055334│
─2018-12-15 14:02:45.680443 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 12 uid store 19810 +Flags (\Seen)   │
┌14:02:45.702630 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1620, win 249, options [nop,nop,TS val 2204055367 ecr 757606117], length 0      │
│14:02:45.738789 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2535:2575, ack 1620, win 249, options [nop,nop,TS val 2204055403 ecr 757606117]│
└14:02:45.738835 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2575, win 4094, options [nop,nop,TS val 757606175 ecr 2204055403], length 0     │
┌2018-12-15 14:02:45.739808 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX┤
│2018-12-15 14:02:45.739815 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf┤
│2018-12-15 14:02:45.739875 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19810>9    ┤
│2018-12-15 14:02:45.740646 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   ┤
└2018-12-15 14:02:45.740798 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@┤
─14:02:45.743588 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1620:1662, ack 2575, win 4096, options [nop,nop,TS val 757606179 ecr 2204055403┤
─2018-12-15 14:02:45.743490 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 13 uid store 19810 +Flags (\Seen \De│
┌14:02:45.805279 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1662, win 249, options [nop,nop,TS val 2204055470 ecr 757606179], length 0      │
│14:02:46.511394 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2575:2622, ack 1662, win 249, options [nop,nop,TS val 2204056051 ecr 757606179]│
│14:02:46.511398 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2622:2653, ack 1662, win 249, options [nop,nop,TS val 2204056051 ecr 757606179]│
│14:02:46.511399 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2622:2653, ack 1662, win 249, options [nop,nop,TS val 2204056101 ecr 757606179]│
│14:02:46.511481 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2622, win 4094, options [nop,nop,TS val 757606940 ecr 2204056051], length 0     │
│14:02:46.511496 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2653, win 4093, options [nop,nop,TS val 757606940 ecr 2204056051], length 0     │
└14:02:46.511505 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2653, win 4093, options [nop,nop,TS val 757606940 ecr 2204056101,nop,nop,sack 1 │
┌2018-12-15 14:02:46.518531 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:46.518538 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:46.518584 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>1    │
─14:02:46.519817 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1662:1704, ack 2653, win 4096, options [nop,nop,TS val 757606948 ecr 2204056101│
┌2018-12-15 14:02:46.519373 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   ┤
│2018-12-15 14:02:46.519502 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@┤
└2018-12-15 14:02:46.519710 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 14 uid store 19811 +Flags (\Seen)   ┤
┌14:02:46.540237 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1704, win 249, options [nop,nop,TS val 2204056204 ecr 757606948], length 0      ┤
│14:02:47.945017 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2653:2700, ack 1704, win 249, options [nop,nop,TS val 2204057502 ecr 757606948]┤
└14:02:47.945067 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2700, win 4094, options [nop,nop,TS val 757608363 ecr 2204057502], length 0     ┤
┌2018-12-15 14:02:47.950702 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:47.950707 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
└2018-12-15 14:02:47.950747 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>1    │
─14:02:47.951465 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1704:1743, ack 2700, win 4096, options [nop,nop,TS val 757608369 ecr 2204057502│
┌2018-12-15 14:02:47.951091 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
│2018-12-15 14:02:47.951121 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
└2018-12-15 14:02:47.951363 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 15 uid store 19811 +Flags (\Seen)   │
┌14:02:47.972105 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1743, win 249, options [nop,nop,TS val 2204057636 ecr 757608369], length 0      │
│14:02:48.551007 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2700:2739, ack 1743, win 249, options [nop,nop,TS val 2204058215 ecr 757608369]│
└14:02:48.551092 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2739, win 4094, options [nop,nop,TS val 757608963 ecr 2204058215], length 0     │
┌2018-12-15 14:02:48.551991 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX│
│2018-12-15 14:02:48.551997 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgf│
│2018-12-15 14:02:48.552057 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/addmsgflags>UID>/INBOX>19811>9    ┤
│2018-12-15 14:02:48.552813 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   ┤
└2018-12-15 14:02:48.552965 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@┤
─14:02:48.553467 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1743:1785, ack 2739, win 4096, options [nop,nop,TS val 757608965 ecr 2204058215┤
─2018-12-15 14:02:48.553318 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 16 uid store 19811 +Flags (\Seen \De┤
┌14:02:48.576748 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1785, win 249, options [nop,nop,TS val 2204058241 ecr 757608965], length 0      ┤
│14:02:50.097713 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2739:2786, ack 1785, win 249, options [nop,nop,TS val 2204059664 ecr 757608965]│
└14:02:50.097788 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2786, win 4094, options [nop,nop,TS val 757610498 ecr 2204059664], length 0     │
┌2018-12-15 14:02:50.103568 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19812│
│2018-12-15 14:02:50.103575 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>U│
│2018-12-15 14:02:50.103619 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19812            │
│2018-12-15 14:02:50.104137 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
└2018-12-15 14:02:50.104230 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
─14:02:50.118609 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1785:1841, ack 2786, win 4096, options [nop,nop,TS val 757610518 ecr 2204059664│
─2018-12-15 14:02:50.118530 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 17 UID fetch 19812 (BODYSTRUCTURE)  │
┌14:02:50.173723 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1841, win 249, options [nop,nop,TS val 2204059838 ecr 757610518], length 0      │
│14:02:50.347831 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2786:2849, ack 1841, win 249, options [nop,nop,TS val 2204060012 ecr 757610518]│
│14:02:50.347879 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 2849, win 4094, options [nop,nop,TS val 757610744 ecr 2204060012], length 0     │
│14:02:50.348263 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 2849:3040, ack 1841, win 249, options [nop,nop,TS val 2204060012 ecr 757610518]┤
│14:02:50.348277 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 3040, win 4090, options [nop,nop,TS val 757610744 ecr 2204060012], length 0     ┤
└14:02:50.348800 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1841:1890, ack 3040, win 4096, options [nop,nop,TS val 757610744 ecr 2204060012┤
─2018-12-15 14:02:50.348728 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 18 UID fetch 19812 (UID RFC822.SIZE ┤
┌14:02:50.374337 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1890, win 249, options [nop,nop,TS val 2204060039 ecr 757610744], length 0      ┤
│14:02:50.709619 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 3040:3135, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744]┤
│14:02:50.709621 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 3135:4553, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744],│
│14:02:50.709622 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 4553:4712, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744]│
│14:02:50.709658 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 3135, win 4093, options [nop,nop,TS val 757611103 ecr 2204060247], length 0     │
│14:02:50.709680 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 4712, win 4043, options [nop,nop,TS val 757611103 ecr 2204060247], length 0     │
│14:02:50.709741 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 4712:6130, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744]│
│14:02:50.709755 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 6130, win 4096, options [nop,nop,TS val 757611103 ecr 2204060247], length 0     │
│14:02:50.709760 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 6130, win 4096, options [nop,nop,TS val 757611103 ecr 2204060247], length 0     │
│14:02:50.709873 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 6130:7229, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744]│
└14:02:50.709891 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 7229, win 4061, options [nop,nop,TS val 757611103 ecr 2204060247], length 0     │
─2018-12-15 14:02:50.709936 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:OPEN Size: 271121: Begin Message Downlo│
┌14:02:50.710076 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 7229:8647, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744],│
│14:02:50.710077 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 8647:10065, ack 1890, win 249, options [nop,nop,TS val 2204060247 ecr 757610744]│
│14:02:50.710093 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 10065, win 4007, options [nop,nop,TS val 757611103 ecr 2204060247], length 0    ┤
│14:02:50.710168 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 10065, win 4096, options [nop,nop,TS val 757611103 ecr 2204060247], length 0    ┤
│14:02:50.710177 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 10065:11483, ack 1890, win 249, options [nop,nop,TS val 2204060248 ecr 757610744┤
│14:02:50.710580 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 11483:12901, ack 1890, win 249, options [nop,nop,TS val 2204060248 ecr 757610744┤
│14:02:50.710581 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 12901:14319, ack 1890, win 249, options [nop,nop,TS val 2204060250 ecr 757610744┤
│14:02:50.710596 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 12901, win 4051, options [nop,nop,TS val 757611103 ecr 2204060248], length 0    ┤
14:02:50.710685 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 14319, win 4094, options [nop,nop,TS val 757611104 ecr 2204060250], length 0    │
│14:02:50.710692 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 14319:15737, ack 1890, win 249, options [nop,nop,TS val 2204060250 ecr 757610744│
│14:02:50.710810 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 15737:17155, ack 1890, win 249, options [nop,nop,TS val 2204060251 ecr 757610744│
│14:02:50.710823 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 17155, win 4051, options [nop,nop,TS val 757611104 ecr 2204060250], length 0    │
│14:02:50.710936 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 17155:18573, ack 1890, win 249, options [nop,nop,TS val 2204060251 ecr 757610744│
│14:02:50.711034 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 18573, win 4096, options [nop,nop,TS val 757611104 ecr 2204060251], length 0    │
│14:02:50.711053 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 18573:19991, ack 1890, win 249, options [nop,nop,TS val 2204060253 ecr 757610744│
│14:02:50.712660 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 19991:21409, ack 1890, win 249, options [nop,nop,TS val 2204060253 ecr 757610744│
│14:02:50.712662 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 21409:22827, ack 1890, win 249, options [nop,nop,TS val 2204060255 ecr 757610744│
│14:02:50.712678 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 21409, win 4051, options [nop,nop,TS val 757611105 ecr 2204060253], length 0    │
│14:02:50.712753 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 22827:24245, ack 1890, win 249, options [nop,nop,TS val 2204060255 ecr 757610744│
│14:02:50.712761 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 24245, win 4002, options [nop,nop,TS val 757611105 ecr 2204060255], length 0    │
│14:02:50.712792 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 24245, win 4089, options [nop,nop,TS val 757611105 ecr 2204060255], length 0    ┤
│14:02:50.712870 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 24245:25663, ack 1890, win 249, options [nop,nop,TS val 2204060256 ecr 757610744┤
│14:02:50.712994 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 25663:27081, ack 1890, win 249, options [nop,nop,TS val 2204060256 ecr 757610744┤
│14:02:50.713004 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 27081, win 4051, options [nop,nop,TS val 757611105 ecr 2204060256], length 0    ┤
│14:02:50.713130 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 27081:28499, ack 1890, win 249, options [nop,nop,TS val 2204060258 ecr 757610744┤
│14:02:50.713175 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 28499, win 4096, options [nop,nop,TS val 757611105 ecr 2204060258], length 0    ┤
│14:02:50.714442 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 28499:29917, ack 1890, win 249, options [nop,nop,TS val 2204060374 ecr 757610744│
│14:02:50.733467 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 29917:31335, ack 1890, win 249, options [nop,nop,TS val 2204060397 ecr 757611103│
│14:02:50.733493 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 31335, win 4051, options [nop,nop,TS val 757611125 ecr 2204060374], length 0    │
│14:02:50.733935 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 31335:32753, ack 1890, win 249, options [nop,nop,TS val 2204060397 ecr 757611103│
│14:02:50.734001 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 32753, win 4096, options [nop,nop,TS val 757611125 ecr 2204060397], length 0    │
│14:02:50.738100 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 32753:34171, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611103│
│14:02:50.738665 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 34171:35589, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611103│
│14:02:50.738683 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 35589, win 4051, options [nop,nop,TS val 757611129 ecr 2204060402], length 0    │
│14:02:50.738975 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 35589:37007, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611103│
│14:02:50.739036 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 37007, win 4096, options [nop,nop,TS val 757611129 ecr 2204060402], length 0    │
│14:02:50.740325 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 37007:38425, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611103│
│14:02:50.740991 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 38425:39843, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611103│
│14:02:50.741005 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 39843, win 4051, options [nop,nop,TS val 757611131 ecr 2204060402], length 0    ┤
│14:02:50.742308 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 39843:41261, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611105┤
│14:02:50.742369 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 41261, win 4096, options [nop,nop,TS val 757611132 ecr 2204060402], length 0    ┤
│14:02:50.742604 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 41261:42679, ack 1890, win 249, options [nop,nop,TS val 2204060402 ecr 757611105┤
│14:02:50.743634 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 42679:44097, ack 1890, win 249, options [nop,nop,TS val 2204060404 ecr 757611105┤
│14:02:50.743650 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 44097, win 4051, options [nop,nop,TS val 757611133 ecr 2204060402], length 0    ┤
│14:02:50.744224 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 44097:45515, ack 1890, win 249, options [nop,nop,TS val 2204060404 ecr 757611105│
│14:02:50.744274 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 45515, win 4096, options [nop,nop,TS val 757611133 ecr 2204060404], length 0    │
│14:02:50.745302 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 45515:46933, ack 1890, win 249, options [nop,nop,TS val 2204060406 ecr 757611105│
│14:02:50.745696 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 46933:48351, ack 1890, win 249, options [nop,nop,TS val 2204060406 ecr 757611105│
│14:02:50.745713 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 48351, win 4051, options [nop,nop,TS val 757611134 ecr 2204060406], length 0    │
│14:02:50.747223 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 48351:49769, ack 1890, win 249, options [nop,nop,TS val 2204060407 ecr 757611105│
│14:02:50.747336 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 49769, win 4096, options [nop,nop,TS val 757611135 ecr 2204060407], length 0    │
│14:02:50.747438 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 49769:51187, ack 1890, win 249, options [nop,nop,TS val 2204060407 ecr 757611105│
│14:02:50.748631 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 51187:52605, ack 1890, win 249, options [nop,nop,TS val 2204060409 ecr 757611105│
│14:02:50.748645 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 52605, win 4051, options [nop,nop,TS val 757611136 ecr 2204060407], length 0    │
│14:02:50.749449 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 52605:54023, ack 1890, win 249, options [nop,nop,TS val 2204060409 ecr 757611105│
│14:02:50.749515 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 54023, win 4096, options [nop,nop,TS val 757611136 ecr 2204060409], length 0    │
│14:02:50.750302 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 54023:55441, ack 1890, win 249, options [nop,nop,TS val 2204060411 ecr 757611105┤
│14:02:50.750607 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], seq 55441:56859, ack 1890, win 249, options [nop,nop,TS val 2204060411 ecr 757611105┤
│14:02:50.750620 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 56859, win 4051, options [nop,nop,TS val 757611137 ecr 2204060411], length 0    ┤
│14:02:50.759169 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 56859:57815, ack 1890, win 249, options [nop,nop,TS val 2204060423 ecr 75761112┤
└14:02:50.759189 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 57815, win 4066, options [nop,nop,TS val 757611145 ecr 2204060423], length 0    ┤
┌2018-12-15 14:02:50.760706 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:STREAM:CLOSE: Normal Message End Download Stre┤
│2018-12-15 14:02:50.765767 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP BODYSHELL:  Adding shell to cache.                                               │
│2018-12-15 14:02:50.906275 UTC - [80456:Main Thread]: I/IMAP considering playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19811│
│2018-12-15 14:02:50.906299 UTC - [80456:Main Thread]: I/IMAP creating protocol instance to play queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>U│
│2018-12-15 14:02:50.906338 UTC - [80456:Main Thread]: I/IMAP playing queued url:imap://xxxxxx@gmail.com@imap.gmail.com:993/fetch>UID>/INBOX>19811            │
│2018-12-15 14:02:50.947895 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
└2018-12-15 14:02:50.954288 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
─14:02:50.956541 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1890:1932, ack 57815, win 4096, options [nop,nop,TS val 757611338 ecr 220406042│
─2018-12-15 14:02:50.956440 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 19 UID fetch 19811 (UID RFC822.SIZE │
┌14:02:50.978051 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 1932, win 249, options [nop,nop,TS val 2204060642 ecr 757611338], length 0      │
│14:02:50.980953 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 57815:57854, ack 1932, win 249, options [nop,nop,TS val 2204060645 ecr 75761133│
│14:02:50.980987 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 57854, win 4094, options [nop,nop,TS val 757611361 ecr 2204060645], length 0    │
└14:02:50.981790 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1932:1976, ack 57854, win 4096, options [nop,nop,TS val 757611361 ecr 220406064│
─2018-12-15 14:02:50.981672 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 20 IDLE                             ┤
┌14:02:51.008536 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 57854:57898, ack 1976, win 249, options [nop,nop,TS val 2204060673 ecr 75761136┤
│14:02:51.008568 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 57898, win 4094, options [nop,nop,TS val 757611388 ecr 2204060673], length 0    ┤
└14:02:52.782164 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 1976:2016, ack 57898, win 4096, options [nop,nop,TS val 757613153 ecr 220406067┤
─2018-12-15 14:02:52.782035 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: DONE                                ┤
┌14:02:52.807864 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 57898:57953, ack 2016, win 249, options [nop,nop,TS val 2204062472 ecr 75761315┤
│14:02:52.807909 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 57953, win 4094, options [nop,nop,TS val 757613178 ecr 2204062472], length 0    │
└14:02:52.808740 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 2016:2058, ack 57953, win 4096, options [nop,nop,TS val 757613178 ecr 220406247│
┌2018-12-15 14:02:52.808145 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL: entering                   │
│2018-12-15 14:02:52.808316 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:ProcessCurrentURL:imap://xxxxxx%40gmail%2Ecom@│
└2018-12-15 14:02:52.808651 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 21 uid store 19812 +Flags (\Seen)   │
┌14:02:52.875465 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 2058, win 249, options [nop,nop,TS val 2204062540 ecr 757613178], length 0      │
│14:02:53.701824 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 57953:58031, ack 2058, win 249, options [nop,nop,TS val 2204063366 ecr 75761317│
│14:02:53.701884 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 58031, win 4093, options [nop,nop,TS val 757614064 ecr 2204063366], length 0    │
│14:02:53.701902 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 58070, win 4092, options [nop,nop,TS val 757614064 ecr 2204063366], length 0    │
└14:02:53.703334 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [P.], seq 2058:2097, ack 58070, win 4096, options [nop,nop,TS val 757614065 ecr 220406336│
─2018-12-15 14:02:53.703204 UTC - [80456:Unnamed thread 0x126cb32e0]: I/IMAP 0x111116000:imap.gmail.com:S-INBOX:SendData: 22 IDLE                             │
┌14:02:53.728245 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [.], ack 2097, win 249, options [nop,nop,TS val 2204063392 ecr 757614065], length 0      │
│14:02:53.729473 IP 108.177.15.109.993 > 192.168.10.199.55332: Flags [P.], seq 58070:58107, ack 2097, win 249, options [nop,nop,TS val 2204063394 ecr 75761406┤
└14:02:53.729510 IP 192.168.10.199.55332 > 108.177.15.109.993: Flags [.], ack 58107, win 4094, options [nop,nop,TS val 757614090 ecr 2204063394], length 0    ┤
┌Dec 15 14:04:16 --- last message repeated 2 times ---                                                                                                        ┤
└Dec 15 14:05:35 ··· Safari[2016]: tcp_connection_tls_session_error_callback_imp 12628 __tcp_connection_tls_session_callback_write_block_invoke.434 error 22  ┤
─14:06:34.107190 IP 192.168.10.199.55308 > 74.125.133.109.993: Flags [P.], seq 1269:1309, ack 1564, win 4096, options [nop,nop,TS val 757834236 ecr 84063830],┤
─2018-12-15 14:06:34.107054 UTC - [80456:Unnamed thread 0x12239fc70]: I/IMAP 0x122d66800:imap.gmail.com:S-INBOX:SendData: DONE                                ┤
NOTE I have reset back to 29mins polling of this gmail account allowing server notifications, another gmail account is polling at 10mins and allowing server push. I have not determined if there is any action from this other account in the time slot above, it would only be by bad luck of polling since the account was "quiet" at the time.
The tcpdump shows reset by Flags [R.] or similar.

However I have no idea if the retransmission types of event that WS can infer can be determined in the tcpdump list. In general I have found it a VERY stable pattern that there is the sequence of 10 or so TCP packets with sub-1 sec gaps gradually extending to 5 or so seconds, 35s in total, then the reset and finally a TLS login and a new stream connection [change in client port numbers visible in tcpdump list].
Thanks for the info but haven't had a chance to go over it yet but will right now. However, one thing I should mention: it's probably better not to dump long log files in the comment area (re: comment 66). Would be better and easier for me to access them as text file attachments and others that may be receiving bug mail (probably at least Wayne and Jorg) won't receive huge emails with all the logs.
Trying to parse comment 66 which is a bit hard. Could you just attach the raw tcpdump output file and the raw imap log as separate text files? The lnav thing seems to cut off and put in special chars that mess up the display when I copy/paste comment 66 into a text editor, either that or bugzilla is doing it, not sure. I can correlate the times on them manually if you can provide separate flat text files with no special characters. If you can't provide separate files, then please just attach the raw file that I assume is produced by lnav (using Attach File line above) that you dumped into comment 66. Thanks.
Ok, I don't see much interesting in most of comment 66 so you can skip attaching separate files like I requested (but in future please do that). I do see right before tb resets (request connection shutdown) the connection there are server retransmits of the same packet similar to the tcp retransmission you see in wireshark.

To me this looks pretty much like the imap server is just not answering tb when it tries to do an action. In comment 66 the action was just exit IDLE state by sending a DONE command.

Maybe you answered this before, but do you still have 5 "cached" connections per account configured on the "advanced server" page? This may matter if one connection fails (e.g., stops answering requests) so you still a few more for backup that can be switched to. I do see "unable to obtain a protocol instance" errors that indicate probably network error. A "protocol" instance is basically a server connection and its associated imap protocol thread.
Yes, it is set for 5 max connections. When I go to that gmail account I usually see a login in the progress bar for each of the first few mailboxes I click, so new connections are being added rather than redeploy an older one, often created just 10s before.

My suspicions have been similar to your observation in para 2, and this fits with the gmail map pings observations.

With the long polling time I have currently (29m) I see the problem more often. I believe because gmail has killed its end and already swapped to a new server for a new connection. 
Is it possible that TB tries too **** the stream that gmail has decided to drop? Maybe the Google approach to swapping servers is to set-up and point to services on a fresh server instance and then do some sort of kill/re-incarnation on the instance that has been retired. Maybe that is all standard documented stuff?

On 5 minute polling setup I tested for a few days I saw less spins as I suspect most of them occur when background polling happens and gmail has swapped but, typically, I am not active with that account (or at all using TB) at the time and so it is not observed.

I do also see the spins with non gmail servers, virginmedia namely, but much less frequently. They also employ server switching but at a much lower rate, around every 2 hours rather than 10mins. Imaps seems to be farmed out to server farms typically LEASEWEB-<NAME> usually relatively local in Holland but for 10mins this a.m. using USA based. Their pings are timed out way more than gmail with 3,614 timeouts to 13,922 replies (26%) over 22 hours and 11 server ip swaps.

I know nothing about the TB layering and structure at present, but...
I'd be minded to monitor the typical current duration of streams per account, with some sort of weighted floating average if timeouts can be visible at the appropriate level. Then use that information and the age of a current stream to decide when to die fast after, say, 2 quick tries and restart afresh early rather than spin and re-try for the longer periods I see.
Presumably we do not want to code for different names/types of server, which will doubtless change over time anyway and have simple robust ways of adjusting to observed service behaviour.

It seems faster to create a new stream more readily and use that to service a user demand and later continue to retry/timeout/deal-with/kill and clean up the old one? 
I suspect Tb rarely uses the full 5 streams... With my config it is hard to be sure which streams are for which account but I rarely seem to observe many open connections to gmail servers, sometimes there are 5 but that is across 2 gmail accounts. Typically I see 3 or 4 gmail streams open when I am not actively interacting with TB.

Apologies if this has unhelpful musings!
Since I rarely see the problem you see with gmail, I took one of the "problem" ip addresses you have posted previously, specifically 74.125.71.109, and set it as my current gmail server name. I don't know the physical location of this google server but I assume it is closer to you than to me (I'm Eastern US and you're, I assume, in UK or possibly Holland). So far, I don't see any problems. (It did ask me to confirm a possibly invalid certificate the first time I connected.)

The 5 connections are per account. So if you have 5 accounts and each are set to 5 cached connections then you may see with lsof up to 25 connections listed for thunderbird. To see the 25 you would have had visited recently (clicked on) 5 folders per account.

I would recommend this to minimize the problem you see:

1. Make sure each account has mail.server.serverX.timeout set to the default value of 29. This is done with Config Editor in Preferences | Advanced | General. (Note: Tb automatically adjusts an entry above 29 back to 29.)

2. Make sure on each account you have the Server Setting | Check for new messages every X minutes with X set to no more than 25. This will act as a keepalive to the servers so the connection won't be dropped due to inactivity. Gmail will drop the connection after 30 minutes if no activity.

3. Go ahead and also tick the Check new messages at start up and the Immediate notification options. The "check new messages at startup" really means login immediately to server. Without this, no login occurs until you click on a folder of the account/server. The immediate notification just enables the imap IDLE (if supported by server, most do) so the server tells tb when a new email "exists" and should be fetched by tb (it does not actually "push" emails to tb).
Thanks Gene, a helpful check list that I hope may also help others (if they ever read this far). 

1. All servers were already set to 29 minute timeouts.

2. Certainly helps a great deal. In part I was hoping to help find/fix a problem I feel is there somewhere but maybe avoidance is better, certainly "how to configure" information helps all users!

I wonder, in abstract, under this topic how the timer operates where there are multiple connection streams. Does each connection get exercised within the polling time, or are number 2 & up closed when inactive and just one maintained? If a single timer runs from the LAST contact to a server across any of the multiple connections then other connections to that server will inevitably be left longer unless all are used synchronously, which seems unlikely. Similar questions arise for timeouts too.
A topic I may come back to explore if there is ever time on my hands... I am sure it would be instructive!

3. Yes, those also are set.

For my own part I now know how to avoid the longer, heavier spins and there have been no OS spin dump checks of TB since 4 Dec.
Prior to that they were also seen on Nov 18, 19,28, 28 - there is certainly an improvement with 2 clean weeks!

I also noted the large number of timeouts available in config, a minefield (and while some specify ms or secs most do not!) so working in these areas must require a huge amount of detailed knowledge...

Is it time to close this one??
Well, glad it's better but sorry there is still occasionally a delay when accessing a folder. As I mentioned, I have a few times seen that too and will continue to try to determine the root cause (but I suspect it is just some kind of network glitch that tb is just responding to).

Yes, I have noticed that the units of most Config Editor parameters are not shown. That's probably why it says if you change anything there your "warranty is void" :).

I will go ahead and close the bug as "Invalid" since that is the only option unless it is a duplicate of another reported bug or if a definite fix is identified.
Status: UNCONFIRMED → RESOLVED
Closed: 5 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: