Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test_autofocus_coarse_with_plots[simulator] fails #677

Closed
jamessynge opened this issue Oct 5, 2018 · 6 comments · Fixed by #696
Closed

test_autofocus_coarse_with_plots[simulator] fails #677

jamessynge opened this issue Oct 5, 2018 · 6 comments · Fixed by #696
Assignees
@AnthonyHorton

Comments

@jamessynge
Copy link
Contributor

This was failing at develop:HEAD with a KeyError: 'fileline' exception, so I modified to remove the fileline from the formatting of log messages, which then demonstrated that the error was really an assert failure in the test itself.

(panoptes-env) james@galago:/var/panoptes/POCS (fileline-issue-393)$ pytest -k test_autofocus_coarse_with_plots --color=yes pocs/tests/test_camera.py | tee /var/panoptes/logs/pytest-tee.log
============================= test session starts ==============================
platform linux -- Python 3.6.6, pytest-3.8.0, py-1.6.0, pluggy-0.7.1
rootdir: /home/james/git/panoptes/POCS, inifile: setup.cfg
plugins: xdist-1.23.0, repeat-0.7.0, forked-0.2, flakes-4.0.0
collected 90 items / 87 deselected

pocs/tests/test_camera.py Fss                                            [100%]

=================================== FAILURES ===================================
_________________ test_autofocus_coarse_with_plots[simulator] __________________

camera = <pocs.camera.simulator.Camera object at 0x7f77296f8cc0>
patterns = {'coarse_plot': '/tmp/pytest-of-james/pytest-40/images0/focus/SC9764/*/coarse_focus.png', 'final': '/tmp/pytest-of-jam...ges0/focus/SC9764/*/*_final.fits', 'fine_plot': '/tmp/pytest-of-james/pytest-40/images0/focus/SC9764/*/fine_focus.png'}
counter = {'value': 1}

    def test_autofocus_coarse_with_plots(camera, patterns, counter):
        autofocus_event = camera.autofocus(coarse=True, make_plots=True)
        autofocus_event.wait()
        counter['value'] += 1
        assert len(glob.glob(patterns['final'])) == counter['value']
>       assert len(glob.glob(patterns['fine_plot'])) == 1
E       AssertionError: assert 0 == 1
E        +  where 0 = len([])
E        +    where [] = <function glob at 0x7f775c419b70>('/tmp/pytest-of-james/pytest-40/images0/focus/SC9764/*/fine_focus.png')
E        +      where <function glob at 0x7f775c419b70> = glob.glob

pocs/tests/test_camera.py:352: AssertionError
@wtgee
Copy link
Member

wtgee commented Oct 6, 2018

#632

@AnthonyHorton
Copy link
Collaborator

Hmmm, well the test failure means that the expected focus plot file doesn't exist, at least not at the expected location. Is this consistently failing, or only sometimes? Wondering whether there's some sort of race condition here.

@wtgee
Copy link
Member

wtgee commented Oct 6, 2018

I was hoping this would be fixed by #681, which made the image location consistent. So be aware that things may have changed this Issue was open.

@jamessynge
Copy link
Contributor Author

This is still failing on my laptop (i.e. not saying that it is failing for everybody). Here is the pytest output:

________________________________________________ test_autofocus_coarse_with_plots[simulator] ________________________________________________
camera = <pocs.camera.simulator.Camera object at 0x7f54e5722908>
patterns = {'coarse_plot': '/tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/*/coarse_focus.png', 'final': '/tmp/pytest-of-j...s0/focus/SC5597/*/*_final.fits', 'fine_plot': '/tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/*/fine_focus.png'}
counter = {'value': 1}

    def test_autofocus_coarse_with_plots(camera, patterns, counter):
        autofocus_event = camera.autofocus(coarse=True, make_plots=True)
        autofocus_event.wait()
        counter['value'] += 1
        assert len(glob.glob(patterns['final'])) == counter['value']
>       assert len(glob.glob(patterns['fine_plot'])) == 1
E       AssertionError: assert 0 == 1
E        +  where 0 = len([])
E        +    where [] = <function glob at 0x7f55245bfb70>('/tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/*/fine_focus.png')
E        +      where <function glob at 0x7f55245bfb70> = glob.glob

