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.

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

Fix #9481: fix invalid output during environment initialization #9633

Merged
merged 1 commit into from Mar 12, 2018

Conversation

Projects
None yet
6 participants
@yashhere
Copy link
Contributor

yashhere commented Feb 22, 2018

Earlier the logger was emitting an empty JSON file for errors during
environment initialization. Now the mozlog shutdown() method is called
if the environment initialization fails to ensure that the generated report
file contains valid JSON object. The suite_end() method functionality
has been moved to the shutdown function to avoid redundancy.


This change is Reviewable

@wpt-pr-bot wpt-pr-bot added the infra label Feb 22, 2018

@wpt-pr-bot wpt-pr-bot requested review from gsnedders and jgraham Feb 22, 2018

@w3c-bots

This comment has been minimized.

Copy link

w3c-bots commented Feb 22, 2018

Build PASSED

Started: 2018-03-09 14:49:06
Finished: 2018-03-09 15:07:09

View more information about this build on:

@jgraham
Copy link
Contributor

jgraham left a comment

I think the changes in formatters.py make sense, but the way that we are ensuring that the logger is shutdown doesn't really work.

@@ -133,3 +133,4 @@ def __exit__(self, *args, **kwargs):
pass
self.logging_queue.close()
self.logger.info("queue closed")
self.logger.shutdown()

This comment has been minimized.

Copy link
@jgraham

jgraham Feb 22, 2018

Contributor

So, I don't think this is going to work. Sometimes we (hackily?) run multiple session with the same logger (e.g. for stability checking). I think you need to look for all the places in the code where we call setup_logging and ensure that each of those places has a corresponding call to logger.shutdown() once the logger is no longer in use.

This comment has been minimized.

Copy link
@yashhere

yashhere Feb 25, 2018

Author Contributor

But don't you think that if a command, like mentioned in original issue, is going to fail, then the control will never return to the place, where I have called setup_logging, so even if I define the shutdown function at each place, the logger will not shut down properly and nothing will be written to the log file. The command fails at the environment variable initialization part in the wptrunner.py file, and that was the reason that the suite_end() function was never called. Also, I could not understand what you want to say when you mention about run multiple session with the same logger? If you could provide a command which gives such scenario, that would be a great help for testing.

This comment has been minimized.

Copy link
@yashhere

yashhere Feb 25, 2018

Author Contributor

I think that you want to change the call in wptlogging.py for successful calls only. When the tests fail, the call in wptrunner.py will call the shutdown() method and write to the file correctly. But when the test cases succeed, the control will reach the end, and hence the shutdown() calls will also execute. If this is what you want me to do, then I think, I agree with you here. I'll do the necessary changes. If not, please elaborate your opinion about the problem.

This comment has been minimized.

Copy link
@jgraham

jgraham Feb 26, 2018

Contributor

So when there's an exception the stack will unwind, but we'll still have the oppertunty to execute exception handlers and finally cluases in each calling function.

The way that the logger is used isn't ideal because we tend to call setup_logging and set a global, but it's quite possible to ensure that we have a try/finally block enclosing the scope over which the logger is actually used, and calling shotdown if we exit that scope even via an exception.

This comment has been minimized.

Copy link
@yashhere

yashhere Mar 2, 2018

Author Contributor

Hi, sorry for the delay. I have updated the code to wrap all the setup_logging calls in try/finally blocks. I have kept my previous logic of calling shutdown() in wptlogging.py's CaptureIO class as without that nothing was being written to the empty.json file. Please review and give suggestions.

@jgraham
Copy link
Contributor

jgraham left a comment

I think the way this works in run.py is more or less right, but there are a couple of other places that will break without similar changes. In wptrunner.py itself the main function sets up a mozlog logger. In tools/ci/check_stability.py we create a logger in run. There are a few other places you can see in the search at https://github.com/w3c/web-platform-tests/search?utf8=%E2%9C%93&q=setup_logging&type=

In all these cases we need to ensure that the shutdown method is being called when the logger's no longer in use.

logger.suite_end()
return unexpected_total == 0

return unexpected_count == 0

This comment has been minimized.

Copy link
@jgraham

jgraham Mar 6, 2018

Contributor

