Investigate why nbextension tests keep failing

[jhamrick]

The nbextension tests seem to have a much higher rate of spurious failures recently. They aren't real failures, as restarting the tests seems to fix it, but it is highly annoying.

[lgpage]

From the logs I have downloaded so far:

• 6x _wait_until_loaded(browser) --> raise TimeoutException(message, screen, stacktrace)
• 1x nbextensions/test_assignment_list.py::test_multiple_released_assignments:
  • run_nbgrader(["release", "ps.01", "--course", "xyz 200"]) --> [ReleaseApp | ERROR] Destination already exists, add --force to overwrite: xyz 200 ps.01
  • issue indirectly due to rerun, not the underlying issue

ci-logs-06-02-2017.zip

[jhamrick]

What it looks to me like what is happening is that somehow the extensions aren't being installed/enabled before the notebook server is run. For example, from https://travis-ci.org/jupyter/nbgrader/jobs/199064031 :

---------------------------- Captured stderr setup -----------------------------
Installing /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/assignment_list -> assignment_list
Making directory: /tmp/tmplhShIn/nbextensions/assignment_list/
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/assignment_list/assignment_list.css -> /tmp/tmplhShIn/nbextensions/assignment_list/assignment_list.css
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/assignment_list/assignment_list.js -> /tmp/tmplhShIn/nbextensions/assignment_list/assignment_list.js
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/assignment_list/main.js -> /tmp/tmplhShIn/nbextensions/assignment_list/main.js
- Validating: OK
Installing /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/create_assignment -> create_assignment
Making directory: /tmp/tmplhShIn/nbextensions/create_assignment/
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/create_assignment/create_assignment.css -> /tmp/tmplhShIn/nbextensions/create_assignment/create_assignment.css
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/create_assignment/main.js -> /tmp/tmplhShIn/nbextensions/create_assignment/main.js
- Validating: OK
Installing /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/formgrader -> formgrader
Making directory: /tmp/tmplhShIn/nbextensions/formgrader/
Copying: /home/travis/build/jupyter/nbgrader/nbgrader/nbextensions/formgrader/main.js -> /tmp/tmplhShIn/nbextensions/formgrader/main.js
- Validating: OK
    To initialize this nbextension in the browser every time the notebook (or other app) loads:
    
          jupyter nbextension enable nbgrader --user --py
    
Enabling: nbgrader.server_extensions.assignment_list
- Writing config: /tmp/tmpLW_37s
    - Validating...
Enabling tree extension assignment_list/main...
      - Validating: OK
Enabling notebook extension create_assignment/main...
      - Validating: OK
Enabling tree extension formgrader/main...
      - Validating: OK
[D 02:28:24.811 NotebookApp] Searching [u'/tmp/tmpH02_8C', '/tmp/tmpLW_37s', '/home/travis/virtualenv/python2.7.9/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 02:28:24.812 NotebookApp] Looking for jupyter_config in /etc/jupyter
[D 02:28:24.814 NotebookApp] Looking for jupyter_config in /usr/local/etc/jupyter
[D 02:28:24.814 NotebookApp] Looking for jupyter_config in /home/travis/virtualenv/python2.7.9/etc/jupyter
[D 02:28:24.814 NotebookApp] Looking for jupyter_config in /tmp/tmpLW_37s
[D 02:28:24.815 NotebookApp] Looking for jupyter_config in /tmp/tmpH02_8C
[D 02:28:24.817 NotebookApp] Looking for jupyter_notebook_config in /etc/jupyter
[D 02:28:24.818 NotebookApp] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 02:28:24.818 NotebookApp] Looking for jupyter_notebook_config in /home/travis/virtualenv/python2.7.9/etc/jupyter
[D 02:28:24.818 NotebookApp] Looking for jupyter_notebook_config in /tmp/tmpLW_37s
[D 02:28:24.819 NotebookApp] Loaded config file: /tmp/tmpLW_37s/jupyter_notebook_config.json
[D 02:28:24.819 NotebookApp] Looking for jupyter_notebook_config in /tmp/tmpH02_8C
[I 02:28:24.835 NotebookApp] Writing notebook server cookie secret to /tmp/tmplhShIn/runtime/notebook_cookie_secret
[W 02:28:24.877 NotebookApp] All authentication is disabled.  Anyone who can connect to this server will be able to run code.
      nbgrader.server_extensions.assignment_list  OK
Enabling: nbgrader.server_extensions.formgrader
- Writing config: /tmp/tmpLW_37s
    - Validating...
[I 02:28:24.892 NotebookApp] Loading the assignment_list nbgrader serverextension
[I 02:28:24.904 NotebookApp] Serving notebooks from local directory: /tmp/tmpH02_8C
[I 02:28:24.904 NotebookApp] 0 active kernels 
[I 02:28:24.905 NotebookApp] The Jupyter Notebook is running at: http://localhost:37441/
[I 02:28:24.905 NotebookApp] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
      nbgrader.server_extensions.formgrader  OK
...

Notice how there are logs from the notebook server before the line nbgrader.server_extensions.formgrader OK, which suggests to me that somehow that code hasn't finished executing before the notebook is run.

I think I was making the assumption that those subprocesses would finish before moving on to the next statement, but I'm thinking that is probably an incorrect assumption. I bet adding .wait() to the end of those calls would fix this issue.

[minrk]

#700 uses check_call to install the extensions, which waits for the subprocess to exit and checks the exit code.

[lgpage]

I'm going to reopen this issue as the following failures are still occurring multiple times:

• _wait(browser).until(EC.visibility_of_element_located((By.CSS_SELECTOR, "#released_assignments_list_placeholder"))) --> raise TimeoutException(message, screen, stacktrace)
• _save_and_validate(browser) --> raise TimeoutException(message, screen, stacktrace)

[jhamrick]

The _save_and_validate(browser) error seems to have been fixed by #762 and I haven't recently seen _wait(browser).until(EC.visibility_of_element_located((By.CSS_SELECTOR, "#released_assignments_list_placeholder"))), so I am going to close this for now.