Bug 1299

Summary: warning when using JOGL on Mac OS X El Capitan
Product: [JogAmp] Nativewindow Reporter: Andy Skinner <askinner>
Component: macosxAssignee: Sven Gothel <sgothel>
Status: VERIFIED FIXED    
Severity: normal CC: gouessej, Peter.C.Mehlitz
Priority: P4    
Version: 2.4.0   
Hardware: All   
OS: macosx   
Type: DEFECT SCM Refs:
jogl d590c5df17650b3790bb434fb7529df874914a09
Workaround: ---
Bug Depends on:    
Bug Blocks: 1306, 1307    
Attachments: Sample Java program
patch 01 to fix the issue

Description Andy Skinner 2016-03-30 21:00:09 CEST
Created attachment 775 [details]
Sample Java program

When we run a very simple JOGL app (it just initializes JOGL and shuts down) on MAC OS X 10.11, El Capitan, we get a warning like this:

CoreAnimation: warning, deleted thread with uncommitted CATransaction; set CA_DEBUG_TRANSACTIONS=1 in environment to log backtraces. 

I've attached the app, TryJOGL.java.

Maybe I should have put this into JOGL instead of nativewindow, but I'm not sure where the lines are drawn.
Comment 1 Julien Gouesse 2016-04-06 15:00:23 CEST
Maybe this trick would help:
http://stackoverflow.com/a/19779554
Comment 2 Andy Skinner 2016-04-06 15:14:05 CEST
(In reply to Julien Gouesse from comment #1)
> Maybe this trick would help:
> http://stackoverflow.com/a/19779554

Does that mean we may be drawing on the wrong thread somewhere?

We have this trace:
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const: conn 0x172b7 token 0xdffffffffff5a3
Apr  5 17:29:10  java[90488] <Warning>: Backtrace (at 376568):
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  0   CoreGraphics                        0x00007fff8f31fecd CGSDisableUpdateToken + 210
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  1   AppKit                              0x00007fff9db42c20 ___disable_updates_sync_block_invoke_2 + 17
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  2   libdispatch.dylib                   0x00007fff94acd33f _dispatch_client_callout + 8
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  3   libdispatch.dylib                   0x00007fff94ace926 _dispatch_barrier_sync_f_invoke + 74
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  4   AppKit                              0x00007fff9db41de9 NSCGSDisableUpdates + 213
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  5   AppKit                              0x00007fff9db42fff NSCGSTransactionRunPreCommitActionsForOrder_ + 156
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  6   AppKit                              0x00007fff9db42014 NSCGSTransactionRunPreCommitActions_ + 21
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  7   AppKit                              0x00007fff9db424ea -[_NSCGSTransaction synchronize] + 33
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  8   AppKit                              0x00007fff9db42b38 NSCGSTransactionSynchronize + 76
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  9   AppKit                              0x00007fff9d916e09 -[NSSurface syncSurfaceWantsExtendedDynamicRange] + 150
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  10  AppKit                              0x00007fff9d24f3d9 -[NSSurface _createSurface] + 677
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  11  AppKit                              0x00007fff9d24ed34 -[NSSurface setFrame:] + 785
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  12  AppKit                              0x00007fff9d916f0f __38-[NSSurface syncToViewUnconditionally]_block_invoke + 154
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  13  AppKit                              0x00007fff9da43659 NSPerformVisuallyAtomicChange + 147
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  14  AppKit                              0x00007fff9d24e658 -[NSSurface syncToViewUnconditionally] + 100
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  15  AppKit                              0x00007fff9d916fa8 __37-[NSSurface orderSurface:relativeTo:]_block_invoke + 44
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  16  AppKit                              0x00007fff9da43659 NSPerformVisuallyAtomicChange + 147
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  17  AppKit                              0x00007fff9d24e52d -[NSSurface orderSurface:relativeTo:] + 160
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  18  AppKit                              0x00007fff9d51bece NSOpenGLContextAttachOnScreenViewSurface + 183
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  19  AppKit                              0x00007fff9d85f9ea __27-[NSOpenGLContext setView:]_block_invoke + 192
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  20  AppKit                              0x00007fff9da43659 NSPerformVisuallyAtomicChange + 147
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  21  AppKit                              0x00007fff9d507204 -[NSOpenGLContext setView:] + 119
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  22  libjogl_desktop.jnilib              0x000000012d293c46 createContext + 438
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  23  libjogl_desktop.jnilib              0x000000012d301f98 Java_jogamp_opengl_macosx_cgl_CGL_createContext0__JJZJZLjava_lang_Object_2I + 152
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  24  ???                                 0x000000010fc75758 0x0 + 4559689560
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  25  ???                                 0x000000010fc69175 0x0 + 4559638901
Apr  5 17:29:10  java[90488] <Warning>: void CGSUpdateManager::log() const:  26  ???                                 0x000000010fc69175 0x0 + 4559638901
CoreAnimation: warning, deleted thread with uncommitted CATransaction; set CA_DEBUG_TRANSACTIONS=1 in environment to log backtraces.
Comment 3 Julien Gouesse 2016-04-06 17:05:21 CEST
I don't talk about drawing but maybe we're retrieving some information from the "wrong" thread.
Comment 4 Andy Skinner 2016-04-15 14:19:50 CEST
I don't know how you rank importance of bugs, so am not asking for it to be "major", but I increased the importance from "minor" to "normal", and it is pretty important for us.  That is because our customers will see warnings that look fairly dire while they are using our software to do their work.

That long trace I included below shows up for our customers.

thanks
andy
Comment 5 Sven Gothel 2016-05-12 06:00:38 CEST
Created attachment 786 [details]
patch 01 to fix the issue
Comment 6 Sven Gothel 2016-05-12 06:06:59 CEST
(In reply to Sven Gothel from comment #5)
> Created attachment 786 [details]
> patch 01 to fix the issue

Below is the described issue, reproduced after 
updating to the OSX version on another test machine.

I was mislead first, i.e. assuming the OpenGL context itself was 
incorrect and wasted some time here. 
It also wasn't the specific thread at fault.
In the end it luckily turned out to be just the missing CATransaction,
i.e. the native create/destroy commands had to be encapsulated  
within [CATransaction begin] and [CATransaction commit].

I will run a full unit test on the machine used to reproduce the issue 
and will report on the result.

You may test w/ the patch, attachment 786 [details].

CoreAnimation: warning, deleted thread with uncommitted CATransaction; created by:
0   QuartzCore                          0x00007fff8f55769a _ZN2CA11Transaction4pushEv + 318
1   QuartzCore                          0x00007fff8f55719a _ZN2CA11Transaction15ensure_implicitEv + 276
2   QuartzCore                          0x00007fff8f560aa6 _ZN2CA11Transaction8set_seedEj + 30
3   QuartzCore                          0x00007fff8f560a60 +[CATransaction(CATransactionPrivate) generateSeed] + 56
4   AppKit                              0x00007fff889d4a51 +[NSDisplayCycle currentDisplayCycle] + 37
5   AppKit                              0x00007fff88a41fcf -[NSDisplayCycleObserver setNeedsDisplay:] + 34
6   AppKit                              0x00007fff88997be0 -[NSView _setWindow:] + 2291
7   AppKit                              0x00007fff88b6c9ca -[NSNextStepFrame initWithFrame:styleMask:owner:] + 154
8   AppKit                              0x00007fff889caa7c -[NSWindow _commonInitFrame:styleMask:backing:defer:] + 568
9   AppKit                              0x00007fff889c90c7 -[NSWindow _initContent:styleMask:backing:defer:contentView:] + 1475
10  AppKit                              0x00007fff889c8afd -[NSWindow initWithContentRect:styleMask:backing:defer:] + 45
11  libnativewindow_macosx.jnilib       0x000000012141e3fe Java_jogamp_nativewindow_macosx_OSXUtil_CreateNSWindow0 + 398
12  ???                                 0x00000001093d9954 0x0 + 4449999188
Comment 7 Sven Gothel 2016-05-12 06:13:04 CEST
(In reply to Andy Skinner from comment #4)
> I don't know how you rank importance of bugs, so am not asking for it to be
> "major", but I increased the importance from "minor" to "normal", and it is
> pretty important for us.  That is because our customers will see warnings
> that look fairly dire while they are using our software to do their work.
> 
> That long trace I included below shows up for our customers.
> 

I leaking or pending transaction might be of an issue here 
in regards to stability, hence a higher priority is appropriate.

We should assume the transaction to be completed after leaving the 
native function, otherwise the resource [1] may not be usable
or [2] not properly removed. 
IMO this is more a case of [2], i.e. a leaking resource,
since [1] using the resource would imply waiting for the transaction
and the caller thread hasn't died either.
Comment 8 Sven Gothel 2016-05-12 06:52:06 CEST
(In reply to Sven Gothel from comment #6)
> I will run a full unit test on the machine used to reproduce the issue 
> and will report on the result.
> 

No regressions, no occurrence of the CATransaction warning.
Comment 9 Andy Skinner 2016-05-16 14:01:27 CEST
Yes, it does appear to be fixed.  Thanks!

And the fix appears simple and makes lots of sense.

We've tried it in several different situations in which we use JOGL, and all are better.

thanks a lot,
andy
Comment 10 Julien Gouesse 2016-05-16 15:26:48 CEST
(In reply to Andy Skinner from comment #9)
> Yes, it does appear to be fixed.  Thanks!
> 
> And the fix appears simple and makes lots of sense.
> 
> We've tried it in several different situations in which we use JOGL, and all
> are better.
> 
> thanks a lot,
> andy

Sorry for having lowered the importance of this bug and thank you for confirming that Sven's patch just works :)
Comment 11 Sven Gothel 2018-01-15 07:22:33 CET
see commit d590c5df17650b3790bb434fb7529df874914a09