Ginga start very slow with Python 3.4 on Mac

[cdeil]

I tried starting ginga with the latest Astropy and Ginga git master versions and Python 3.4 on Mac OS X 10.10.

It does start, but runs for over a minute at 100% CPU and prints several errors and warnings to the console (I killed with CTRL + C after a minute or two): https://gist.github.com/cdeil/c89f1c4b8d1d4513e4c4

@ejeschke Can you reproduce or have an idea what is going on from the console output?

[cdeil]

One thing that is nice about python setup.py test in astropy and other affiliated packages is that it prints all relevant machine / version infos to the console (see example ... this helps a lot with bug reports).

With python setup.py test in Ginga that is not the case (see example) ... maybe you could add this there or even print it always when the reference viewer is started or at least add an option to print all relevant info for bug reports.

[cdeil]

With Python 2 I don't see the tracebacks, but the same behaviour of taking 100% CPU.

Here's two samples of the process ... maybe it helps you figure out where Ginga is stuck? https://gist.github.com/cdeil/6c7f5c83672dee03b38a https://gist.github.com/cdeil/7c0b4424fe0797db1a91

[ejeschke]

@cdeil, I have seen something like this in the past, but only on the first start of the program. Tell me, after you kill the program (when it happened to me I used force quit), and you start it a second time, does it start up normally thereafter?

I'm running os x 10.9.

[cdeil]

I've started ginga a few times in new terminals ... it's always the same issue. Not sure how to best debug this ...

[wtgee]

I was seeing this issue while playing with python 3.2 a few months back. I had successfully traced it back at the time and eliminated the slow startup time but unfortunately never merged the code. When I get back to desktop later tonight I'll try and dig it up. But, from memory, it did seem to be one specific call that was the problem.

On Wed, Dec 3, 2014, 08:45 Christoph Deil notifications@github.com wrote:

I've started ginga a few times in new terminals ... it's always the same issue. Not sure how to best debug this ...

— Reply to this email directly or view it on GitHub https://github.com/ejeschke/ginga/issues/57#issuecomment-65463960.

[ejeschke]

Does it happen if you run any of the examples? e.g. .../examples/qt/example2_qt.py

[ejeschke]

@wtgee, that would be great! Please report here if you find anything out.

[cdeil]

For qt/example2_qt.py I get these errors: https://gist.github.com/cdeil/4065a0cfe71f8e9c8a0f

This happens when I move the mouse over the window:

Bad coordinate conversion: 'NoneType' object has no attribute 'all_pix2world'
Error calculating pixtoradec: 'NoneType' object has no attribute 'all_pix2world'

[cdeil]

Looks like the error is now Qt specific ... I also get errors for this matplotlib example: https://gist.github.com/cdeil/99e84e9b250d37069b3b

[ejeschke]

Hmm, those errors don't look like the sort that would be associated with a freeze. Could you try the following:

python ./examples/matplotlib/example4_mpl.py /path/to/some/fits/file.fits

This probably will invoke the tk version of matplotlib.

[cdeil]

This works (only some warnings) ... not sure if this is tk:

$ python ./examples/matplotlib/example4_mpl.py ginga/icons/ginga.fits 
/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141203011503-py3.4.egg/ginga/BaseImage.py:31: FutureWarning: comparison to `None` will result in an elementwise object comparison in the future.
  if data_np == None:
/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141203011503-py3.4.egg/ginga/RGBMap.py:168: FutureWarning: comparison to `None` will result in an elementwise object comparison in the future.
  if self.iarr != None:
/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141203011503-py3.4.egg/ginga/util/io_fits.py:137: FutureWarning: comparison to `None` will result in an elementwise object comparison in the future.
  if hdu.data == None:
/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141203011503-py3.4.egg/ginga/ImageView.py:703: FutureWarning: comparison to `None` will result in an elementwise object comparison in the future.
  if (whence <= 0.0) or (self._rgbarr == None):
/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141203011503-py3.4.egg/ginga/ImageView.py:714: FutureWarning: comparison to `None` will result in an elementwise object comparison in the future.
  if (whence <= 2.0) or (self._rgbarr2 == None):

