944361 - [mozprofile] Python 2.6 incompatibility when installing add-ons due to "ZipFile instance has no attribute '__exit__'"

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[mario garbi]

We get constant failures both locally and on the mm-osx-106-4 machine for testrun_addons. At first glance the Selenium addon isn't even opening, the test failing as soon as the browser get's opened.

We aren't getting any dashboard reports sent so here is a Jenkins console log snippet:

02:33:57 *** Downloading http://release.seleniumhq.org/selenium-ide/editor/2.3.0/selenium-ide-editor-2.3.0.xpi to /var/folders/Jj/Jjc6CMB3GWKy9EgG9MiLS++++TM/-Tmp-/selenium-ide-editor-2.3.0.xpi
02:33:57 *** Creating profile: /Users/mozauto/jenkins/workspace/mozilla-aurora_addons/data/profile
02:33:57 2013-11-28 02:36:32.497 firefox[85865:900b] invalid pixel format
02:33:57 2013-11-28 02:36:32.500 firefox[85865:900b] invalid context
02:33:57 2013-11-28 02:36:32.500 firefox[85865:900b] invalid pixel format
02:33:57 2013-11-28 02:36:32.500 firefox[85865:900b] invalid context
02:33:57 2013-11-28 02:36:32.501 firefox[85865:903] invalid pixel format
02:33:57 2013-11-28 02:36:32.502 firefox[85865:903] invalid context
02:33:57 2013-11-28 02:36:32.502 firefox[85865:903] invalid pixel format
02:33:57 2013-11-28 02:36:32.503 firefox[85865:903] invalid context
02:33:57 TEST-START | testCommands/testAlert/testAssertAlertFails.js | setupModule
02:33:57 ERROR | Test Failure | {
02:33:57   "exception": {
02:33:57     "message": "Menu entry '#menuToolsSeleniumIDE' not found.", 
02:33:57     "lineNumber": 156, 
02:33:57     "name": "Error", 
02:33:57     "fileName": "resource://mozmill/driver/controller.js"
02:33:57   }
02:33:57 }

This should be easily reproducible on a osx 10.6 machine.

Comment 1

[Andreea Matei [:AndreeaMatei]]

Only this test fails?  testCommands/testAlert/testAssertAlertFails.js 
If so, we can prepare a skip patch for it.

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Why only 10.6? Is this happening on all the 10.6 nodes or only a specific one?

Comment 3

[mario garbi]

It seems so, yes. I can reproduce it locally on a Mac 10.6 and we have successful reports for OSX 107, 108 and 109.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

So not sure what's going on here but the selenium add-on is clearly not installed in Firefox. There might be a problem with downloading it? The testrun works perfectly when I run it directly on the node but fails via Jenkins. Sounds like a proxy issue again.

Comment 5

[mario garbi]

I can reproduce it locally on my mac 10.6 and only with Mozmill 2.0, not sure if it's a proxy issue.

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2]]

How do you reproduce? This bug still lacks the information about steps. Please provide those in every case!!

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+2]]

So I have taken mm-osx-106-4 offline for testing that in a temporary production instance, and this problem is definitely not a faulty download. The downloaded file is a valid XPI so something else is causing this.

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Ok, for whatever reason mozrunner doesn't correctly setup the staged folder so that the add-on gets installed. I have no idea why yet. But that really smells like a problem in mozprofile.

Comment 9

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Ok, so the problems here are because of the ZipFile incompatibility with the `with` statement. The exception is hidden at the moment because we silently drop the message and return False in is_addon(). That's unfortunate and we should fix that to at least give a warning.

But the real question here is should we keep compatibility with Python 2.6 or not? I'm currently not sure what the minimum requirements for mozbase are. If it's 2.7 we might want to catch this already in setup.py when installing the package.

Jeff, William, Andrew, any insights from you?

In case of our mozmill-ci 10.6 machines I will upgrade them to Python 2.7.3, so that we are not blocked on this decision / fix.

Comment 10

[Andrew Halberstadt [:ahal]]

I believe we still need to support python 2.6 unless that changed recently and I didn't know about it. So yeah, we shouldn't use with statements.

Comment 11

[William Lachance (:wlach)]

The with statement is supported in Python 2.6.

http://stackoverflow.com/a/3791936/295132

Is it a problem with using "with" and "ZipFile" together? A code pointer would be helpful here.

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Yes, it's a combination of both. Sorry for missing the code pointer. You can find it here:
https://github.com/mozilla/mozbase/blob/master/mozprofile/mozprofile/addons.py#L260

A quick search shows that the needed fix never made it into the 2.6 release:
http://bugs.python.org/issue5511

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+2]]

The only thing I have to know if we have to keep compatibility with 2.6. If that's the case I will find a proper solution for it.

Comment 14

[William Lachance (:wlach)]

