[PATCH 4 of 8 v2] blackbox: flush output file descriptor
timeless
timeless at mozdev.org
Mon Feb 8 01:15:06 EST 2016
# HG changeset patch
# User timeless <timeless at mozdev.org>
# Date 1454512709 0
# Wed Feb 03 15:18:29 2016 +0000
# Node ID f62002c3837f6e1a746db59a2210c5bc7fa4f0a4
# Parent 39070e1fa7fed120e63cc5f28ac49b3e826dc6c1
blackbox: flush output file descriptor
Without this, when there are multiple ui views, each blackbox
will have its own file handle, and the logging will be in
a really bad order.
Also, because of the way blackbox works, it never closes its
file handles, which means the last output before exit is
often lost.
diff --git a/hgext/blackbox.py b/hgext/blackbox.py
--- a/hgext/blackbox.py
+++ b/hgext/blackbox.py
@@ -112,6 +112,7 @@
try:
blackbox.write('%s %s (%s)> %s' %
(date, user, pid, formattedmsg))
+ blackbox.flush()
except IOError as err:
self.debug('warning: cannot write to blackbox.log: %s\n' %
err.strerror)
diff --git a/tests/test-blackbox.t b/tests/test-blackbox.t
--- a/tests/test-blackbox.t
+++ b/tests/test-blackbox.t
@@ -15,6 +15,7 @@
$ hg blackbox
1970/01/01 00:00:00 bob (*)> add a (glob)
1970/01/01 00:00:00 bob (*)> add a exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox (glob)
incoming change tracking
@@ -43,12 +44,13 @@
adding file changes
added 1 changesets with 1 changes to 1 files
(run 'hg update' to get a working copy)
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> pull (glob)
1970/01/01 00:00:00 bob (*)> updated served branch cache in * seconds (glob)
1970/01/01 00:00:00 bob (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
1970/01/01 00:00:00 bob (*)> 1 incoming changes - new heads: d02f48003e62 (glob)
1970/01/01 00:00:00 bob (*)> pull exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
we must not cause a failure if we cannot write to the log
@@ -104,12 +106,13 @@
$ hg strip tip
0 files updated, 0 files merged, 1 files removed, 0 files unresolved
saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob)
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> strip tip (glob)
1970/01/01 00:00:00 bob (*)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob)
1970/01/01 00:00:00 bob (*)> updated base branch cache in * seconds (glob)
1970/01/01 00:00:00 bob (*)> wrote base branch cache with 1 labels and 2 nodes (glob)
1970/01/01 00:00:00 bob (*)> strip tip exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
extension and python hooks - use the eol extension for a pythonhook
@@ -120,12 +123,13 @@
$ hg update
hooked
1 files updated, 0 files merged, 0 files removed, 0 files unresolved
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> update (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
1970/01/01 00:00:00 bob (*)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
1970/01/01 00:00:00 bob (*)> exthook-update: echo hooked finished in * seconds (glob)
1970/01/01 00:00:00 bob (*)> update exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
log rotation
@@ -146,6 +150,7 @@
$ hg init blackboxtest3
$ cd blackboxtest3
$ hg blackbox
+ 1970/01/01 00:00:00 bob (*)> blackbox (glob)
$ mv .hg/blackbox.log .hg/blackbox.log-
$ mkdir .hg/blackbox.log
$ sed -e 's/\(.*test1.*\)/#\1/; s#\(.*commit2.*\)#os.rmdir(".hg/blackbox.log")\nos.rename(".hg/blackbox.log-", ".hg/blackbox.log")\n\1#' $TESTDIR/test-dispatch.py > ../test-dispatch.py
@@ -174,6 +179,7 @@
$ hg blackbox
1970/01/01 00:00:00 bob (*)> blackbox (glob)
1970/01/01 00:00:00 bob (*)> blackbox exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox (glob)
cleanup
$ cd ..
diff --git a/tests/test-obsolete-tag-cache.t b/tests/test-obsolete-tag-cache.t
--- a/tests/test-obsolete-tag-cache.t
+++ b/tests/test-obsolete-tag-cache.t
@@ -67,11 +67,12 @@
042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
- $ hg blackbox -l 4
+ $ hg blackbox -l 5
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> 2/2 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 2 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 5 (glob)
Hiding another changeset should cause the filtered hash to change
@@ -86,11 +87,12 @@
5 2942a772f72a444bef4bef13874d515f50fa27b6 2fce1eec33263d08a4d04293960fc73a555230e4
042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
- $ hg blackbox -l 4
+ $ hg blackbox -l 5
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> 1/1 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 5 (glob)
Resolving tags on an unfiltered repo writes a separate tags cache
@@ -106,8 +108,9 @@
55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
d75775ffbc6bca1794d300f5571272879bd280da test2
- $ hg blackbox -l 4
+ $ hg blackbox -l 5
1970/01/01 00:00:00 bob (*)> --hidden tags (glob)
1970/01/01 00:00:00 bob (*)> 2/2 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2 with 3 tags (glob)
1970/01/01 00:00:00 bob (*)> --hidden tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 5 (glob)
diff --git a/tests/test-tags.t b/tests/test-tags.t
--- a/tests/test-tags.t
+++ b/tests/test-tags.t
@@ -136,12 +136,13 @@
$ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
$ hg identify
b9154636be93 tip
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> identify (glob)
1970/01/01 00:00:00 bob (*)> writing 48 bytes to cache/hgtagsfnodes1 (glob)
1970/01/01 00:00:00 bob (*)> 0/1 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
- 1970/01/01 00:00:00 bob (*)> identify exited 0 after ?.?? seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> identify exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
Failure to acquire lock results in no write
@@ -149,12 +150,13 @@
$ echo 'foo:1' > .hg/wlock
$ hg identify
b9154636be93 tip
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> identify (glob)
1970/01/01 00:00:00 bob (*)> not writing .hg/cache/hgtagsfnodes1 because lock cannot be acquired (glob)
1970/01/01 00:00:00 bob (*)> 0/1 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> identify exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
$ fnodescacheexists
no fnodes cache
@@ -348,12 +350,13 @@
tip 5:8dbfe60eff30
bar 1:78391a272241
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> writing 24 bytes to cache/hgtagsfnodes1 (glob)
1970/01/01 00:00:00 bob (*)> 2/3 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
#if unix-permissions no-root
Errors writing to .hgtags fnodes cache are silently ignored
@@ -368,12 +371,13 @@
tip 6:b968051b5cf3
bar 1:78391a272241
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> couldn't write cache/hgtagsfnodes1: [Errno 13] Permission denied: '$TESTTMP/t2/.hg/cache/hgtagsfnodes1' (glob)
1970/01/01 00:00:00 bob (*)> 2/3 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
$ chmod a+w .hg/cache/hgtagsfnodes1
@@ -382,12 +386,13 @@
tip 6:b968051b5cf3
bar 1:78391a272241
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> writing 24 bytes to cache/hgtagsfnodes1 (glob)
1970/01/01 00:00:00 bob (*)> 2/3 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=168
@@ -410,11 +415,12 @@
tip 4:0c192d7d5e6b
bar 1:78391a272241
- $ hg blackbox -l 4
+ $ hg blackbox -l 5
1970/01/01 00:00:00 bob (*)> writing 24 bytes to cache/hgtagsfnodes1 (glob)
1970/01/01 00:00:00 bob (*)> 2/3 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 5 (glob)
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=120
@@ -426,12 +432,13 @@
tip 5:035f65efb448
bar 1:78391a272241
- $ hg blackbox -l 5
+ $ hg blackbox -l 6
1970/01/01 00:00:00 bob (*)> tags (glob)
1970/01/01 00:00:00 bob (*)> writing 24 bytes to cache/hgtagsfnodes1 (glob)
1970/01/01 00:00:00 bob (*)> 2/3 cache hits/lookups in * seconds (glob)
1970/01/01 00:00:00 bob (*)> writing .hg/cache/tags2-visible with 1 tags (glob)
1970/01/01 00:00:00 bob (*)> tags exited 0 after * seconds (glob)
+ 1970/01/01 00:00:00 bob (*)> blackbox -l 6 (glob)
$ f --size .hg/cache/hgtagsfnodes1
.hg/cache/hgtagsfnodes1: size=144
More information about the Mercurial-devel
mailing list