1185501 - Support mozlog 3.0 in gaiatest

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

Description

[Johan Lorenzo [:jlorenzo]]

Follow up from bug 1185479. Now that our dependencies needs mozlog 3.0, we have to comply to it.

In bug 1185479, we put gaiatest back working thank to version pinning, here we'll delete the version pinning, bring back mozlog 3.0 and make gaiatest runs with it.

Comment 1

[GitHub Autolander Bot]

Attachment: [gaia] zapion:bug_1185501 > mozilla-b2g:master

Comment 2

[Paul Yang [:pyang] (away)]

Attachment: 1st_patch

A quick patch and works fine in my local. feedback?

Comment 3

[Martijn Wargers (dead)]

Comment on attachment 8636523 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

I assume this is fine, I see you just changed the requirements.txt file back from what was changed in bug 1185479  too, which is good.
I hope I can read some documentation about this mozlogger thing, because for me it's quite unclear and what it's doing.

Comment 4

[Paul Yang [:pyang] (away)]

mozlog overwrote logger and try to provide formatter integrating treehelder.
Besides mozlog there are some new comers in mozbase and seem unstable, e.g., mozversion.
Mostly I spent time tracing code instead of doc for better understanding, and they change fast.

Comment 5

[Johan Lorenzo [:jlorenzo]]

Comment on attachment 8636523 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

The patch is on the right track. Thanks for clearing the dependencies. I'm getting another error, though. The logger doesn't seem to be initialized anymore:

> TEST-UNEXPECTED-ERROR | test_add_contact_to_favorites.py TestAddContactToFavorite.test_add_contact_to_favorite | AttributeError: 'NoneType' object has no attribute 'debug'
> 
> Traceback (most recent call last):
>   File "/home/jlorenzo/git/gaia/tests/python/gaia-ui-tests/.env/lib/python2.7/site-packages/marionette_client-0.16-py2.7.egg/marionette/marionette_test.py", line 277, in run
>     self.setUp()
>   File "/home/jlorenzo/git/gaia/tests/python/gaia-ui-tests/gaiatest/tests/functional/contacts/test_add_contact_to_favorites.py", line 13, in setUp
>     GaiaTestCase.setUp(self)
>   File "/home/jlorenzo/git/gaia/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 859, in setUp
>     self.set_default_settings()
>   File "/home/jlorenzo/git/gaia/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 1078, in set_default_settings
>     self.logger.debug('Setting %s to %s' % (name, value))
> TEST-INFO took 28072ms

Comment 6

[Martijn Wargers (dead)]

You also might want to read bug 1014760, comment 30:
"
Mozlog.unstructured is an old implementation that we aren't really supporting anymore. It's just a really thin wrapper around python's logging module, so if you just need some kind of basic logger, I'd recommend just using logging directly.

But if you were previously using 'mozlog', it's easiest to just update your imports, e.g:
import mozlog.unstructured as mozlog

Mozlog.structured (now just 'mozlog') is the recommended way to do logging. But it can be overkill for many cases, so it might not be worth upgrading to it. The documentation for mozlog structured is here:
https://mozbase.readthedocs.org/en/latest/mozlog_structured.html

There is purposefully no documentation for mozlog.unstructured because we don't want any new consumers using it.
"

Comment 7

[Paul Yang [:pyang] (away)]

johan - I tried following script and it failed so looks like a framework issue.

---
from mozlog.structuredlog import get_default_logger
my_logger = get_default_logger()
print my_logger
---
The result is None

Comment 8

[Paul Yang [:pyang] (away)]

My bad, I saw marionette_test.py has initialized default_logger by setup_logging() so nothing should be changed.
just tried test_add_contact_to_favorite and it passed

Can you help to cleanup environment and try again? thanks!

Comment 9

[Johan Lorenzo [:jlorenzo]]

That works for me!

Like Martijn noticed, we may want to move to structured logs if we want to comply to the new API. We worked around the problem in bug 1185479. Do you think we can change our usage of mozlogs to structured, Paul?

Comment 10

[Andrew Halberstadt [:ahal]]