I don't think this change is right; we certainly want to still call suite_end.

rv = run_single(venv, **kwargs) > 0
except Exception as e:
logger.error(e)
logger.shutdown()

This comment has been minimized.

Copy link
@jgraham

jgraham Mar 6, 2018

Contributor

This should be in a finally block.

@yashhere

This comment has been minimized.

Copy link
Contributor Author

yashhere commented Mar 6, 2018

How do I test these changes? Can you tell some particular test cases, where these changes might fail? Or shall I run the complete test suite?

@jgraham

This comment has been minimized.

Copy link
Contributor

jgraham commented Mar 6, 2018

So if you run e.g. wpt run --log-wptreport=file.json firefox infrastructure, that should work. Then there are a few other cases that are less common. You can source _venv/bin./activate to activate the wpt virtualenv and then run wptrunner directly by installing it cd tools/wptrunner && pip install -e ./ and running it somethingn like wptrunner --log-wptreport=file.json infrastructure. The stability checking script is harder to test since it depends on travis but it also doesn't depend on wptreport.json files at present, so I think we can rely on code inspection in that case.

Fix #9481: fix invalid output during environment initialization
Earlier the logger was emitting an empty JSON file for errors during
environment initialization. Now the mozlog shutdown() method is called
if the environment initialization fails to ensure that the generated report
file contains valid JSON object. The suite_end() method functionality
has been moved to the shutdown function to avoid redundancy.
@jgraham

This comment has been minimized.

Copy link
Contributor

jgraham commented Mar 12, 2018

OK, I think this is good now, thanks. Let's merge it and find out if anything unexpectedly breaks.

@jgraham jgraham merged commit 9692b53 into web-platform-tests:master Mar 12, 2018

1 check passed

continuous-integration/travis-ci/pr The Travis CI build passed
Details
@rakuco

This comment has been minimized.

Copy link
Contributor

rakuco commented Mar 12, 2018

This seems to have broken Travis: see https://travis-ci.org/w3c/web-platform-tests/jobs/352369551 and https://travis-ci.org/w3c/web-platform-tests/jobs/352369562, for example.

Traceback (most recent call last):
  File "./wpt", line 5, in <module>
    wpt.main()
  File "/home/travis/build/w3c/web-platform-tests/tools/wpt/wpt.py", line 132, in main
    rv = script(*args, **kwargs)
  File "/home/travis/build/w3c/web-platform-tests/tools/ci/check_stability.py", line 383, in run
    logger.shutdown()
AttributeError: 'Logger' object has no attribute 'shutdown'
@yashhere

This comment has been minimized.

Copy link
Contributor Author

yashhere commented Mar 12, 2018

How did my changes pass Travis test, in this case? @jgraham shall I push more commits to fix this, or do I need to create a new pull request?

@rakuco

This comment has been minimized.

Copy link
Contributor

rakuco commented Mar 12, 2018

I don't think you can push more commits and reopen this PR, so could you please create a new pull request?

@yashhere yashhere deleted the yashhere:wpt-cli-bug branch Mar 12, 2018

@yashhere

This comment has been minimized.

Copy link
Contributor Author

yashhere commented Mar 12, 2018

How do I check if there are issues at other places also? Tox passes without showing any errors.

@jgraham

This comment has been minimized.

Copy link
Contributor

jgraham commented Mar 12, 2018

Sorry, that's my fault. It looks like the logger in check_stability.py isn't a mozlog logger; it's wpt_logger that is. If you open another PR with the same changes, but calling shutdown on wpt_logger in check_stability instead, and in a separate commit make a change to a test (e.g. add some whitespace to infrastructure/Ahem.html) and we can check that this works.

@gsnedders

This comment has been minimized.

Copy link
Contributor

gsnedders commented Mar 12, 2018

@jgraham why did the automatic running of infrastructure/ not catch this?

@jgraham

This comment has been minimized.

Copy link
Contributor

jgraham commented Mar 12, 2018

Because that doesn't run in the stability checker, just using normal wpt run.

@gsnedders

This comment has been minimized.

Copy link
Contributor

gsnedders commented Mar 12, 2018

@jgraham what would it take to have some unit tests for the stability checker?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.