(In reply to Henrik Skupin (:whimboo) from comment #13)
> The only thing I have to know if we have to keep compatibility with 2.6. If
> that's the case I will find a proper solution for it.

To be honest I really don't know at the moment. I know that everything in mozilla-central (mochitest, reftest, etc) is running under python 2.7. Talos may sometimes still be running under an earlier version still. I think everything else would be easy to upgrade to 2.7 if it isn't already.

Joel, do we need to keep 2.6 or earlier compatibility for Talos still?

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Well, bug 711299 hasn't been fixed yet. So I still think that a lot of test machines are around which run 2.6.

Comment 16

[Joel Maher ( :jmaher ) (UTC -8)]

as far as I can tell everything runs some version of python 2.7!

Comment 17

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Joal, so bug 711299 should be marked as fixed then?

Comment 18

[Joel Maher ( :jmaher ) (UTC -8)]

bug 711299 is regarding python 2.7.3, I am not sure if all of our machines are on that version.  I recall a wide variety of 2.7.* versions earlier.

Comment 19

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: WIP

Jeff, what do you think? I'm not 100% sure how to best log those warnings but that seems to be the best idea. is_addon() should not always log but only if it is important. Otherwise we should always throw an AddonFormatError and the calling code has to handle it appropriately.

This patch is not ready yet, so please only give your feedback which path we want to take here. Thanks.

Comment 20

[Jeff Hammel]

> The only thing I have to know if we have to keep compatibility with
> 2.6. If that's the case I will find a proper solution for it.

https://wiki.mozilla.org/Auto-tools/Projects/Mozbase says

"Mozbase requires python 2.6 or greater (pending bug 907794, when it
will require 2.7) "

Bug 907794 is resolved so this (badly) implies we now require
2.7(?!).

> Well, bug 711299 hasn't been fixed yet. So I still think that a lot
> of test machines are around which run 2.6.

If bug 711299 is a blocker for mozbase to deprecate 2.6, this should
be noted on https://wiki.mozilla.org/Auto-tools/Projects/Mozbase .

That said, we can make whatever policy we want.

Comment 21

[Jeff Hammel]

Comment on attachment 8341738 [details] [diff] [review]
WIP

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

> Jeff, what do you think? I'm not 100% sure how to best log those
> warnings but that seems to be the best idea. is_addon() should not
> always log but only if it is important. Otherwise we should always
> throw an AddonFormatError and the calling code has to handle it
> appropriately.

For logging, I'd rather have a logger passed in to an instance, but I don't know if we have a consistent pattern (though we probably should).

I don't think we should fix 2.6 compatibility by raising a AddonFormatError. It is a harness issue.

::: mozprofile/mozprofile/addons.py
@@ +35,5 @@
>          """
>          self.profile = profile
>          self.restore = restore
>  
> +        self.logger = mozlog.getLogger(__name__)

I'd rather give an explicit name, but this is fine.  Also, kill extra whitespace line.

@@ +144,5 @@
>  
>          raise IOError('Add-on not found: %s' % addon_id)
>  
>      @classmethod
> +    def is_addon(self, addon_path, log_warning=False):

IMHO we should always log warnings if we are logging at all.

@@ +273,5 @@
> +            else:
> +                with open(os.path.join(addon_path, 'install.rdf'), 'r') as f:
> +                    manifest = f.read()
> +        except (IOError, KeyError), e:
> +            raise AddonFormatError, str(e), sys.exc_info()[2]

IMHO we shouldn't treat the zipfile (library code) + `with` error as a AddonFormatError, since the problem is not with the addon, but with the harness.

@@ +326,5 @@
>          # install each addon
>          for addon in addons:
>              # determine the addon id
>              addon_details = self.addon_details(addon)
>              addon_id = addon_details.get('id')

Why is this deleted?

::: mozprofile/setup.py
@@ +10,5 @@
>  # we only support python 2 right now
>  assert sys.version_info[0] == 2
>  
> +deps = ['ManifestDestiny >= 0.5.4',
> +        'mozfile >= 0.12']

Please remove from patch

Comment 22

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Jeff Hammel [:jhammel] from comment #20)
> > The only thing I have to know if we have to keep compatibility with
> > 2.6. If that's the case I will find a proper solution for it.
> 
> https://wiki.mozilla.org/Auto-tools/Projects/Mozbase says
> 
> "Mozbase requires python 2.6 or greater (pending bug 907794, when it
> will require 2.7) "
>
> Bug 907794 is resolved so this (badly) implies we now require
> 2.7(?!).

That's also a question I have and which we find an answer for. I hope we can get details from Dustin.

> > Well, bug 711299 hasn't been fixed yet. So I still think that a lot
> > of test machines are around which run 2.6.
> 
> If bug 711299 is a blocker for mozbase to deprecate 2.6, this should
> be noted on https://wiki.mozilla.org/Auto-tools/Projects/Mozbase .

I hope Dustin also knows about those bits.

Comment 23

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Jeff Hammel [:jhammel] from comment #21)
> For logging, I'd rather have a logger passed in to an instance, but I don't
> know if we have a consistent pattern (though we probably should).

I have read a good page about logging yesterday. Let me find out what we can do best here.

> I don't think we should fix 2.6 compatibility by raising a AddonFormatError.
> It is a harness issue.

This is not what we are doing. See my comments inline.

> ::: mozprofile/mozprofile/addons.py
> @@ +35,5 @@
> >          """
> >          self.profile = profile
> >          self.restore = restore
> >  
> > +        self.logger = mozlog.getLogger(__name__)
> 
> I'd rather give an explicit name, but this is fine.  Also, kill extra
> whitespace line.