I'd say don't upgrade to structured logging just for the sake of it. Structured logging is nice, because you can turn the raw json logs into any format you want, and you can use the log for arbitrary actions other than displaying information. But if you don't have anything that will consume the structured logs, it's probably easiest to just keep using mozlog.unstructured. If you do want to use it, there are some examples in the docs that might help:
http://mozbase.readthedocs.org/en/latest/mozlog.html#simple-examples

Comment 11

[Johan Lorenzo [:jlorenzo]]

Comment on attachment 8636523 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

Right. We don't plan to use these features. Let's use unstructured for now, then.

Comment 12

[Paul Yang [:pyang] (away)]

Thanks for review!

Comment 13

[Ryan VanderMeulen [:RyanVM]]

Master: https://github.com/mozilla-b2g/gaia/commit/0a21cdcdc647af23319a4fa3223e9bfeae290d48

Comment 14

[Johan Lorenzo [:jlorenzo]]

Automation is failing with the same error as in comment 5: http://jenkins1.qa.scl3.mozilla.com/view/UI/job/flame-kk-spark-319.mozilla-central.nightly.ui.functional.spark/3/console

Martijn and I repro'd the issue locally. We need automation to run, so it's better if we backout the patch for now. Sorry to not have discovered it in the second test.

https://github.com/mozilla-b2g/gaia/commit/8d4d0bb88f61e72554ab68e51282f08e1be536b6

Comment 15

[Martijn Wargers (dead)]

