Bazaar Version Control System

Merge lp:~mbp/bzr/406113-extension-warnings into lp:bzr

Proposed by Martin Pool on 2009-09-11
Status: Merged
Approved by: John A Meinel on 2009-09-11
Approved revision: 4584
Merged at revision: not available
Proposed branch: lp:~mbp/bzr/406113-extension-warnings
Merge into: lp:bzr
Diff against target: None lines
To merge this branch: bzr merge lp:~mbp/bzr/406113-extension-warnings
Reviewer Review Type Date Requested Status
John A Meinel 2009-09-11 Approve on 2009-09-11
Review via email: mp+11584@code.launchpad.net
To post a comment you must log in.
Martin Pool (mbp) wrote :

Here's an update for the bug 406113 taking into account John's comments in the previous review.

We now give just one warning, at the end of running bzr, describing all modules that failed to load.

John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Martin Pool wrote:
> Martin Pool has proposed merging lp:~mbp/bzr/406113-extension-warnings into lp:bzr.
>
> Requested reviews:
> bzr-core (bzr-core)
>
> Here's an update for the bug 406113 taking into account John's comments in the previous review.
>
> We now give just one warning, at the end of running bzr, describing all modules that failed to load.
>

I like it, though I'm a little concerned about:
+ warnings.warn(
+ "bzr: warning: Failed to load compiled extensions:\n"
+ " %s\n"
+ " Bazaar can run, but performance may be reduced.\n"
+ " Check Bazaar is correctly installed or set
ignore_missing_extensions"
+ % '\n '.join(_extension_load_failures,))

^- "Bazaar can run" is being issued after Bazaar finishes running. I
can't think off-hand of a better way to write it, though. So

  review: approve
  merge: approve

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkqqPGUACgkQJdeBCYSNAANLRwCgs6UGupgQYRLX1QA/lE88U9Vk
hugAn2dcrgFkwauP1wHQIbTme3f2RH9m
=7yI0
-----END PGP SIGNATURE-----

review: Approve
4585. By Martin Pool on 2009-09-14

News for fix of 406113

4586. By Martin Pool on 2009-09-14

Merge news

John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Martin Pool wrote:
> Martin Pool has proposed merging lp:~mbp/bzr/406113-extension-warnings into lp:bzr.
>
> Requested reviews:
> bzr-core (bzr-core)
>
> Here's an update for the bug 406113 taking into account John's comments in the previous review.
>
> We now give just one warning, at the end of running bzr, describing all modules that failed to load.
>

So with this new version, I just started getting the failure on
Kerguelen. So I went to investigate, but I can't get any real info. This
is what is in .bzr.log:

Tue 2009-09-22 14:18:26 +1000
0.266 bzr arguments: [u'--version']
0.406 encoding stdout as sys.stdout encoding 'cp437'
0.641 failed to load compiled extension: DLL load failed: Access is denied.
0.844 opening working tree 'C:/home/shared/bzr/bzr.dev'
6.344 return code 0
[58364] 2009-09-22 14:18:33.082 WARNING: bzr: warning: some compiled
extensions could not be loaded; see
<https://answers.launchpad.net/bzr/+faq/703>

So it says "I can't load" but it doesn't say *what* fails to load, and
with the shorter error, you don't show the summary of what failed to
load either.

- -Derror doesn't seem to help.

So I would recommend and least dropping the list of failures into the
log file.

John
=:->

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkq4UOoACgkQJdeBCYSNAAPh2QCeOoJIYy3Xie8UHG5u0fJtYrvK
rFQAoJhwF6fepodbW2uI3PUO7YVvDq3S
=l3m6
-----END PGP SIGNATURE-----

John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

John A Meinel wrote:
> Martin Pool wrote:
>> Martin Pool has proposed merging lp:~mbp/bzr/406113-extension-warnings into lp:bzr.
>
>> Requested reviews:
>> bzr-core (bzr-core)
>
>> Here's an update for the bug 406113 taking into account John's comments in the previous review.
>
>> We now give just one warning, at the end of running bzr, describing all modules that failed to load.
>
>
> So with this new version, I just started getting the failure on
> Kerguelen. So I went to investigate, but I can't get any real info. This
> is what is in .bzr.log:
>
> Tue 2009-09-22 14:18:26 +1000
> 0.266 bzr arguments: [u'--version']
> 0.406 encoding stdout as sys.stdout encoding 'cp437'
> 0.641 failed to load compiled extension: DLL load failed: Access is denied.
> 0.844 opening working tree 'C:/home/shared/bzr/bzr.dev'
> 6.344 return code 0
> [58364] 2009-09-22 14:18:33.082 WARNING: bzr: warning: some compiled
> extensions could not be loaded; see
> <https://answers.launchpad.net/bzr/+faq/703>
>
>
> So it says "I can't load" but it doesn't say *what* fails to load, and
> with the shorter error, you don't show the summary of what failed to
> load either.
>
> -Derror doesn't seem to help.
>
> So I would recommend and least dropping the list of failures into the
> log file.