In this case it will get the name 'mozprofile.addons', which I think is all what we need or? See http://docs.python.org/2/library/logging.html#logger-objects. With it we can control different settings for mozprofile and child loggers.

> @@ +144,5 @@
> >  
> >          raise IOError('Add-on not found: %s' % addon_id)
> >  
> >      @classmethod
> > +    def is_addon(self, addon_path, log_warning=False):
> 
> IMHO we should always log warnings if we are logging at all.

Thing is that we also make use of that method in install_from_path() when recursively iterating over sub directories to find add-ons. I don't think it is appropriate to log those warnings then. That's why I have added this flag. It should really only warn during the installation process when this method is called and we check if it is a valid addon. I could move the logging to the install_from_path() method but then we would loose the exception details.

> > +            else:
> > +                with open(os.path.join(addon_path, 'install.rdf'), 'r') as f:
> > +                    manifest = f.read()
> > +        except (IOError, KeyError), e:
> > +            raise AddonFormatError, str(e), sys.exc_info()[2]
> 
> IMHO we shouldn't treat the zipfile (library code) + `with` error as a
> AddonFormatError, since the problem is not with the addon, but with the
> harness.

We don't do that. As you can see I only catch IOError and KeyError. Both are not at all related to the missing __exit__ property, which should throw an AttributeError. KeyError is thrown via zipFile if the install.rdf file is not present, and IOError for an unpacked version of the addon.

> @@ +326,5 @@
> >          # install each addon
> >          for addon in addons:
> >              # determine the addon id
> >              addon_details = self.addon_details(addon)
> >              addon_id = addon_details.get('id')
> 
> Why is this deleted?

Because we already did that via the calls to is_addon(). All addons in this list are valid ones, so no need anymore to do the same check again.

> ::: mozprofile/setup.py
> @@ +10,5 @@
> >  # we only support python 2 right now
> >  assert sys.version_info[0] == 2
> >  
> > +deps = ['ManifestDestiny >= 0.5.4',
> > +        'mozfile >= 0.12']
> 
> Please remove from patch

Well, I would need it with the addition of mozlog, which I missed to add here.

Comment 24

[Dustin J. Mitchell [:dustin] (he/him)]

Well, I don't know a thing about mozbase's requirements (I assume from the name it's an a-team package), but the quoted sentence in comment 20 indicates a desire to drop 2.6 compatibility when the talos systems are upgraded, and not an automatic change.

What I can say is that all slave systems which are managed by PuppetAgain have Python-2.7.3 installed:

  http://hg.mozilla.org/build/puppet/file/b941c5d293e6/modules/buildslave/manifests/install/version.pp#l21
    21             include packages::mozilla::python27

and as far as I know all of the various server systems do as well.  However, foopies install both 2.6 and 2.7, so I'm not sure which they're using.

http://hg.mozilla.org/build/puppet/file/b941c5d293e6/modules/foopy/manifests/init.pp#l19
    19     include packages::mozilla::python26
    20     include packages::mozilla::python27

Bear in mind, too, that all CentOS systems have 2.6 installed in the base system, so code which does not explicitly use /tools/python27/bin/python2.7 might find itself running in 2.6.

Comment 25

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: WIP v2 (propagate exception correctly)

Updated WIP patch to propagate the exception correctly, and using the logger. Please be aware that this does not fix the underlying issue. This will be done once we agreed on the correct logging and exception handling.

Comment 26

[Jeff Hammel]

Comment on attachment 8342440 [details] [diff] [review]
WIP v2 (propagate exception correctly)

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

Looking at the code with comment 23, this looks good!

Comment 27

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Patch v1

Final patch with the old method included so that we do not break with Python 2.6. There are no additional tests needed. All existent ones cover those additions.

Comment 28

[Jeff Hammel]

Comment on attachment 8342644 [details] [diff] [review]
Patch v1

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

lgtm; thanks!

Comment 29

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Landed as:
https://github.com/mozilla/mozbase/commit/9161a783b4ba2a263b395587b0877855618395c0

Comment 30

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I had to push a follow-up patch to fix the addons test. Interestingly I haven't seen this failure before when I run all the tests. It might also be that test.py does not always report the right results.

Landed on master:
https://github.com/mozilla/mozbase/commit/c6f987eef41c5ba081e3f0942fe4cf72a6072bf5