(In reply to Johan Lorenzo [:jlorenzo] (QA) from comment #14)
> Automation is failing with the same error as in comment 5:
> http://jenkins1.qa.scl3.mozilla.com/view/UI/job/flame-kk-spark-319.mozilla-
> central.nightly.ui.functional.spark/3/console

Just to be clear, it's this error:
06:45:40  1:22.17 TEST_END: MainThread ERROR, expected PASS
06:45:40 Traceback (most recent call last):
06:45:40   File "/var/jenkins/1/workspace/flame-kk-spark-319.mozilla-central.nightly.ui.functional.spark/.env/local/lib/python2.7/site-packages/marionette_client-0.16-py2.7.egg/marionette/marionette_test.py", line 277, in run
06:45:40     self.setUp()
06:45:40   File "/var/jenkins/1/workspace/flame-kk-spark-319.mozilla-central.nightly.ui.functional.spark/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 859, in setUp
06:45:40     self.set_default_settings()
06:45:40   File "/var/jenkins/1/workspace/flame-kk-spark-319.mozilla-central.nightly.ui.functional.spark/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 1078, in set_default_settings
06:45:40     self.logger.debug('Setting %s to %s' % (name, value))
06:45:40 AttributeError: 'NoneType' object has no attribute 'debug'
06:45:40 
06:45:40  1:22.24 LOG: MainThread INFO

Comment 16

[Paul Yang [:pyang] (away)]

I tried to step-in CommonTestCase __init__ , get_default_logger return None here and cause issue above.
The code related is all in structuredlog.py, not sure if it is by this patch or by mozlog patch.

Comment 17

[Andrew Halberstadt [:ahal]]

get_default_logger returns None if no one has called set_default_logger before. It looks like marionette (indirectly) calls set_default_logger here:
https://dxr.mozilla.org/mozilla-central/source/testing/marionette/client/marionette/runtests.py#53

In the automation, is that line getting hit? If not the fix might just be to manually create a default logger and call set_default_logger with it. Btw the mozlog patch didn't change any code, just moved some directories around.

Comment 18

[Paul Yang [:pyang] (away)]

I figure out marionette package on pypi is 6/26 so we don't have latest update for mozlog change.
David, is it possible to push latest marionette with ahal's patch? Thanks!

Comment 19

[David Burns :automatedtester]

Riased bug 1188826 to do this.

Comment 20

[Paul Yang [:pyang] (away)]

Thanks David!
Will fix requirement and re-trigger the test.

Comment 21

[GitHub Autolander Bot]

Attachment: [gaia] zapion:bug_1185501 > mozilla-b2g:master

Comment 22

[Paul Yang [:pyang] (away)]

Comment on attachment 8641539 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

slightly change in requirement.

Comment 23

[Martijn Wargers (dead)]

Attachment: console_output.txt

I tried out https://github.com/mozilla-b2g/gaia/pull/31192 with starting from a clean slate. This is what I get. I can't get it to run a Gaia UI test, I get this error: ImportError: cannot import name __version__

Perhaps I'm doing something wrong. Could you perhaps give me the correct instructions to start from a clean slate?

Comment 24

[Paul Yang [:pyang] (away)]

I just create a new virtualenv and install gaiatest, marionette_transport's version is 0.6, not 0.5
I guess requires.txt in your env wasn't updated so it kept using 0.5; can you help to build new environment and check again? thanks!

Comment 25

[Martijn Wargers (dead)]

Comment on attachment 8641539 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

If it works for you, then I guess it's fine.
I did start from scratch, with a new virtual environment, fwiw.
To be honest, I don't really know how all these packages tie into each other and how it all works, so I'm not the best reviewer. I can only test out the pull request. It would be great if someone could tell me why it didn't work for me.

Comment 26

[Paul Yang [:pyang] (away)]

We should figure out why since partners might try gaiatest on their own.

version.py is generated when installing package,

{virtual_env}/lib/python2.7/site-packages/gaiatest-0.33-py2.7.egg/EGG-INFO/SOURCES.txt:gaiatest/version.py

Might need install log of gaiatest because installation seems not completed.

Comment 27

[Johan Lorenzo [:jlorenzo]]

The patch looks good to me. I'd prefer to test the patch on an adhoc job, before r+'ing it. We currently face that Jenkins issue (bug 1192299), which prevent us from running jobs.

Comment 28

[Paul Yang [:pyang] (away)]

Martijn and I tried the patch with latest gaia master and it worked fine.
Set depends on bug 1192299 we can test once jenkins recovered.

Comment 29

[Johan Lorenzo [:jlorenzo]]

I put your patch on the top of gaia-master and started this job[1]. Let's see how it goes.

[1] http://jenkins1.qa.scl3.mozilla.com/job/flame-kk.ui.adhoc/863/console

Comment 30

[Johan Lorenzo [:jlorenzo]]

Comment on attachment 8641539 [details] [review]
[gaia] zapion:bug_1185501 > mozilla-b2g:master

The adhoc job didn't fail because of mozlog. I'll merge the PR tomorrow (in my morning) in order to make sure that no job is broken. NI myself to do so.

Comment 31

[Johan Lorenzo [:jlorenzo]]

Merged in master at https://github.com/mozilla-b2g/gaia/commit/b9e542a2ece1efd2e6b1e5c48e73e7a051c4b862. I'm taking a look at the Jenkins jobs to see if anything fails.

Comment 32

[Johan Lorenzo [:jlorenzo]]

I checked the jobs that failed after the merge, and none of them fails due to mozlog:
* http://jenkins1.qa.scl3.mozilla.com/view/UI/job/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.1/407/console
* http://jenkins1.qa.scl3.mozilla.com/job/flame-kk-319.b2g-inbound.tinderbox.ui.unit.bitbar/2236/console
* http://jenkins1.qa.scl3.mozilla.com/job/flame-kk-319.mozilla-inbound.tinderbox.ui.functional.sanity.bitbar/5185/console

Comment 33

[Martijn Wargers (dead)]

Was this something that we needed to send a message to the gaia-ui-automation list that people needed to update their virtualenv?
I remember that I had to help Mermi friday with some weird error (not sure it was about this), that was fixed by upgrading her marionette-driver package.

Comment 34

[Martijn Wargers (dead)]

We have this:
http://mxr.mozilla.org/gaia/source/tests/python/gaia-ui-tests/requirements.txt#3
marionette_client>=0.17

Doesn't that mean, we're always using the latest marionette_client version here? (as long as it's newer than 0.17).

That part now seems to cause breakage, see bug 1196489, comment 2.

Comment 35

[Paul Yang [:pyang] (away)]

pip upgrade strategy showed here https://pip.pypa.io/en/latest/user_guide.html#only-if-needed-recursive-upgrade

For newly install package it tried latest version. Once it was downloaded, it may not change anything until requirement modified; in this case it won't download 0.18 since 0.17 still meets "marionette_client>=0.17".

I guess we can explicitly call upgrade for environment setup, or cleanup virtualenv and re-download them.