Closed Bug 897067 Opened 7 years ago Closed 6 years ago

"ImportError: cannot import name OrderedDict" at resourcemonitor.py line 14, on green mochitest runs

Categories

(Release Engineering :: General, defect)

defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: emorley, Assigned: emorley)

References

(Blocks 1 open bug)

Details

Attachments

(1 file, 2 obsolete files)

A soon to be deployed TBPL parser improvement has found more uncaught Python exceptions in green Ubuntu debug mochitest runs.

a) Should these be making the test run fail?
b) We should catch/fix this so we don't spam the annotated failure summary once this TBPL patchset is rolled out.

eg:
https://tbpl-dev.allizom.org/php/getParsedLog.php?id=25605501&tree=Mozilla-Central#error2

Rev3 Fedora 12x64 mozilla-central debug test mochitest-browser-chrome on 2013-07-23 03:31:07 PDT for push fb4bf993a58a

slave: talos-r3-fed64-060

{
03:33:15     INFO - Running post-action listener: _resource_record_post_action
03:33:15     INFO - Running post-action listener: _start_resource_monitoring
03:33:15  WARNING - Unable to start resource monitor: Traceback (most recent call last):
03:33:15  WARNING -   File "/home/cltbld/talos-slave/test/scripts/mozharness/base/python.py", line 388, in _start_resource_monitoring
03:33:15  WARNING -     from mozsystemmonitor.resourcemonitor import SystemResourceMonitor
03:33:15  WARNING -   File "/home/cltbld/talos-slave/test/build/venv/lib/python2.6/site-packages/mozsystemmonitor/resourcemonitor.py", line 14, in <module>
03:33:15  WARNING -     from collections import (
03:33:15  WARNING - ImportError: cannot import name OrderedDict
}

http://mxr.mozilla.org/mozilla-central/source/testing/mozbase/mozsystemmonitor/mozsystemmonitor/resourcemonitor.py#14

14 from collections import (
15     OrderedDict,
16     namedtuple,
17 )
Flags: needinfo?(gps)
(Machines are running Python 2.6)
Depends on: 602908
All automation machines should be running Python 2.7.3+.
Component: Mozbase → Release Engineering: Automation (General)
Flags: needinfo?(gps)
Product: Testing → mozilla.org
QA Contact: hskupin → catlee
Version: Trunk → other
No longer depends on: 602908
I'm going to push back that this is a bug with mozharness.

What's happening is we are attempting to start resource monitoring, catching an exception, and printing that exception to help with future diagnosis. The printing of that error is triggering the log parser.

The error is printed at warning level (as opposed to say error). The printed error has value, otherwise we wouldn't know why resource monitoring isn't working!

I think this is a bug with the log parser.
So this should be warning level ERROR and turning the run orange?
Not a bug in mozharness; it's getting marked as a WARNING.
TBPL is finding the assertion and highlighting it.

We could potentially add some magic string to each line that TBPL looks for first, to ignore errors, or hide the error.
(In reply to Ed Morley [:edmorley UTC+1] from comment #5)
> So this should be warning level ERROR and turning the run orange?

Nope, mozharness is appropriately marking it as a WARNING and not changing the end result of the run.
I think keeping the timestamp (to show that these errors are happening well before the real errors) and the log level would be helpful.
Product: mozilla.org → Release Engineering
OS: Linux → All
Hardware: x86_64 → All
Summary: "ImportError: cannot import name OrderedDict" at resourcemonitor.py line 14, on green Fedora debug mochitest runs → "ImportError: cannot import name OrderedDict" at resourcemonitor.py line 14, on green mochitest runs
Ed, I think we're going to have to just ignore this for now, as it doesn't appear a fix is coming any time soon.
Flags: needinfo?(emorley)
But surely if we want resource monitoring deployed & working - then it not being found is worthy of failing the run (hence what I meant by comment 5)...
Flags: needinfo?(emorley)
IMO we should be catching this exception if it is expected - hardcoding TBPL to ignore this failure seems extremely suboptimal...
RyanVM pinged me on IRC. I'm going to reiterate that I think this is a bug with the log parser. Well, foremost it's a bug with RelEng: they need to deploy Python 2.7 everywhere. If bug 711299 (opened in 2011!) were fixed, this problem would go away.

mozharness is trapping an error loading an *optional* feature and it is reporting that error to help with diagnosis so that failure can eventually be fixed. IMO it's doing everything right. If we failed to catch the error, resource monitoring would be backed out. If we didn't report the error, we wouldn't know why resource monitoring failed and would have a hard time making it work.

The problem is the downstream log parser is interpreting this caught error as a real error. It isn't a real error. Therefore the problem resides with the log parser.

A quick hack would be to have output that should be ignored by the error log parser to contain a token in the log line. e.g. perhaps we could prefix each log message with "optional" or some such. This is trivial to implement in mozharness. I think it should be relatively straightforward to adapt downstream log parsers as well. We just need to agree on the implementation and we can move forward.
We should still catch the exception and print a friendly message (eg: "Optional package not found!"), which would both be The Right Thing To Do & also fix the false positive in TBPL too :-)
(In reply to Ed Morley [:edmorley UTC+1] from comment #13)
> (eg: "Optional package not found!")

Well, more appropriately:
"Warning Python 2.7.x not installed, resource monitoring will not be enabled!"
Assignee: nobody → emorley
Status: NEW → ASSIGNED
Attachment #791682 - Flags: review?(gps)
Attachment #791683 - Flags: review?(gps)
Comment on attachment 791682 [details] [diff] [review]
Print useful error rather than exception

Review of attachment 791682 [details] [diff] [review]:
-----------------------------------------------------------------

This code is in mozbase and I'm not a peer, so I can't conduct a review. Please try :ahal or :jhammel if you wish to touch this file. See also https://wiki.mozilla.org/Auto-tools/Projects/MozBase#Working_on_Mozbase_and_Contributing_Patches for their slightly-different patch landing process.

That being said, I would give this code an r- because continuing to load a module due to a missing required import should result in an Exception. We only ignore the failure to import psutil in resourcemonitor.py because psutil is optional - the resource monitor class can continue to function without it. Until Python 2.7 can be deployed everywhere (the proper solution to this bug), the temporary solution is for downstream consumers to trap the ImportError thrown by resourcemonitor.py. mozharness already does this, just not in a method the log parsers find acceptable.

I understand I'm not leaving you with an alternative. I think the least crappy solution is to catch the ImportError in mozharness.
Attachment #791682 - Flags: review?(gps)
Comment on attachment 791683 [details] [diff] [review]
Fix most of the existing flake8 warnings

Review of attachment 791683 [details] [diff] [review]:
-----------------------------------------------------------------

Please follow the mozbase contribution guidelines to land this.

Also, I personally believe the subsequent line indenting is BS (wastes too much line real estate) and I don't follow it. I encourage you to do the same.
Attachment #791683 - Flags: review?(gps)
No longer blocks: 892958
Blocks: log-SnR
Hi Ed, have you had a chance to work on this lately? :)
Flags: needinfo?(emorley)
Attachment #791683 - Attachment is obsolete: true
Newer log:
https://tbpl.mozilla.org/php/getParsedLog.php?id=28446601&tree=Mozilla-Central#error0

{
19:33:44     INFO - Running post-action listener: _resource_record_post_action
19:33:44     INFO - Running post-action listener: _start_resource_monitoring
19:33:44  WARNING - Unable to start resource monitor: Traceback (most recent call last):
19:33:44  WARNING -   File "/home/cltbld/talos-slave/test/scripts/mozharness/base/python.py", line 433, in _start_resource_monitoring
19:33:44  WARNING -     from mozsystemmonitor.resourcemonitor import SystemResourceMonitor
19:33:44  WARNING -   File "/home/cltbld/talos-slave/test/build/venv/lib/python2.6/site-packages/mozsystemmonitor/resourcemonitor.py", line 14, in <module>
19:33:44  WARNING -     from collections import (
19:33:44  WARNING - ImportError: cannot import name OrderedDict
}
Flags: needinfo?(emorley)
Attachment #791682 - Attachment is obsolete: true
Don't attempt to start the (for now) optional resource monitor if Python < v2.7.
You're right, this is a much better place to handle this.
Attachment #811110 - Flags: review?(gps)
Attachment #811110 - Flags: review?(gps) → review+
Attachment #811110 - Flags: checked-in+
In production :-)
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.