Merge lp:~gary-lasker/software-center/fix-makedirs-race-crashes into lp:software-center

Proposed by Gary Lasker
Status: Merged
Merged at revision: 3006
Proposed branch: lp:~gary-lasker/software-center/fix-makedirs-race-crashes
Merge into: lp:software-center
Diff against target: 174 lines (+82/-27)
4 files modified
softwarecenter/config.py (+2/-2)
softwarecenter/log.py (+3/-3)
softwarecenter/utils.py (+42/-22)
test/test_logging.py (+35/-0)
To merge this branch: bzr merge lp:~gary-lasker/software-center/fix-makedirs-race-crashes
Reviewer Review Type Date Requested Status
software-store-developers Pending
Review via email: mp+105389@code.launchpad.net

Description of the change

This branch fixes one of the most common software-center crashes as reported at errors.ubuntu.com, bug 743003, as well as bug 621182. These crashes appear to occur in new installs of Ubuntu, and are the result of a race between different processes creating the cache directory (for bug 743003) and the config directory (for bug 621182). The crash occurs because os.makedirs will throw an OSError if it is called and the directory is found to already exist. The fix for both of these use a new method in utils called safe_makedirs.

I also added a new unit test, test_logging.py, as suggested in comment #3 of bug 743003. This unit test checks the case where the cache directory is found to be not writable, and so is moved aside and a new cache directory created. I'm not sure if the code in log.py itself needs a change as it seems to work fine. It has been modified to use the new safe_makedirs method in any case.

Thanks for your review!

To post a comment you must log in.
3007. By Gary Lasker on 2012-05-10

make test_logging.py a little better

Michael Vogt (mvo) wrote :

Thanks for the branch, it looks good, but there is a issue with the test.

I noticed that you use "os.chmod(cache_dir, 600)" here. As this is decimal 600 (and not octal) its confusing for me to read and will result in a odd permission on disk (see my comment for https://code.launchpad.net/~gary-lasker/software-center/fix-shutdown-crash-lp996333/+merge/105027). Please use either 0400 or stat.S_IRUSR.

It would be nice if safe_makedirs() would get a individual test in test_utils.py (even though its pretty trivial).

Gary Lasker (gary-lasker) wrote :

Oh sure, thanks, I'll fix that (the value) for both merges. Often, with very trivial details like this, I'll just make the tweak and do the merge, and then just mention the fix here. That way we expedite the merge (reduce the back and forth), and still share knowledge and best practices. I've seen you do that yourself for many merges, so I hope you will feel free to do the same for trivial cases like this.

As far as a test for safe_makedirs, of course my impulse is to write it but I think there comes a point where a test gets to be overkill, and this is one of those cases imo. Meaning, the test itself will probably be 2-3x the lines of code of the function it's actually testing (which is pretty trivial, as you said, really little more than a single line protected by a try/except block). But it's not a problem, I can add it if you really want me to.

3008. By Gary Lasker on 2012-05-11

use stat values for setting the chmod value in the unit test

Gary Lasker (gary-lasker) wrote :

Hi Michael, I updated the unit test to use stat.S_IRUSR as this definitely seem more proper (as I mentioned in the other MP). Thanks again!

Gary Lasker (gary-lasker) wrote :

I took a quick look at making a unit test for safe_makedirs, but I don't immediately see a way to simulate the race condition that causes the error. If you would like a test for that and have any ideas about how to simulate the condition, please let me know and I'll be happy to write the test. As I mentioned, though, I think it's a trivial enough method that a unit test for it is probably overkill.

Thanks again!

Michael Vogt (mvo) wrote :

Thanks for updating the branch. Its fine now and I merged it into 5.2

I wrote a small unittest that does not exactly simulate the race, but gets close by patching os.path.exists() which will lead to calling the makedir code in any case so we can test that it does not crash for existing dirs and also propergate regular errors still.

As for the earlier comment, I did not want to fix the decimal vs octal issue during the merge because to me its not a trivial detail as it touched the test in such a way that the logic had to be inverted and it also touched two branches.

For small stuff I still do it (and you are always free to correct me here of course when I overdo it or make mistakes).

Small stuff to me is something like:
             LOG.warn("encountered non-writeable file, attempting to fix "
- "by deleting: %s",
- file_path)
+ "by deleting: %s" % file_path)
(not the "," vs the "%s") which is not really as issue as LOG will happily deal with the "," but the "%" is
more python. But no logic changed etc.