pocs/tests/test_camera.py:375: AssertionError
------------------------------------------------------------ Captured log setup -------------------------------------------------------------
focuser.py                 106 DEBUG    Focuser created: Simulated Focuser on /dev/ttyFAKE
simulator.py                17 DEBUG    Initialising simulator focuser
simulator.py                34 DEBUG    Connected to focuser SF1155
simulator.py                19 INFO     Simulated Focuser (SF1155) on /dev/ttyFAKE initialised
camera.py                   84 DEBUG    Camera created: Simulated Camera
simulator.py                20 DEBUG    Initializing simulated camera
simulator.py                32 DEBUG    Simulated Camera connected
------------------------------------------------------------- Captured log call -------------------------------------------------------------
focuser.py                 221 DEBUG    Starting autofocus
focuser.py                 333 DEBUG    Beginning coarse autofocus of Simulated Camera (SC5597) on None with Simulated Focuser - initial position: 20000
focuser.py                 347 DEBUG    Taking dark frame /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/dark.fits on camera Simulated Camera (SC5597) on None with Simulated Focuser
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/dark.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/dark.fits
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20000_coarse_initial.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20000_coarse_initial.fits
simulator.py                38 DEBUG    Moving focuser SF1155 to 19960
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19960_00.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19960_00.fits
simulator.py                38 DEBUG    Moving focuser SF1155 to 19980
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19980_01.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19980_01.fits
simulator.py                38 DEBUG    Moving focuser SF1155 to 20000
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20000_02.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20000_02.fits
simulator.py                38 DEBUG    Moving focuser SF1155 to 20020
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20020_03.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20020_03.fits
simulator.py                38 DEBUG    Moving focuser SF1155 to 20040
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20040_04.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/20040_04.fits
focuser.py                 421 WARNING  Best focus outside sweep range, aborting autofocus on Simulated Camera (SC5597) on None with Simulated Focuser!
simulator.py                38 DEBUG    Moving focuser SF1155 to 19960
simulator.py                65 DEBUG    Taking 0.1 second exposure on Simulated Camera: /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19960_coarse_final.fits
fits.py                    368 DEBUG    Image written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/19960_coarse_final.fits
font_manager.py           1346 DEBUG    findfont: Matching :family=sans-serif:style=normal:variant=normal:weight=normal:stretch=normal:size=12.0 to DejaVu Sans ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSans.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=sans-serif:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to DejaVu Sans ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSans.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXGeneral:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXGeneral ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXGeneral.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXGeneral:style=italic:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXGeneral ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXGeneralItalic.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXGeneral:style=normal:variant=normal:weight=bold:stretch=normal:size=10.0 to STIXGeneral ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXGeneralBol.ttf') with score of 0.000000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXNonUnicode:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXNonUnicode ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXNonUni.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXNonUnicode:style=italic:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXNonUnicode ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXNonUniIta.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXNonUnicode:style=normal:variant=normal:weight=bold:stretch=normal:size=10.0 to STIXNonUnicode ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXNonUniBol.ttf') with score of 0.000000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXSizeOneSym:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXSizeOneSym ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXSizOneSymReg.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXSizeTwoSym:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXSizeTwoSym ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXSizTwoSymReg.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXSizeThreeSym:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXSizeThreeSym ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXSizThreeSymReg.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXSizeFourSym:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXSizeFourSym ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXSizFourSymReg.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=STIXSizeFiveSym:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to STIXSizeFiveSym ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/STIXSizFiveSymReg.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmsy10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmsy10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmsy10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmr10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmr10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmr10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmtt10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmtt10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmtt10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmmi10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmmi10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmmi10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmb10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmb10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmb10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmss10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmss10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmss10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=cmex10:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to cmex10 ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/cmex10.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=DejaVu Sans:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to DejaVu Sans ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSans.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=DejaVu Sans:style=italic:variant=normal:weight=normal:stretch=normal:size=10.0 to DejaVu Sans ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSans-Oblique.ttf') with score of 0.150000
font_manager.py           1346 DEBUG    findfont: Matching :family=DejaVu Sans:style=normal:variant=normal:weight=bold:stretch=normal:size=10.0 to DejaVu Sans ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSans-Bold.ttf') with score of 0.000000
font_manager.py           1346 DEBUG    findfont: Matching :family=DejaVu Sans Mono:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to DejaVu Sans Mono ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSansMono.ttf') with score of 0.050000
font_manager.py           1346 DEBUG    findfont: Matching :family=DejaVu Sans Display:style=normal:variant=normal:weight=normal:stretch=normal:size=10.0 to DejaVu Sans Display ('/var/panoptes/miniconda/envs/panoptes-env/lib/python3.6/site-packages/matplotlib/mpl-data/fonts/ttf/DejaVuSansDisplay.ttf') with score of 0.050000
focuser.py                 529 INFO     Coarse focus plot for camera Simulated Camera (SC5597) on None with Simulated Focuser written to /tmp/pytest-of-james/pytest-1473/images0/focus/SC5597/20181016T235345/coarse_focus.png
focuser.py                 532 DEBUG    Autofocus of Simulated Camera (SC5597) on None with Simulated Focuser complete - final focus position: 19960

@jamessynge
Copy link
Contributor Author

I should clarify that I'm testing this with the latest commit as of an hour ago:

commit 7703e5a9ba5afef9dc98a3fb59a71215942c1495 (HEAD -> develop, upstream/develop)
Author: Wilfred Tyler Gee <[email protected]>
Date:   Tue Oct 16 14:07:27 2018 +1100

    Quick Camera fix (#694)
    
    * Skip gphoto2 camera if it doesn't respond to request for serialnumber

@wtgee
Copy link
Member

wtgee commented Oct 17, 2018

Two things going on here:

  • The check for the fine focus should be removed (from Separate coarse autofocus from fine autofocus #659).
  • The counter fixture has module level scope. It appears that if we remove the check for the fine plots in this failing test then the test will work, however, it would be easy for it to get screwed up in the future as it's not totally obvious that the counter is not resetting.

I'll put in a fix for the first point, which should get it passing.

@wtgee wtgee mentioned this issue Oct 17, 2018
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@AnthonyHorton AnthonyHorton

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix autofocus tests wtgee/POCS
3 participants
@wtgee @jamessynge @AnthonyHorton