travis-ci timeouts when using --coverage?

[abathur]

I'm not sure if I've stumbled into a real issue, or just fallen into a documentation hole.

I had a bear of a time getting travis-ci set up this time. When I use run_tests --coverage, I get a timeout waiting for ST3 to respond. When I use run_tests without coverage, they run fine. The raw logs for both runs show the bootstrap installing sublime-coverage:

...
Running command: bootstrap 
copy the package to sublime package directory
download UnitTesting tag: 1.2.0
76d466417e4747098e22da768631f6107e736d43

download sublime-coverage tag: 1.0.0
bdda8348acf163fbb2c7e276d7d5415c2d0fa4bb

installing sublime text 3
...

Here's an example of the time-out/coverage run:

[0K$ sh travis.sh run_tests --coverage
Running command: run_tests --coverage
Schedule:
  output: /home/travis/.config/sublime-text-3/Packages/User/UnitTesting/Constellation/result
  syntax_test: False
  color_scheme_test: False
  coverage: True
  package: Constellation
Wait for Sublime Text response
.Xlib:  extension "RANDR" missing on display ":99.0".
............................................................Timeout: Sublime Text is not responding

Here's an example of one succeeding without:

[0K$ sh travis.sh run_tests
Running command: run_tests 
Schedule:
  output: /home/travis/.config/sublime-text-3/Packages/User/UnitTesting/Constellation/result
  syntax_test: False
  color_scheme_test: False
  coverage: False
  package: Constellation
Wait for Sublime Text response
.Xlib:  extension "RANDR" missing on display ":99.0".
..
Start to read output...
test_core_commands (test_core.TestCore) ... ERROR

======================================================================
ERROR: test_core_commands (test_core.TestCore)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/travis/.config/sublime-text-3/Packages/UnitTesting/unittesting/core/st3/case.py", line 11, in _executeTestPart
    deferred = function()
  File "/home/travis/.config/sublime-text-3/Packages/Constellation/tests/test_core.py", line 84, in test_core_commands
    self.create_constellation("test_one")
  File "/home/travis/.config/sublime-text-3/Packages/Constellation/tests/test_core.py", line 18, in create_constellation
    self.assertIn(name, s.get("constellations"))
  File "./python3.3/unittest/case.py", line 902, in assertIn
TypeError: argument of type 'NoneType' is not iterable

----------------------------------------------------------------------
Ran 1 test in 0.121s

FAILED (errors=1)

UnitTesting: Done.

[randy3k]

Cloning your package and running UnitTesting reveals that
there is an error in the source code

test_core (unittest.loader.ModuleImportFailure) ... ERROR

======================================================================
ERROR: test_core (unittest.loader.ModuleImportFailure)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "./python3.3/unittest/case.py", line 384, in _executeTestPart
  File "./python3.3/unittest/loader.py", line 32, in testFailure
ImportError: Failed to import test module: test_core
Traceback (most recent call last):
  File "./python3.3/unittest/loader.py", line 261, in _find_tests
  File "./python3.3/unittest/loader.py", line 239, in _get_module_from_name
  File "/Users/Randy/Dropbox/Sublime Text 3/Packages/Constellation/tests/test_core.py", line 13
    s = sublime.load_settings("Preferences.sublime-settings")
                                                            ^
TabError: inconsistent use of tabs and spaces in indentation


----------------------------------------------------------------------
Ran 1 test in 0.009s

FAILED (errors=1)

UnitTesting: Done.

With run_tests --coverage, UnitTesting would first reload the package first. The error may explain why UnitTesting is not responding.
Also, you are using DeferrableTestCase but deferred is not set to true.

[abathur]

@randy3k Not running master, or my output would show the same.

I'd already wiped the debug branch I was working on, but I've re-produced the issue for you:

Broken/coverage: https://travis-ci.org/abathur/constellation/jobs/364712602
Working/no-coverage: https://travis-ci.org/abathur/constellation/jobs/364710289

[abathur]

@randy3k I saw that you were able to reproduce this CI failure on a fork yesterday. I also noticed that you've bumped versions, so ran the failing build again to see. It still breaks, but the output is a little different, so I thought I'd update you in case it saves a any work:

�[0K$ sh travis.sh bootstrap
Running command: bootstrap 
copy the package to sublime package directory
download UnitTesting tag: 1.3.1
bccbc6e304dcb616d40f4d185fafe8ed16c055b6

download sublime-coverage tag: 1.0.0
bdda8348acf163fbb2c7e276d7d5415c2d0fa4bb

installing sublime text 3
downloading https://download.sublimetext.com/sublime_text_3_build_3143_x64.tar.bz2
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 9626k  100 9626k    0     0  51.9M      0 --:--:-- --:--:-- --:--:-- 52.2M

...

�[0K$ sh travis.sh run_tests --coverage
Running command: run_tests --coverage
Schedule:
  output: /home/travis/.config/sublime-text-3/Packages/User/UnitTesting/Constellation/result
  syntax_test: None
  color_scheme_test: None
  coverage: True
  package: Constellation
Xlib:  extension "RANDR" missing on display ":99.0".
Wait for tests output..................................
Timeout: Could not obtain tests output.
Maybe Sublime Text is not responding or the tests outputis being written to the wrong file.

travis_time:end:154e5900:start=1523550327857172650,finish=1523550358772913578,duration=30915740928
�[0K
�[31;1mThe command "sh travis.sh run_tests --coverage" exited with 1.�[0m

Done. Your build exited with 1.

[abathur]

@randy3k I figured this out today. I'm tempted to close because this is mostly my fault, but I'll see what you think since it was a little tricky.

• At one point I refactored a single deferred test, extracting parts of it into individual functions and replacing them with calls.
• If I had been thinking clearly when I did this, it would have been obvious to me that moving the yield statements out of actual test methods would mean they don't actually delay execution, and that they would guard any subsequent assertions from being run.
• I didn't think to look closely at the tests themselves because the local/plugin UnitTesting runs were completing without a loud/obvious complaint and showing reasonable coverage information.

I'm not quite certain from here why the "timeout" messages on travis-ci. I suspect the above errors are just eating critical output and leaving it puzzled.

I'm fine with closing this unless you have some ideas about how one platform or the other could detect and message more clearly in this case.

[randy3k]

how about using yield form https://docs.python.org/3/whatsnew/3.3.html#pep-380?

[abathur]

I've got my tests working already; I needed to split methods up along similar lines for entirely different reasons, which is how I noticed what was going on.

But yes, the test method could have properly handled yield in a sub-call if I had been paying enough attention. :)

[abathur]

Though, I did get this other response (emanuelen5/Word-highlighter@1fe8c0e#commitcomment-30289483) from @emanuelen5; it sounds like his case was a simple syntax error. Maybe there's just a broader problem with the coverage script swallowing other messages (perhaps if they don't fit some format?)

[randy3k]

A syntax error like that is always fatal. This is the reason for the timeout.

[randy3k]

Wait, I may have misunderstood the issue, the error was from the test suite....there may be something fishy there.