services/sync/tests/unit/test_errorhandler_filelog.js

branch
TOR_BUG_9701
changeset 15
b8a032363ba2
equal deleted inserted replaced
-1:000000000000 0:cfa05e963a18
1 /* Any copyright is dedicated to the Public Domain.
2 http://creativecommons.org/publicdomain/zero/1.0/ */
3
4 Cu.import("resource://gre/modules/Log.jsm");
5 Cu.import("resource://services-common/utils.js");
6 Cu.import("resource://services-sync/service.js");
7 Cu.import("resource://services-sync/util.js");
8 Cu.import("resource://gre/modules/FileUtils.jsm");
9 Cu.import("resource://gre/modules/NetUtil.jsm");
10
11 const logsdir = FileUtils.getDir("ProfD", ["weave", "logs"], true);
12 const LOG_PREFIX_SUCCESS = "success-";
13 const LOG_PREFIX_ERROR = "error-";
14
15 // Delay to wait before cleanup, to allow files to age.
16 // This is so large because the file timestamp granularity is per-second, and
17 // so otherwise we can end up with all of our files -- the ones we want to
18 // keep, and the ones we want to clean up -- having the same modified time.
19 const CLEANUP_DELAY = 2000;
20 const DELAY_BUFFER = 500; // Buffer for timers on different OS platforms.
21
22 const PROLONGED_ERROR_DURATION =
23 (Svc.Prefs.get('errorhandler.networkFailureReportTimeout') * 2) * 1000;
24
25 let errorHandler = Service.errorHandler;
26
27 function setLastSync(lastSyncValue) {
28 Svc.Prefs.set("lastSync", (new Date(Date.now() - lastSyncValue)).toString());
29 }
30
31 function run_test() {
32 initTestLogging("Trace");
33
34 Log.repository.getLogger("Sync.Service").level = Log.Level.Trace;
35 Log.repository.getLogger("Sync.SyncScheduler").level = Log.Level.Trace;
36 Log.repository.getLogger("Sync.ErrorHandler").level = Log.Level.Trace;
37
38 run_next_test();
39 }
40
41 add_test(function test_noOutput() {
42 // Ensure that the log appender won't print anything.
43 errorHandler._logAppender.level = Log.Level.Fatal + 1;
44
45 // Clear log output from startup.
46 Svc.Prefs.set("log.appender.file.logOnSuccess", false);
47 Svc.Obs.notify("weave:service:sync:finish");
48
49 // Clear again without having issued any output.
50 Svc.Prefs.set("log.appender.file.logOnSuccess", true);
51
52 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
53 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
54
55 errorHandler._logAppender.level = Log.Level.Trace;
56 Svc.Prefs.resetBranch("");
57 run_next_test();
58 });
59
60 // Fake a successful sync.
61 Svc.Obs.notify("weave:service:sync:finish");
62 });
63
64 add_test(function test_logOnSuccess_false() {
65 Svc.Prefs.set("log.appender.file.logOnSuccess", false);
66
67 let log = Log.repository.getLogger("Sync.Test.FileLog");
68 log.info("this won't show up");
69
70 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
71 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
72 // No log file was written.
73 do_check_false(logsdir.directoryEntries.hasMoreElements());
74
75 Svc.Prefs.resetBranch("");
76 run_next_test();
77 });
78
79 // Fake a successful sync.
80 Svc.Obs.notify("weave:service:sync:finish");
81 });
82
83 function readFile(file, callback) {
84 NetUtil.asyncFetch(file, function (inputStream, statusCode, request) {
85 let data = NetUtil.readInputStreamToString(inputStream,
86 inputStream.available());
87 callback(statusCode, data);
88 });
89 }
90
91 add_test(function test_logOnSuccess_true() {
92 Svc.Prefs.set("log.appender.file.logOnSuccess", true);
93
94 let log = Log.repository.getLogger("Sync.Test.FileLog");
95 const MESSAGE = "this WILL show up";
96 log.info(MESSAGE);
97
98 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
99 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
100
101 // Exactly one log file was written.
102 let entries = logsdir.directoryEntries;
103 do_check_true(entries.hasMoreElements());
104 let logfile = entries.getNext().QueryInterface(Ci.nsILocalFile);
105 do_check_eq(logfile.leafName.slice(-4), ".txt");
106 do_check_eq(logfile.leafName.slice(0, LOG_PREFIX_SUCCESS.length),
107 LOG_PREFIX_SUCCESS);
108 do_check_false(entries.hasMoreElements());
109
110 // Ensure the log message was actually written to file.
111 readFile(logfile, function (error, data) {
112 do_check_true(Components.isSuccessCode(error));
113 do_check_neq(data.indexOf(MESSAGE), -1);
114
115 // Clean up.
116 try {
117 logfile.remove(false);
118 } catch(ex) {
119 dump("Couldn't delete file: " + ex + "\n");
120 // Stupid Windows box.
121 }
122
123 Svc.Prefs.resetBranch("");
124 run_next_test();
125 });
126 });
127
128 // Fake a successful sync.
129 Svc.Obs.notify("weave:service:sync:finish");
130 });
131
132 add_test(function test_sync_error_logOnError_false() {
133 Svc.Prefs.set("log.appender.file.logOnError", false);
134
135 let log = Log.repository.getLogger("Sync.Test.FileLog");
136 log.info("this won't show up");
137
138 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
139 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
140 // No log file was written.
141 do_check_false(logsdir.directoryEntries.hasMoreElements());
142
143 Svc.Prefs.resetBranch("");
144 run_next_test();
145 });
146
147 // Fake an unsuccessful sync due to prolonged failure.
148 setLastSync(PROLONGED_ERROR_DURATION);
149 Svc.Obs.notify("weave:service:sync:error");
150 });
151
152 add_test(function test_sync_error_logOnError_true() {
153 Svc.Prefs.set("log.appender.file.logOnError", true);
154
155 let log = Log.repository.getLogger("Sync.Test.FileLog");
156 const MESSAGE = "this WILL show up";
157 log.info(MESSAGE);
158
159 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
160 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
161
162 // Exactly one log file was written.
163 let entries = logsdir.directoryEntries;
164 do_check_true(entries.hasMoreElements());
165 let logfile = entries.getNext().QueryInterface(Ci.nsILocalFile);
166 do_check_eq(logfile.leafName.slice(-4), ".txt");
167 do_check_eq(logfile.leafName.slice(0, LOG_PREFIX_ERROR.length),
168 LOG_PREFIX_ERROR);
169 do_check_false(entries.hasMoreElements());
170
171 // Ensure the log message was actually written to file.
172 readFile(logfile, function (error, data) {
173 do_check_true(Components.isSuccessCode(error));
174 do_check_neq(data.indexOf(MESSAGE), -1);
175
176 // Clean up.
177 try {
178 logfile.remove(false);
179 } catch(ex) {
180 dump("Couldn't delete file: " + ex + "\n");
181 // Stupid Windows box.
182 }
183
184 Svc.Prefs.resetBranch("");
185 run_next_test();
186 });
187 });
188
189 // Fake an unsuccessful sync due to prolonged failure.
190 setLastSync(PROLONGED_ERROR_DURATION);
191 Svc.Obs.notify("weave:service:sync:error");
192 });
193
194 add_test(function test_login_error_logOnError_false() {
195 Svc.Prefs.set("log.appender.file.logOnError", false);
196
197 let log = Log.repository.getLogger("Sync.Test.FileLog");
198 log.info("this won't show up");
199
200 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
201 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
202 // No log file was written.
203 do_check_false(logsdir.directoryEntries.hasMoreElements());
204
205 Svc.Prefs.resetBranch("");
206 run_next_test();
207 });
208
209 // Fake an unsuccessful login due to prolonged failure.
210 setLastSync(PROLONGED_ERROR_DURATION);
211 Svc.Obs.notify("weave:service:login:error");
212 });
213
214 add_test(function test_login_error_logOnError_true() {
215 Svc.Prefs.set("log.appender.file.logOnError", true);
216
217 let log = Log.repository.getLogger("Sync.Test.FileLog");
218 const MESSAGE = "this WILL show up";
219 log.info(MESSAGE);
220
221 Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
222 Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
223
224 // Exactly one log file was written.
225 let entries = logsdir.directoryEntries;
226 do_check_true(entries.hasMoreElements());
227 let logfile = entries.getNext().QueryInterface(Ci.nsILocalFile);
228 do_check_eq(logfile.leafName.slice(-4), ".txt");
229 do_check_eq(logfile.leafName.slice(0, LOG_PREFIX_ERROR.length),
230 LOG_PREFIX_ERROR);
231 do_check_false(entries.hasMoreElements());
232
233 // Ensure the log message was actually written to file.
234 readFile(logfile, function (error, data) {
235 do_check_true(Components.isSuccessCode(error));
236 do_check_neq(data.indexOf(MESSAGE), -1);
237
238 // Clean up.
239 try {
240 logfile.remove(false);
241 } catch(ex) {
242 dump("Couldn't delete file: " + ex + "\n");
243 // Stupid Windows box.
244 }
245
246 Svc.Prefs.resetBranch("");
247 run_next_test();
248 });
249 });
250
251 // Fake an unsuccessful login due to prolonged failure.
252 setLastSync(PROLONGED_ERROR_DURATION);
253 Svc.Obs.notify("weave:service:login:error");
254 });
255
256 // Check that error log files are deleted above an age threshold.
257 add_test(function test_logErrorCleanup_age() {
258 _("Beginning test_logErrorCleanup_age.");
259 let maxAge = CLEANUP_DELAY / 1000;
260 let oldLogs = [];
261 let numLogs = 10;
262 let errString = "some error log\n";
263
264 Svc.Prefs.set("log.appender.file.logOnError", true);
265 Svc.Prefs.set("log.appender.file.maxErrorAge", maxAge);
266
267 _("Making some files.");
268 for (let i = 0; i < numLogs; i++) {
269 let now = Date.now();
270 let filename = LOG_PREFIX_ERROR + now + "" + i + ".txt";
271 let newLog = FileUtils.getFile("ProfD", ["weave", "logs", filename]);
272 let foStream = FileUtils.openFileOutputStream(newLog);
273 foStream.write(errString, errString.length);
274 foStream.close();
275 _(" > Created " + filename);
276 oldLogs.push(newLog.leafName);
277 }
278
279 Svc.Obs.add("weave:service:cleanup-logs", function onCleanupLogs() {
280 Svc.Obs.remove("weave:service:cleanup-logs", onCleanupLogs);
281
282 // Only the newest created log file remains.
283 let entries = logsdir.directoryEntries;
284 do_check_true(entries.hasMoreElements());
285 let logfile = entries.getNext().QueryInterface(Ci.nsILocalFile);
286 do_check_true(oldLogs.every(function (e) {
287 return e != logfile.leafName;
288 }));
289 do_check_false(entries.hasMoreElements());
290
291 // Clean up.
292 try {
293 logfile.remove(false);
294 } catch(ex) {
295 dump("Couldn't delete file: " + ex + "\n");
296 // Stupid Windows box.
297 }
298
299 Svc.Prefs.resetBranch("");
300 run_next_test();
301 });
302
303 let delay = CLEANUP_DELAY + DELAY_BUFFER;
304
305 _("Cleaning up logs after " + delay + "msec.");
306 CommonUtils.namedTimer(function onTimer() {
307 Svc.Obs.notify("weave:service:sync:error");
308 }, delay, this, "cleanup-timer");
309 });

mercurial