[ejeschke]

@cdeil, I think this points to something with qt. I've just committed a few fixes to remove spurious errors that occur in plugins when there is no image loaded when ginga starts up (version 2.1.20141207082012). This combined with your PR to change the None testing should point up any real exceptions happening. Try running the reference viewer with full log output in debug mode to the terminal and see how far it gets (or where it is getting stuck). You can do this by:

$ ginga --loglevel=10 --stderr

[cdeil]

I don't think it's ever completely stuck ... it just takes minutes to start up where previously it took seconds or less. Here's the log I get from running ginga --loglevel=10 --stderr for a few minutes: https://gist.github.com/cdeil/63c2f62a7f70abb8f62f

@ejeschke If you want I can make you an account on a Mac server you can log into via ssh to debug Mac issues like this one ... send me an email if that would be helpful.

[cdeil]

It looks like ginga starts ~ 45 threads ... probably one of them is is an infinite loop or hogging the GIL? https://gist.github.com/cdeil/580e0cb98384d47f3d32 (sorry I can't be helpful here ... I don't know what to do to find the issue in multi-threaded apps quickly)

[ejeschke]

The thread pool is started for use by the plugins and the file loader, to avoid locking the gui during file loads, preloads and network operations like catalog access. But this doesn't explain the behavior with example2_qt.py, which just uses the ginga display widget and doesn't start any threads. I think this is getting stuck in some qt code. Do you know if there is the equivalent of Linux's strace command for macs? Then we could possibly interrupt it and find out where it is stuck.

I have a few Macs around, but an account might be helpful, especially for versions of os x that I'm not running. Thanks!

[cdeil]

I did run this:

$ python -mtrace --trace /Users/deil/Library/Python/3.4/bin/ginga

It's very slow and prints many MB of text to the console, but maybe it helps you pinpoint the issue ... here's some output lines I get after the window started up but one core keeps running at 100%: https://gist.github.com/cdeil/d30f540af981a07c2d51

[ejeschke]

@cdeil, thanks for the help. I'm finally getting somewhere with this, I think. Could you try the following. Start the reference viewer with the option --numthreads=0. You will have to open a file using the File->Load Image menu, as dragging won't work in this case. Let me know your result.

I'm seeing similar slowdowns on Ubuntu 14.04 with python3 (albeit not as bad as on mac os x).

[cdeil]

Yes, with --numthreads=0 it looks like ginga works OK for me with Python 3.

[ejeschke]

@cdeil, could you try commit 3ddb7b993a89db0b63881abc6858ef55057c0d17. This seems to solve the issue on my Ubuntu 14.04 machine with python3.

[cdeil]

Now I find that ginga starts up with Python 2 and 3 within a few seconds (not very fast, but OK) and then keeps using a bit more than 100% CPU even if I don't to anything with it:

I don't see many "idle wakeup calls" with other processes ... maybe that's the issue.

[cdeil]

One thing I do see with Python 3 only is this:

$ ginga
failed to set WCS package preference: 
failed to set FITS package preference: 
Error importing Ginga config file: No module named 'ginga_config'
Traceback:
  File "/Users/deil/Library/Python/3.4/lib/python/site-packages/ginga-2.1.20141208222340-py3.4.egg/ginga/main.py", line 327, in main
    import ginga_config

Maybe you're not using new-style relative imports everywhere? This is what Astropy suggests:

One exception is to be made from the PEP8 style: new style relative imports of the form from . import modname are allowed and required for Astropy, as opposed to absolute (as PEP8 suggests) or the simpler import modname syntax. This is primarily due to improved relative import support since PEP8 was developed, and to simplify the process of moving modules.

[ejeschke]

Just checked CPU use on RHEL 6.6. Current master (9e6199e6959484790c1aa7bd9b6b4a55c415a483) uses about 6% CPU idling (python2.6). On Ubuntu 14.04 (python2.7 and python3.4) it uses 105% or so.

[ejeschke]

This is fixed in recent versions of ginga after a timer module refactoring. Currently seeing about 8.3% CPU usage with python3/qt5 on Ubuntu. Start up is just as fast or faster than for python 2.