So I tried editing it myself, and that error message is all you get from
the exception. (ie, it doesn't tell you what plugin failed to load).

To get that info, we would have to actually add it to the api... :(

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkq4WfwACgkQJdeBCYSNAAO4agCfbmz3mRCWx722uX8IMmEBDCbt
XakAoIKkTQpW0whPZxvWpDXKbOAape5D
=S/ns
-----END PGP SIGNATURE-----

Martin Pool (mbp) wrote :

2009/9/22 John Arbash Meinel <email address hidden>:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> John A Meinel wrote:
>> Martin Pool wrote:
>>> Martin Pool has proposed merging lp:~mbp/bzr/406113-extension-warnings into lp:bzr.
>>
>>> Requested reviews:
>>>     bzr-core (bzr-core)
>>
>>> Here's an update for the bug 406113 taking into account John's comments in the previous review.
>>
>>> We now give just one warning, at the end of running bzr, describing all modules that failed to load.
>>
>>
>> So with this new version, I just started getting the failure on
>> Kerguelen. So I went to investigate, but I can't get any real info. This
>> is what is in .bzr.log:
>>
>> Tue 2009-09-22 14:18:26 +1000
>> 0.266  bzr arguments: [u'--version']
>> 0.406  encoding stdout as sys.stdout encoding 'cp437'
>> 0.641  failed to load compiled extension: DLL load failed: Access is denied.
>> 0.844  opening working tree 'C:/home/shared/bzr/bzr.dev'
>> 6.344  return code 0
>> [58364] 2009-09-22 14:18:33.082 WARNING: bzr: warning: some compiled
>> extensions could not be loaded; see
>> <https://answers.launchpad.net/bzr/+faq/703>
>>
>>
>> So it says "I can't load" but it doesn't say *what* fails to load, and
>> with the shorter error, you don't show the summary of what failed to
>> load either.
>>
>> -Derror doesn't seem to help.
>>
>> So I would recommend and least dropping the list of failures into the
>> log file.
>
> So I tried editing it myself, and that error message is all you get from
> the exception. (ie, it doesn't tell you what plugin failed to load).
>
> To get that info, we would have to actually add it to the api... :(

Do we even know which plugin is involved here?

It seems weird to me that a unix program would use the term "DLL", so
I suspect it's hardcoded in one of our plugins, and they're raising a
custom ImportError.

--
Martin <http://launchpad.net/~mbp/>

John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

...

>>> So with this new version, I just started getting the failure on
>>> Kerguelen. So I went to investigate, but I can't get any real info. This
>>> is what is in .bzr.log:
>>>
>>> Tue 2009-09-22 14:18:26 +1000
>>> 0.266 bzr arguments: [u'--version']
>>> 0.406 encoding stdout as sys.stdout encoding 'cp437'
>>> 0.641 failed to load compiled extension: DLL load failed: Access is denied.
>>> 0.844 opening working tree 'C:/home/shared/bzr/bzr.dev'
>>> 6.344 return code 0
>>> [58364] 2009-09-22 14:18:33.082 WARNING: bzr: warning: some compiled
>>> extensions could not be loaded; see
>>> <https://answers.launchpad.net/bzr/+faq/703>
>>>
>>>
>>> So it says "I can't load" but it doesn't say *what* fails to load, and
>>> with the shorter error, you don't show the summary of what failed to
>>> load either.
>>>
>>> -Derror doesn't seem to help.
>>>
>>> So I would recommend and least dropping the list of failures into the
>>> log file.
>> So I tried editing it myself, and that error message is all you get from
>> the exception. (ie, it doesn't tell you what plugin failed to load).
>>
>> To get that info, we would have to actually add it to the api... :(
>
> Do we even know which plugin is involved here?
>
> It seems weird to me that a unix program would use the term "DLL", so
> I suspect it's hardcoded in one of our plugins, and they're raising a
> custom ImportError.

Well, this is on Windows, and it occurs even after I delete everything
and rebuild. I wonder if it is the _readdir_pyx issue, but I sort of
doubt it.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkq4X+AACgkQJdeBCYSNAAO6YQCgix5Uw6p+EUh4+KMpALR15Qja
q/gAoL/CPIJuoeJ2OhzPxWJxie2JMiiy
=p4bA
-----END PGP SIGNATURE-----

Martin Pool (mbp) wrote :

2009/9/22 John Arbash Meinel <email address hidden>:
> Well, this is on Windows, and it occurs even after I delete everything
> and rebuild. I wonder if it is the _readdir_pyx issue, but I sort of
> doubt it.

My mistake.

I was assuming that the ImportError would always tell you what module
failed. Apparently not. If you file another bug, we can arrange for
the module name to be included in the message.

--
Martin <http://launchpad.net/~mbp/>

John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Martin Pool wrote:
> 2009/9/22 John Arbash Meinel <email address hidden>:
>> Well, this is on Windows, and it occurs even after I delete everything
>> and rebuild. I wonder if it is the _readdir_pyx issue, but I sort of
>> doubt it.
>
> My mistake.
>
> I was assuming that the ImportError would always tell you what module
> failed. Apparently not. If you file another bug, we can arrange for
> the module name to be included in the message.
>
>

I managed to track it down to a failure to load _chk_map_pyx, and *that*
was actually because it was failing to import zlib1.dll.

By copying zlib1.dll into the bzrlib folder, and then changing the
permission bits, things worked again.

I did submit a bug request for making debugging extension failures
easier. On the plus side, this is exactly what your patch helps, since
before we just didn't know that things were failing.

John
=:->

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkq48psACgkQJdeBCYSNAAN11wCcD2hOqQRbs/gpVbnKUGGkpHWJ
++kAn2oGw3gxDXsfhNeA8UYEpgD+jSHY
=XpUz
-----END PGP SIGNATURE-----

Preview Diff

1=== modified file 'bzrlib/__init__.py'
2--- bzrlib/__init__.py 2009-07-20 11:27:05 +0000
3+++ bzrlib/__init__.py 2009-07-29 03:08:32 +0000
4@@ -55,6 +55,7 @@
5 # API compatibility version: bzrlib is currently API compatible with 1.15.
6 api_minimum_version = (1, 17, 0)
7
8+
9 def _format_version_tuple(version_info):
10 """Turn a version number 2, 3 or 5-tuple into a short string.
11
12
13=== modified file 'bzrlib/annotate.py'
14--- bzrlib/annotate.py 2009-07-08 17:09:03 +0000
15+++ bzrlib/annotate.py 2009-09-11 06:36:50 +0000
16@@ -454,5 +454,6 @@
17
18 try:
19 from bzrlib._annotator_pyx import Annotator
20-except ImportError:
21+except ImportError, e:
22+ osutils.failed_to_load_extension(e)
23 from bzrlib._annotator_py import Annotator
24
25=== modified file 'bzrlib/bencode.py'
26--- bzrlib/bencode.py 2009-06-03 14:14:31 +0000
27+++ bzrlib/bencode.py 2009-09-11 06:36:50 +0000
28@@ -16,7 +16,10 @@
29
30 """Wrapper around the bencode pyrex and python implementation"""
31
32+from bzrlib import osutils
33+
34 try:
35 from bzrlib._bencode_pyx import bdecode, bdecode_as_tuple, bencode, Bencached
36-except ImportError:
37+except ImportError, e:
38+ osutils.failed_to_load_extension(e)
39 from bzrlib.util._bencode_py import bdecode, bdecode_as_tuple, bencode, Bencached
40
41=== modified file 'bzrlib/btree_index.py'
42--- bzrlib/btree_index.py 2009-07-01 10:51:47 +0000
43+++ bzrlib/btree_index.py 2009-09-11 06:36:50 +0000
44@@ -1385,5 +1385,6 @@
45
46 try:
47 from bzrlib import _btree_serializer_pyx as _btree_serializer
48-except ImportError:
49+except ImportError, e:
50+ osutils.failed_to_load_extension(e)
51 from bzrlib import _btree_serializer_py as _btree_serializer
52
53=== modified file 'bzrlib/chk_map.py'
54--- bzrlib/chk_map.py 2009-07-16 23:28:49 +0000
55+++ bzrlib/chk_map.py 2009-09-11 06:36:50 +0000
56@@ -1637,7 +1637,8 @@
57 _deserialise_leaf_node,
58 _deserialise_internal_node,
59 )
60-except ImportError:
61+except ImportError, e:
62+ osutils.failed_to_load_extension(e)
63 from bzrlib._chk_map_py import (
64 _search_key_16,
65 _search_key_255,
66
67=== modified file 'bzrlib/commands.py'
68--- bzrlib/commands.py 2009-06-19 09:06:56 +0000
69+++ bzrlib/commands.py 2009-09-11 06:42:23 +0000
70@@ -1107,6 +1107,7 @@
71 argv = new_argv
72 ret = run_bzr_catch_errors(argv)
73 trace.mutter("return code %d", ret)
74+ osutils.report_extension_load_failures()
75 return ret
76
77
78
79=== modified file 'bzrlib/dirstate.py'
80--- bzrlib/dirstate.py 2009-07-20 08:56:45 +0000
81+++ bzrlib/dirstate.py 2009-09-11 06:36:50 +0000
82@@ -3809,7 +3809,8 @@
83 ProcessEntryC as _process_entry,
84 update_entry as update_entry,
85 )
86-except ImportError:
87+except ImportError, e:
88+ osutils.failed_to_load_extension(e)
89 from bzrlib._dirstate_helpers_py import (
90 _read_dirblocks,
91 bisect_dirblock,
92
93=== modified file 'bzrlib/graph.py'
94--- bzrlib/graph.py 2009-06-12 18:05:15 +0000
95+++ bzrlib/graph.py 2009-09-11 06:36:50 +0000
96@@ -19,6 +19,7 @@
97 from bzrlib import (
98 debug,
99 errors,
100+ osutils,
101 revision,
102 trace,
103 tsort,
104@@ -1660,5 +1661,6 @@
105 _counters = [0,0,0,0,0,0,0]
106 try:
107 from bzrlib._known_graph_pyx import KnownGraph
108-except ImportError:
109+except ImportError, e:
110+ osutils.failed_to_load_extension(e)
111 from bzrlib._known_graph_py import KnownGraph
112
113=== modified file 'bzrlib/groupcompress.py'
114--- bzrlib/groupcompress.py 2009-07-06 20:21:34 +0000
115+++ bzrlib/groupcompress.py 2009-09-11 06:36:50 +0000
116@@ -1828,6 +1828,7 @@
117 decode_base128_int,
118 )
119 GroupCompressor = PyrexGroupCompressor
120-except ImportError:
121+except ImportError, e:
122+ osutils.failed_to_load_extension(e)
123 GroupCompressor = PythonGroupCompressor
124
125
126=== modified file 'bzrlib/knit.py'
127--- bzrlib/knit.py 2009-07-28 08:09:13 +0000
128+++ bzrlib/knit.py 2009-09-11 06:36:50 +0000
129@@ -3622,5 +3622,6 @@
130
131 try:
132 from bzrlib._knit_load_data_pyx import _load_data_c as _load_data
133-except ImportError:
134+except ImportError, e:
135+ osutils.failed_to_load_extension(e)
136 from bzrlib._knit_load_data_py import _load_data_py as _load_data
137
138=== modified file 'bzrlib/osutils.py'
139--- bzrlib/osutils.py 2009-07-23 16:01:17 +0000
140+++ bzrlib/osutils.py 2009-09-11 06:39:56 +0000
141@@ -21,6 +21,7 @@
142 S_ISCHR, S_ISBLK, S_ISFIFO, S_ISSOCK)
143 import sys
144 import time
145+import warnings
146
147 from bzrlib.lazy_import import lazy_import
148 lazy_import(globals(), """
149@@ -881,9 +882,56 @@
150 return parents
151
152
153+_extension_load_failures = []
154+
155+
156+def failed_to_load_extension(exception):
157+ """Handle failing to load a binary extension.
158+
159+ This should be called from the ImportError block guarding the attempt to
160+ import the native extension. If this function returns, the pure-Python
161+ implementation should be loaded instead::
162+
163+ >>> try:
164+ >>> import bzrlib._fictional_extension_pyx
165+ >>> except ImportError, e:
166+ >>> bzrlib.osutils.failed_to_load_extension(e)
167+ >>> import bzrlib._fictional_extension_py
168+ """
169+ # NB: This docstring is just an example, not a doctest, because doctest
170+ # currently can't cope with the use of lazy imports in this namespace --
171+ # mbp 20090729
172+
173+ # This currently doesn't report the failure at the time it occurs, because
174+ # they tend to happen very early in startup when we can't check config
175+ # files etc, and also we want to report all failures but not spam the user
176+ # with 10 warnings.
177+ from bzrlib import trace
178+ exception_str = str(exception)
179+ if exception_str not in _extension_load_failures:
180+ trace.mutter("failed to load compiled extension: %s" % exception_str)
181+ _extension_load_failures.append(exception_str)
182+
183+
184+def report_extension_load_failures():
185+ if not _extension_load_failures:
186+ return
187+ from bzrlib.config import GlobalConfig
188+ if GlobalConfig().get_user_option_as_bool('ignore_missing_extensions'):
189+ return
190+ # the warnings framework should by default show this only once
191+ warnings.warn(
192+ "bzr: warning: Failed to load compiled extensions:\n"
193+ " %s\n"
194+ " Bazaar can run, but performance may be reduced.\n"
195+ " Check Bazaar is correctly installed or set ignore_missing_extensions"
196+ % '\n '.join(_extension_load_failures,))
197+
198+
199 try:
200 from bzrlib._chunks_to_lines_pyx import chunks_to_lines
201-except ImportError:
202+except ImportError, e:
203+ failed_to_load_extension(e)
204 from bzrlib._chunks_to_lines_py import chunks_to_lines
205
206
207@@ -1466,7 +1514,8 @@
208 try:
209 from bzrlib._readdir_pyx import UTF8DirReader
210 _selected_dir_reader = UTF8DirReader()
211- except ImportError:
212+ except ImportError, e:
213+ failed_to_load_extension(e)
214 pass
215
216 if _selected_dir_reader is None:
217@@ -1778,7 +1827,8 @@
218 try:
219 from bzrlib._readdir_pyx import UTF8DirReader
220 file_kind_from_stat_mode = UTF8DirReader().kind_from_mode
221- except ImportError:
222+ except ImportError, e:
223+ failed_to_load_extension(e)
224 from bzrlib._readdir_py import (
225 _kind_from_mode as file_kind_from_stat_mode
226 )
227
228=== modified file 'bzrlib/rio.py'
229--- bzrlib/rio.py 2009-06-10 03:56:49 +0000
230+++ bzrlib/rio.py 2009-09-11 06:36:50 +0000
231@@ -32,6 +32,7 @@
232
233 import re
234
235+from bzrlib import osutils
236 from bzrlib.iterablefile import IterableFile
237
238 # XXX: some redundancy is allowing to write stanzas in isolation as well as
239@@ -377,7 +378,8 @@
240 _read_stanza_unicode,
241 _valid_tag,
242 )
243-except ImportError:
244+except ImportError, e:
245+ osutils.failed_to_load_extension(e)
246 from bzrlib._rio_py import (
247 _read_stanza_utf8,
248 _read_stanza_unicode,
249
250=== modified file 'bzrlib/tests/test_osutils.py'
251--- bzrlib/tests/test_osutils.py 2009-07-23 16:01:17 +0000
252+++ bzrlib/tests/test_osutils.py 2009-09-11 06:36:50 +0000
253@@ -1798,3 +1798,33 @@
254 def test_local_concurrency(self):
255 concurrency = osutils.local_concurrency()
256 self.assertIsInstance(concurrency, int)
257+
258+
259+class TestFailedToLoadExtension(tests.TestCase):
260+
261+ def _try_loading(self):
262+ try:
263+ import bzrlib._fictional_extension_py
264+ except ImportError, e:
265+ osutils.failed_to_load_extension(e)
266+ return True
267+
268+ def setUp(self):
269+ super(TestFailedToLoadExtension, self).setUp()
270+ self.saved_failures = osutils._extension_load_failures[:]
271+ del osutils._extension_load_failures[:]
272+ self.addCleanup(self.restore_failures)
273+
274+ def restore_failures(self):
275+ osutils._extension_load_failures = self.saved_failures
276+
277+ def test_failure_to_load(self):
278+ self._try_loading()
279+ self.assertLength(1, osutils._extension_load_failures)
280+ self.assertEquals(osutils._extension_load_failures[0],
281+ "No module named _fictional_extension_py")
282+
283+ def test_report_extension_load_failures(self):
284+ self.assertTrue(self._try_loading())
285+ warnings, result = self.callCatchWarnings(osutils.report_extension_load_failures)
286+ self.assertLength(1, warnings)