Michael Vogt (mvo) wrote :

I need to correct myself here about my LOG.warn() change. As Natalia pointed out in another branch its actually preferable to use "," in the logging module than to use "%" as it means that on string format mismatches there
will be no expection in the logging. This is a good reason to use "," and we should keep that in mind for
future branches as a good policy.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'softwarecenter/config.py'
2--- softwarecenter/config.py 2012-04-02 18:23:20 +0000
3+++ softwarecenter/config.py 2012-05-11 22:48:19 +0000
4@@ -31,8 +31,8 @@
5
6 def __init__(self, config):
7 SafeConfigParser.__init__(self)
8- if not os.path.exists(os.path.dirname(config)):
9- os.makedirs(os.path.dirname(config))
10+ from utils import safe_makedirs
11+ safe_makedirs(os.path.dirname(config))
12 # we always want this section, even on fresh installs
13 self.add_section("general")
14 # read the config
15
16=== modified file 'softwarecenter/log.py'
17--- softwarecenter/log.py 2012-03-15 10:43:13 +0000
18+++ softwarecenter/log.py 2012-05-11 22:48:19 +0000
19@@ -23,6 +23,7 @@
20 import os.path
21
22 from paths import SOFTWARE_CENTER_CACHE_DIR
23+from utils import safe_makedirs
24
25 """ setup global logging for software-center """
26
27@@ -92,8 +93,7 @@
28 handler.addFilter(NullFilterThatWarnsAboutRootLoggerUsage())
29
30 # create log file
31-if not os.path.exists(SOFTWARE_CENTER_CACHE_DIR):
32- os.makedirs(SOFTWARE_CENTER_CACHE_DIR)
33+safe_makedirs(SOFTWARE_CENTER_CACHE_DIR)
34 logfile_path = os.path.join(SOFTWARE_CENTER_CACHE_DIR, "software-center.log")
35
36 # try to fix inaccessible s-c directory (#688682)
37@@ -107,7 +107,7 @@
38 if not os.path.exists(target):
39 os.rename(SOFTWARE_CENTER_CACHE_DIR, target)
40 break
41- os.makedirs(SOFTWARE_CENTER_CACHE_DIR)
42+ safe_makedirs(SOFTWARE_CENTER_CACHE_DIR)
43
44 # according to bug 688682 many people have a non-writeable logfile
45 if os.path.exists(logfile_path) and not os.access(logfile_path, os.W_OK):
46
47=== modified file 'softwarecenter/utils.py'
48--- softwarecenter/utils.py 2012-04-25 08:19:42 +0000
49+++ softwarecenter/utils.py 2012-05-11 22:48:19 +0000
50@@ -28,6 +28,7 @@
51 import traceback
52 import time
53 import xml.sax.saxutils
54+import errno
55
56 # py3 compat
57 try:
58@@ -655,6 +656,47 @@
59 os.close(lock)
60
61
62+def make_string_from_list(base_str, item_list):
63+ """ This function takes a list of items and builds a nice human readable
64+ string with it of the form. Note that the base string needs a "%s".
65+ Example return:
66+ The base string with the list items a,b and c in it.
67+ Note that base_str needs to be a ngettext string already, so the
68+ example usage is:
69+ l = ["foo", "bar"]
70+ base_str = ngettext("This list: %s.", "This list: %s", len(l))
71+ s = make_string_from_list(base_string, l)
72+ """
73+ list_str = item_list[0]
74+ if len(item_list) > 1:
75+ # TRANSLATORS: this is a generic list delimit char, e.g. "foo, bar"
76+ list_str = _(", ").join(item_list[:-1])
77+ # TRANSLATORS: this is the last part of a list, e.g. "foo, bar and baz"
78+ list_str = _("%s and %s") % (list_str,
79+ item_list[-1])
80+ s = base_str % list_str
81+ return s
82+
83+
84+def safe_makedirs(dir_path):
85+ """ This function can be used in place of a straight os.makedirs to
86+ handle the possibility of a race condition when more than one
87+ process may potentially be creating the same directory (if this occurs,
88+ it will throw an OSError, see for example LP: #743003)
89+ """
90+ if not os.path.exists(dir_path):
91+ try:
92+ os.makedirs(dir_path)
93+ except OSError as e:
94+ if e.errno == errno.EEXIST:
95+ # it seems that another process has already created this
96+ # directory in the meantime, that's ok
97+ pass
98+ else:
99+ # the error is due to something else, so we want to raise it
100+ raise
101+
102+
103 class SimpleFileDownloader(GObject.GObject):
104
105 LOG = logging.getLogger("softwarecenter.simplefiledownloader")
106@@ -782,28 +824,6 @@
107 self.emit('file-download-complete', self.dest_file_path)
108
109
110-def make_string_from_list(base_str, item_list):
111- """ This function takes a list of items and builds a nice human readable
112- string with it of the form. Note that the base string needs a "%s".
113- Example return:
114- The base string with the list items a,b and c in it.
115- Note that base_str needs to be a ngettext string already, so the
116- example usage is:
117- l = ["foo", "bar"]
118- base_str = ngettext("This list: %s.", "This list: %s", len(l))
119- s = make_string_from_list(base_string, l)
120- """
121- list_str = item_list[0]
122- if len(item_list) > 1:
123- # TRANSLATORS: this is a generic list delimit char, e.g. "foo, bar"
124- list_str = _(", ").join(item_list[:-1])
125- # TRANSLATORS: this is the last part of a list, e.g. "foo, bar and baz"
126- list_str = _("%s and %s") % (list_str,
127- item_list[-1])
128- s = base_str % list_str
129- return s
130-
131-
132 # those helpers are packaging system specific
133 from softwarecenter.db.pkginfo import get_pkg_info
134 # do not call here get_pkg_info, since package switch may not have been set
135
136=== added file 'test/test_logging.py'
137--- test/test_logging.py 1970-01-01 00:00:00 +0000
138+++ test/test_logging.py 2012-05-11 22:48:19 +0000
139@@ -0,0 +1,35 @@
140+#!/usr/bin/python
141+
142+import os
143+import stat
144+import unittest
145+
146+from testutils import setup_test_env
147+setup_test_env()
148+
149+
150+class TestLogging(unittest.TestCase):
151+ """ tests the sc logging facilities """
152+
153+ def test_no_write_access_for_cache_dir(self):
154+ """ test for bug LP: #688682 """
155+ # make the test cache dir non-writeable
156+ import softwarecenter.paths
157+ cache_dir = softwarecenter.paths.SOFTWARE_CENTER_CACHE_DIR
158+ os.chmod(cache_dir, stat.S_IRUSR)
159+ self.assertFalse(os.access(cache_dir, os.W_OK))
160+ # and then start up the logger
161+ import softwarecenter.log
162+ softwarecenter.log # pyflakes
163+ # check that the old directory was moved aside (renamed with a ".0" appended)
164+ self.assertTrue(os.path.exists(cache_dir + ".0"))
165+ self.assertFalse(os.path.exists(cache_dir + ".1"))
166+ # and check that the new directory was created and is now writable
167+ self.assertTrue(os.path.exists(cache_dir))
168+ self.assertTrue(os.access(cache_dir, os.W_OK))
169+
170+
171+if __name__ == "__main__":
172+ import logging
173+ logging.basicConfig(level=logging.DEBUG)
174+ unittest.main()

Subscribers

People subscribed via source and target branches