Show More
@@ -1,141 +1,144 b'' | |||
|
1 | 1 | # loggingutil.py - utility for logging events |
|
2 | 2 | # |
|
3 | 3 | # Copyright 2010 Nicolas Dumazet |
|
4 | 4 | # Copyright 2013 Facebook, Inc. |
|
5 | 5 | # |
|
6 | 6 | # This software may be used and distributed according to the terms of the |
|
7 | 7 | # GNU General Public License version 2 or any later version. |
|
8 | 8 | |
|
9 | 9 | from __future__ import absolute_import |
|
10 | 10 | |
|
11 | 11 | import errno |
|
12 | 12 | |
|
13 |
from . import |
|
|
13 | from . import ( | |
|
14 | encoding, | |
|
15 | pycompat, | |
|
16 | ) | |
|
14 | 17 | |
|
15 | 18 | from .utils import ( |
|
16 | 19 | dateutil, |
|
17 | 20 | procutil, |
|
18 | 21 | stringutil, |
|
19 | 22 | ) |
|
20 | 23 | |
|
21 | 24 | |
|
22 | 25 | def openlogfile(ui, vfs, name, maxfiles=0, maxsize=0): |
|
23 | 26 | """Open log file in append mode, with optional rotation |
|
24 | 27 | |
|
25 | 28 | If maxsize > 0, the log file will be rotated up to maxfiles. |
|
26 | 29 | """ |
|
27 | 30 | |
|
28 | 31 | def rotate(oldpath, newpath): |
|
29 | 32 | try: |
|
30 | 33 | vfs.unlink(newpath) |
|
31 | 34 | except OSError as err: |
|
32 | 35 | if err.errno != errno.ENOENT: |
|
33 | 36 | ui.debug( |
|
34 | 37 | b"warning: cannot remove '%s': %s\n" |
|
35 | % (newpath, err.strerror) | |
|
38 | % (newpath, encoding.strtolocal(err.strerror)) | |
|
36 | 39 | ) |
|
37 | 40 | try: |
|
38 | 41 | if newpath: |
|
39 | 42 | vfs.rename(oldpath, newpath) |
|
40 | 43 | except OSError as err: |
|
41 | 44 | if err.errno != errno.ENOENT: |
|
42 | 45 | ui.debug( |
|
43 | 46 | b"warning: cannot rename '%s' to '%s': %s\n" |
|
44 | % (newpath, oldpath, err.strerror) | |
|
47 | % (newpath, oldpath, encoding.strtolocal(err.strerror)) | |
|
45 | 48 | ) |
|
46 | 49 | |
|
47 | 50 | if maxsize > 0: |
|
48 | 51 | try: |
|
49 | 52 | st = vfs.stat(name) |
|
50 | 53 | except OSError: |
|
51 | 54 | pass |
|
52 | 55 | else: |
|
53 | 56 | if st.st_size >= maxsize: |
|
54 | 57 | path = vfs.join(name) |
|
55 | 58 | for i in pycompat.xrange(maxfiles - 1, 1, -1): |
|
56 | 59 | rotate( |
|
57 | 60 | oldpath=b'%s.%d' % (path, i - 1), |
|
58 | 61 | newpath=b'%s.%d' % (path, i), |
|
59 | 62 | ) |
|
60 | 63 | rotate(oldpath=path, newpath=maxfiles > 0 and path + b'.1') |
|
61 | 64 | return vfs(name, b'a', makeparentdirs=False) |
|
62 | 65 | |
|
63 | 66 | |
|
64 | 67 | def _formatlogline(msg): |
|
65 | 68 | date = dateutil.datestr(format=b'%Y/%m/%d %H:%M:%S') |
|
66 | 69 | pid = procutil.getpid() |
|
67 | 70 | return b'%s (%d)> %s' % (date, pid, msg) |
|
68 | 71 | |
|
69 | 72 | |
|
70 | 73 | def _matchevent(event, tracked): |
|
71 | 74 | return b'*' in tracked or event in tracked |
|
72 | 75 | |
|
73 | 76 | |
|
74 | 77 | class filelogger(object): |
|
75 | 78 | """Basic logger backed by physical file with optional rotation""" |
|
76 | 79 | |
|
77 | 80 | def __init__(self, vfs, name, tracked, maxfiles=0, maxsize=0): |
|
78 | 81 | self._vfs = vfs |
|
79 | 82 | self._name = name |
|
80 | 83 | self._trackedevents = set(tracked) |
|
81 | 84 | self._maxfiles = maxfiles |
|
82 | 85 | self._maxsize = maxsize |
|
83 | 86 | |
|
84 | 87 | def tracked(self, event): |
|
85 | 88 | return _matchevent(event, self._trackedevents) |
|
86 | 89 | |
|
87 | 90 | def log(self, ui, event, msg, opts): |
|
88 | 91 | line = _formatlogline(msg) |
|
89 | 92 | try: |
|
90 | 93 | with openlogfile( |
|
91 | 94 | ui, |
|
92 | 95 | self._vfs, |
|
93 | 96 | self._name, |
|
94 | 97 | maxfiles=self._maxfiles, |
|
95 | 98 | maxsize=self._maxsize, |
|
96 | 99 | ) as fp: |
|
97 | 100 | fp.write(line) |
|
98 | 101 | except IOError as err: |
|
99 | 102 | ui.debug( |
|
100 | 103 | b'cannot write to %s: %s\n' |
|
101 | 104 | % (self._name, stringutil.forcebytestr(err)) |
|
102 | 105 | ) |
|
103 | 106 | |
|
104 | 107 | |
|
105 | 108 | class fileobjectlogger(object): |
|
106 | 109 | """Basic logger backed by file-like object""" |
|
107 | 110 | |
|
108 | 111 | def __init__(self, fp, tracked): |
|
109 | 112 | self._fp = fp |
|
110 | 113 | self._trackedevents = set(tracked) |
|
111 | 114 | |
|
112 | 115 | def tracked(self, event): |
|
113 | 116 | return _matchevent(event, self._trackedevents) |
|
114 | 117 | |
|
115 | 118 | def log(self, ui, event, msg, opts): |
|
116 | 119 | line = _formatlogline(msg) |
|
117 | 120 | try: |
|
118 | 121 | self._fp.write(line) |
|
119 | 122 | self._fp.flush() |
|
120 | 123 | except IOError as err: |
|
121 | 124 | ui.debug( |
|
122 | 125 | b'cannot write to %s: %s\n' |
|
123 | 126 | % ( |
|
124 | 127 | stringutil.forcebytestr(self._fp.name), |
|
125 | 128 | stringutil.forcebytestr(err), |
|
126 | 129 | ) |
|
127 | 130 | ) |
|
128 | 131 | |
|
129 | 132 | |
|
130 | 133 | class proxylogger(object): |
|
131 | 134 | """Forward log events to another logger to be set later""" |
|
132 | 135 | |
|
133 | 136 | def __init__(self): |
|
134 | 137 | self.logger = None |
|
135 | 138 | |
|
136 | 139 | def tracked(self, event): |
|
137 | 140 | return self.logger is not None and self.logger.tracked(event) |
|
138 | 141 | |
|
139 | 142 | def log(self, ui, event, msg, opts): |
|
140 | 143 | assert self.logger is not None |
|
141 | 144 | self.logger.log(ui, event, msg, opts) |
@@ -1,488 +1,499 b'' | |||
|
1 | 1 | setup |
|
2 | 2 | |
|
3 | 3 | $ cat > myextension.py <<EOF |
|
4 | 4 | > from mercurial import error, registrar |
|
5 | 5 | > cmdtable = {} |
|
6 | 6 | > command = registrar.command(cmdtable) |
|
7 | 7 | > @command(b'crash', [], b'hg crash') |
|
8 | 8 | > def crash(ui, *args, **kwargs): |
|
9 | 9 | > raise Exception("oops") |
|
10 | 10 | > @command(b'abortcmd', [], b'hg abortcmd') |
|
11 | 11 | > def abort(ui, *args, **kwargs): |
|
12 | 12 | > raise error.Abort(b"oops") |
|
13 | 13 | > EOF |
|
14 | 14 | $ abspath=`pwd`/myextension.py |
|
15 | 15 | |
|
16 | 16 | $ cat >> $HGRCPATH <<EOF |
|
17 | 17 | > [extensions] |
|
18 | 18 | > blackbox= |
|
19 | 19 | > mock=$TESTDIR/mockblackbox.py |
|
20 | 20 | > mq= |
|
21 | 21 | > myextension=$TESTTMP/myextension.py |
|
22 | 22 | > [alias] |
|
23 | 23 | > confuse = log --limit 3 |
|
24 | 24 | > so-confusing = confuse --style compact |
|
25 | 25 | > EOF |
|
26 | 26 | |
|
27 | 27 | $ hg init blackboxtest |
|
28 | 28 | $ cd blackboxtest |
|
29 | 29 | |
|
30 | 30 | command, exit codes, and duration |
|
31 | 31 | |
|
32 | 32 | $ echo a > a |
|
33 | 33 | $ hg add a |
|
34 | 34 | $ hg blackbox --config blackbox.dirty=True |
|
35 | 35 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest exited 0 after * seconds (glob) |
|
36 | 36 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a |
|
37 | 37 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob) |
|
38 | 38 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> blackbox --config *blackbox.dirty=True* (glob) |
|
39 | 39 | |
|
40 | 40 | failure exit code |
|
41 | 41 | $ rm ./.hg/blackbox.log |
|
42 | 42 | $ hg add non-existent |
|
43 | 43 | non-existent: $ENOENT$ |
|
44 | 44 | [1] |
|
45 | 45 | $ hg blackbox |
|
46 | 46 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add non-existent |
|
47 | 47 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add non-existent exited 1 after * seconds (glob) |
|
48 | 48 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox |
|
49 | 49 | |
|
50 | 50 | abort exit code |
|
51 | 51 | $ rm ./.hg/blackbox.log |
|
52 | 52 | $ hg abortcmd 2> /dev/null |
|
53 | 53 | [255] |
|
54 | 54 | $ hg blackbox -l 2 |
|
55 | 55 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> abortcmd exited 255 after * seconds (glob) |
|
56 | 56 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2 |
|
57 | 57 | |
|
58 | 58 | unhandled exception |
|
59 | 59 | $ rm ./.hg/blackbox.log |
|
60 | 60 | #if chg |
|
61 | 61 | (chg exits 255 because it fails to receive an exit code) |
|
62 | 62 | $ hg crash 2>/dev/null |
|
63 | 63 | [255] |
|
64 | 64 | #else |
|
65 | 65 | (hg exits 1 because Python default exit code for uncaught exception is 1) |
|
66 | 66 | $ hg crash 2>/dev/null |
|
67 | 67 | [1] |
|
68 | 68 | #endif |
|
69 | 69 | $ hg blackbox -l 2 |
|
70 | 70 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> crash exited 1 after * seconds (glob) |
|
71 | 71 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2 |
|
72 | 72 | |
|
73 | 73 | alias expansion is logged |
|
74 | 74 | $ rm ./.hg/blackbox.log |
|
75 | 75 | $ hg confuse |
|
76 | 76 | $ hg blackbox |
|
77 | 77 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> confuse |
|
78 | 78 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3' |
|
79 | 79 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> confuse exited 0 after * seconds (glob) |
|
80 | 80 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox |
|
81 | 81 | |
|
82 | 82 | recursive aliases work correctly |
|
83 | 83 | $ rm ./.hg/blackbox.log |
|
84 | 84 | $ hg so-confusing |
|
85 | 85 | $ hg blackbox |
|
86 | 86 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> so-confusing |
|
87 | 87 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> alias 'so-confusing' expands to 'confuse --style compact' |
|
88 | 88 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3' |
|
89 | 89 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> so-confusing exited 0 after * seconds (glob) |
|
90 | 90 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox |
|
91 | 91 | |
|
92 | 92 | custom date format |
|
93 | 93 | $ rm ./.hg/blackbox.log |
|
94 | 94 | $ hg --config blackbox.date-format='%Y-%m-%d @ %H:%M:%S' \ |
|
95 | 95 | > --config devel.default-date='1334347993 0' --traceback status |
|
96 | 96 | A a |
|
97 | 97 | $ hg blackbox |
|
98 | 98 | 2012-04-13 @ 20:13:13 bob @0000000000000000000000000000000000000000 (5000)> --config *blackbox.date-format=%Y-%m-%d @ %H:%M:%S* --config *devel.default-date=1334347993 0* --traceback status (glob) |
|
99 | 99 | 2012-04-13 @ 20:13:13 bob @0000000000000000000000000000000000000000 (5000)> --config *blackbox.date-format=%Y-%m-%d @ %H:%M:%S* --config *devel.default-date=1334347993 0* --traceback status exited 0 after * seconds (glob) |
|
100 | 100 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox |
|
101 | 101 | |
|
102 | 102 | incoming change tracking |
|
103 | 103 | |
|
104 | 104 | create two heads to verify that we only see one change in the log later |
|
105 | 105 | $ hg commit -ma |
|
106 | 106 | $ hg up null |
|
107 | 107 | 0 files updated, 0 files merged, 1 files removed, 0 files unresolved |
|
108 | 108 | $ echo b > b |
|
109 | 109 | $ hg commit -Amb |
|
110 | 110 | adding b |
|
111 | 111 | created new head |
|
112 | 112 | |
|
113 | 113 | clone, commit, pull |
|
114 | 114 | $ hg clone . ../blackboxtest2 |
|
115 | 115 | updating to branch default |
|
116 | 116 | 1 files updated, 0 files merged, 0 files removed, 0 files unresolved |
|
117 | 117 | $ echo c > c |
|
118 | 118 | $ hg commit -Amc |
|
119 | 119 | adding c |
|
120 | 120 | $ cd ../blackboxtest2 |
|
121 | 121 | $ hg pull |
|
122 | 122 | pulling from $TESTTMP/blackboxtest |
|
123 | 123 | searching for changes |
|
124 | 124 | adding changesets |
|
125 | 125 | adding manifests |
|
126 | 126 | adding file changes |
|
127 | 127 | added 1 changesets with 1 changes to 1 files |
|
128 | 128 | new changesets d02f48003e62 |
|
129 | 129 | (run 'hg update' to get a working copy) |
|
130 | 130 | $ hg blackbox -l 6 |
|
131 | 131 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served) with 1 labels and 2 nodes |
|
132 | 132 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (served.hidden) in * seconds (glob) |
|
133 | 133 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served.hidden) with 1 labels and 2 nodes |
|
134 | 134 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> 1 incoming changes - new heads: d02f48003e62 |
|
135 | 135 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pull exited 0 after * seconds (glob) |
|
136 | 136 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6 |
|
137 | 137 | |
|
138 | 138 | we must not cause a failure if we cannot write to the log |
|
139 | 139 | |
|
140 | 140 | $ hg rollback |
|
141 | 141 | repository tip rolled back to revision 1 (undo pull) |
|
142 | 142 | |
|
143 | 143 | $ mv .hg/blackbox.log .hg/blackbox.log- |
|
144 | 144 | $ mkdir .hg/blackbox.log |
|
145 | 145 | $ hg --debug incoming |
|
146 | 146 | warning: cannot write to blackbox.log: * (glob) |
|
147 | 147 | comparing with $TESTTMP/blackboxtest |
|
148 | 148 | query 1; heads |
|
149 | 149 | searching for changes |
|
150 | 150 | all local changesets known remotely |
|
151 | 151 | changeset: 2:d02f48003e62c24e2659d97d30f2a83abe5d5d51 |
|
152 | 152 | tag: tip |
|
153 | 153 | phase: draft |
|
154 | 154 | parent: 1:6563da9dcf87b1949716e38ff3e3dfaa3198eb06 |
|
155 | 155 | parent: -1:0000000000000000000000000000000000000000 |
|
156 | 156 | manifest: 2:ab9d46b053ebf45b7996f2922b9893ff4b63d892 |
|
157 | 157 | user: test |
|
158 | 158 | date: Thu Jan 01 00:00:00 1970 +0000 |
|
159 | 159 | files+: c |
|
160 | 160 | extra: branch=default |
|
161 | 161 | description: |
|
162 | 162 | c |
|
163 | 163 | |
|
164 | 164 | |
|
165 | 165 | $ hg pull |
|
166 | 166 | pulling from $TESTTMP/blackboxtest |
|
167 | 167 | searching for changes |
|
168 | 168 | adding changesets |
|
169 | 169 | adding manifests |
|
170 | 170 | adding file changes |
|
171 | 171 | added 1 changesets with 1 changes to 1 files |
|
172 | 172 | new changesets d02f48003e62 |
|
173 | 173 | (run 'hg update' to get a working copy) |
|
174 | 174 | |
|
175 | 175 | a failure reading from the log is fatal |
|
176 | 176 | |
|
177 | 177 | $ hg blackbox -l 3 |
|
178 | 178 | abort: *$TESTTMP/blackboxtest2/.hg/blackbox.log* (glob) |
|
179 | 179 | [255] |
|
180 | 180 | |
|
181 | 181 | $ rmdir .hg/blackbox.log |
|
182 | 182 | $ mv .hg/blackbox.log- .hg/blackbox.log |
|
183 | 183 | |
|
184 | 184 | backup bundles get logged |
|
185 | 185 | |
|
186 | 186 | $ touch d |
|
187 | 187 | $ hg commit -Amd |
|
188 | 188 | adding d |
|
189 | 189 | created new head |
|
190 | 190 | $ hg strip tip |
|
191 | 191 | 0 files updated, 0 files merged, 1 files removed, 0 files unresolved |
|
192 | 192 | saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob) |
|
193 | 193 | $ hg blackbox -l 6 |
|
194 | 194 | 1970/01/01 00:00:00 bob @73f6ee326b27d820b0472f1a825e3a50f3dc489b (5000)> strip tip |
|
195 | 195 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/73f6ee326b27-7612e004-backup.hg |
|
196 | 196 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (immutable) in * seconds (glob) |
|
197 | 197 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (immutable) with 1 labels and 2 nodes |
|
198 | 198 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> strip tip exited 0 after * seconds (glob) |
|
199 | 199 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6 |
|
200 | 200 | |
|
201 | 201 | extension and python hooks - use the eol extension for a pythonhook |
|
202 | 202 | |
|
203 | 203 | $ echo '[extensions]' >> .hg/hgrc |
|
204 | 204 | $ echo 'eol=' >> .hg/hgrc |
|
205 | 205 | $ echo '[hooks]' >> .hg/hgrc |
|
206 | 206 | $ echo 'update = echo hooked' >> .hg/hgrc |
|
207 | 207 | $ hg update |
|
208 | 208 | The fsmonitor extension is incompatible with the eol extension and has been disabled. (fsmonitor !) |
|
209 | 209 | hooked |
|
210 | 210 | 1 files updated, 0 files merged, 0 files removed, 0 files unresolved |
|
211 | 211 | updated to "d02f48003e62: c" |
|
212 | 212 | 1 other heads for branch "default" |
|
213 | 213 | $ cat >> .hg/hgrc <<EOF |
|
214 | 214 | > [extensions] |
|
215 | 215 | > # disable eol, because it is not needed for subsequent tests |
|
216 | 216 | > # (in addition, keeping it requires extra care for fsmonitor) |
|
217 | 217 | > eol=! |
|
218 | 218 | > EOF |
|
219 | 219 | $ hg blackbox -l 5 |
|
220 | 220 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> update (no-chg !) |
|
221 | 221 | 1970/01/01 00:00:00 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob) |
|
222 | 222 | 1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> exthook-update: echo hooked finished in * seconds (glob) |
|
223 | 223 | 1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> update exited 0 after * seconds (glob) |
|
224 | 224 | 1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> serve --cmdserver chgunix --address $TESTTMP.chgsock/server.* --daemon-postexec 'chdir:/' (glob) (chg !) |
|
225 | 225 | 1970/01/01 00:00:00 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> blackbox -l 5 |
|
226 | 226 | |
|
227 | 227 | log rotation |
|
228 | 228 | |
|
229 | 229 | $ echo '[blackbox]' >> .hg/hgrc |
|
230 | 230 | $ echo 'maxsize = 20 b' >> .hg/hgrc |
|
231 | 231 | $ echo 'maxfiles = 3' >> .hg/hgrc |
|
232 | 232 | $ hg status |
|
233 | 233 | $ hg status |
|
234 | 234 | $ hg status |
|
235 | 235 | $ hg tip -q |
|
236 | 236 | 2:d02f48003e62 |
|
237 | 237 | $ ls .hg/blackbox.log* |
|
238 | 238 | .hg/blackbox.log |
|
239 | 239 | .hg/blackbox.log.1 |
|
240 | 240 | .hg/blackbox.log.2 |
|
241 | 241 | $ cd .. |
|
242 | 242 | |
|
243 | 243 | $ hg init blackboxtest3 |
|
244 | 244 | $ cd blackboxtest3 |
|
245 | 245 | $ hg blackbox |
|
246 | 246 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest3 exited 0 after * seconds (glob) |
|
247 | 247 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox |
|
248 | 248 | $ mv .hg/blackbox.log .hg/blackbox.log- |
|
249 | 249 | $ mkdir .hg/blackbox.log |
|
250 | 250 | $ sed -e 's/\(.*test1.*\)/#\1/; s#\(.*commit2.*\)#os.rmdir(".hg/blackbox.log")\ |
|
251 | 251 | > os.rename(".hg/blackbox.log-", ".hg/blackbox.log")\ |
|
252 | 252 | > \1#' $TESTDIR/test-dispatch.py > ../test-dispatch.py |
|
253 | 253 | $ "$PYTHON" $TESTDIR/blackbox-readonly-dispatch.py |
|
254 | 254 | running: --debug add foo |
|
255 | 255 | warning: cannot write to blackbox.log: Is a directory (no-windows !) |
|
256 | 256 | warning: cannot write to blackbox.log: $TESTTMP/blackboxtest3/.hg/blackbox.log: Access is denied (windows !) |
|
257 | 257 | adding foo |
|
258 | 258 | result: 0 |
|
259 | 259 | running: --debug commit -m commit1 -d 2000-01-01 foo |
|
260 | 260 | warning: cannot write to blackbox.log: Is a directory (no-windows !) |
|
261 | 261 | warning: cannot write to blackbox.log: $TESTTMP/blackboxtest3/.hg/blackbox.log: Access is denied (windows !) |
|
262 | 262 | committing files: |
|
263 | 263 | foo |
|
264 | 264 | committing manifest |
|
265 | 265 | committing changelog |
|
266 | 266 | updating the branch cache |
|
267 | 267 | committed changeset 0:0e46349438790c460c5c9f7546bfcd39b267bbd2 |
|
268 | 268 | result: 0 |
|
269 | 269 | running: --debug commit -m commit2 -d 2000-01-02 foo |
|
270 | 270 | committing files: |
|
271 | 271 | foo |
|
272 | 272 | committing manifest |
|
273 | 273 | committing changelog |
|
274 | 274 | updating the branch cache |
|
275 | 275 | committed changeset 1:45589e459b2edfbf3dbde7e01f611d2c1e7453d7 |
|
276 | 276 | result: 0 |
|
277 | 277 | running: --debug log -r 0 |
|
278 | 278 | changeset: 0:0e46349438790c460c5c9f7546bfcd39b267bbd2 |
|
279 | 279 | phase: draft |
|
280 | 280 | parent: -1:0000000000000000000000000000000000000000 |
|
281 | 281 | parent: -1:0000000000000000000000000000000000000000 |
|
282 | 282 | manifest: 0:9091aa5df980aea60860a2e39c95182e68d1ddec |
|
283 | 283 | user: test |
|
284 | 284 | date: Sat Jan 01 00:00:00 2000 +0000 |
|
285 | 285 | files+: foo |
|
286 | 286 | extra: branch=default |
|
287 | 287 | description: |
|
288 | 288 | commit1 |
|
289 | 289 | |
|
290 | 290 | |
|
291 | 291 | result: 0 |
|
292 | 292 | running: --debug log -r tip |
|
293 | 293 | changeset: 1:45589e459b2edfbf3dbde7e01f611d2c1e7453d7 |
|
294 | 294 | tag: tip |
|
295 | 295 | phase: draft |
|
296 | 296 | parent: 0:0e46349438790c460c5c9f7546bfcd39b267bbd2 |
|
297 | 297 | parent: -1:0000000000000000000000000000000000000000 |
|
298 | 298 | manifest: 1:895aa9b7886f89dd017a6d62524e1f9180b04df9 |
|
299 | 299 | user: test |
|
300 | 300 | date: Sun Jan 02 00:00:00 2000 +0000 |
|
301 | 301 | files: foo |
|
302 | 302 | extra: branch=default |
|
303 | 303 | description: |
|
304 | 304 | commit2 |
|
305 | 305 | |
|
306 | 306 | |
|
307 | 307 | result: 0 |
|
308 | 308 | $ hg blackbox |
|
309 | 309 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updating the branch cache |
|
310 | 310 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updated branch cache (served) in * seconds (glob) |
|
311 | 311 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> wrote branch cache (served) with 1 labels and 1 nodes |
|
312 | 312 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug commit -m commit2 -d 2000-01-02 foo exited 0 after *.?? seconds (glob) |
|
313 | 313 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0 |
|
314 | 314 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> writing .hg/cache/tags2-visible with 0 tags |
|
315 | 315 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0 exited 0 after *.?? seconds (glob) |
|
316 | 316 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip |
|
317 | 317 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip exited 0 after *.?? seconds (glob) |
|
318 | 318 | 1970/01/01 00:00:00 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> blackbox |
|
319 | 319 | |
|
320 | Skip rotation if the .hg is read-only | |
|
321 | ||
|
322 | #if unix-permissions | |
|
323 | $ chmod -w .hg | |
|
324 | $ hg log -r. -T '{rev}\n' --config blackbox.maxsize=1 --debug | |
|
325 | warning: cannot rename '$TESTTMP/blackboxtest3/.hg/blackbox.log.1' to '$TESTTMP/blackboxtest3/.hg/blackbox.log': Permission denied | |
|
326 | warning: cannot write to blackbox.log: Permission denied | |
|
327 | 1 | |
|
328 | $ chmod +w .hg | |
|
329 | #endif | |
|
330 | ||
|
320 | 331 | Test log recursion from dirty status check |
|
321 | 332 | |
|
322 | 333 | $ cat > ../r.py <<EOF |
|
323 | 334 | > from mercurial import context, error, extensions |
|
324 | 335 | > x=[False] |
|
325 | 336 | > def status(orig, *args, **opts): |
|
326 | 337 | > args[0].repo().ui.log(b"broken", b"recursion?") |
|
327 | 338 | > return orig(*args, **opts) |
|
328 | 339 | > def reposetup(ui, repo): |
|
329 | 340 | > extensions.wrapfunction(context.basectx, 'status', status) |
|
330 | 341 | > EOF |
|
331 | 342 | $ hg id --config extensions.x=../r.py --config blackbox.dirty=True |
|
332 | 343 | 45589e459b2e tip |
|
333 | 344 | |
|
334 | 345 | cleanup |
|
335 | 346 | $ cd .. |
|
336 | 347 | |
|
337 | 348 | Test missing log directory, which shouldn't be created automatically |
|
338 | 349 | |
|
339 | 350 | $ cat <<'EOF' > closeremove.py |
|
340 | 351 | > def reposetup(ui, repo): |
|
341 | 352 | > class rmrepo(repo.__class__): |
|
342 | 353 | > def close(self): |
|
343 | 354 | > super(rmrepo, self).close() |
|
344 | 355 | > self.ui.debug(b'removing %s\n' % self.vfs.base) |
|
345 | 356 | > self.vfs.rmtree() |
|
346 | 357 | > repo.__class__ = rmrepo |
|
347 | 358 | > EOF |
|
348 | 359 | |
|
349 | 360 | $ hg init gone |
|
350 | 361 | $ cd gone |
|
351 | 362 | $ cat <<'EOF' > .hg/hgrc |
|
352 | 363 | > [extensions] |
|
353 | 364 | > closeremove = ../closeremove.py |
|
354 | 365 | > EOF |
|
355 | 366 | $ hg log --debug |
|
356 | 367 | removing $TESTTMP/gone/.hg |
|
357 | 368 | warning: cannot write to blackbox.log: $ENOENT$ (no-windows !) |
|
358 | 369 | warning: cannot write to blackbox.log: $TESTTMP/gone/.hg/blackbox.log: $ENOTDIR$ (windows !) |
|
359 | 370 | $ cd .. |
|
360 | 371 | |
|
361 | 372 | blackbox should disable itself if track is empty |
|
362 | 373 | |
|
363 | 374 | $ hg --config blackbox.track= init nothing_tracked |
|
364 | 375 | $ cd nothing_tracked |
|
365 | 376 | $ cat >> .hg/hgrc << EOF |
|
366 | 377 | > [blackbox] |
|
367 | 378 | > track = |
|
368 | 379 | > EOF |
|
369 | 380 | $ hg blackbox |
|
370 | 381 | $ cd $TESTTMP |
|
371 | 382 | |
|
372 | 383 | a '*' entry in blackbox.track is interpreted as log everything |
|
373 | 384 | |
|
374 | 385 | $ hg --config blackbox.track='*' \ |
|
375 | 386 | > --config blackbox.logsource=True \ |
|
376 | 387 | > init track_star |
|
377 | 388 | $ cd track_star |
|
378 | 389 | $ cat >> .hg/hgrc << EOF |
|
379 | 390 | > [blackbox] |
|
380 | 391 | > logsource = True |
|
381 | 392 | > track = * |
|
382 | 393 | > EOF |
|
383 | 394 | (only look for entries with specific logged sources, otherwise this test is |
|
384 | 395 | pretty brittle) |
|
385 | 396 | $ hg blackbox | egrep '\[command(finish)?\]' |
|
386 | 397 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000) [commandfinish]> --config *blackbox.track=* --config *blackbox.logsource=True* init track_star exited 0 after * seconds (glob) |
|
387 | 398 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000) [command]> blackbox |
|
388 | 399 | $ cd $TESTTMP |
|
389 | 400 | |
|
390 | 401 | #if chg |
|
391 | 402 | |
|
392 | 403 | when using chg, blackbox.log should get rotated correctly |
|
393 | 404 | |
|
394 | 405 | $ cat > $TESTTMP/noop.py << EOF |
|
395 | 406 | > from __future__ import absolute_import |
|
396 | 407 | > import time |
|
397 | 408 | > from mercurial import registrar, scmutil |
|
398 | 409 | > cmdtable = {} |
|
399 | 410 | > command = registrar.command(cmdtable) |
|
400 | 411 | > @command(b'noop') |
|
401 | 412 | > def noop(ui, repo): |
|
402 | 413 | > pass |
|
403 | 414 | > EOF |
|
404 | 415 | |
|
405 | 416 | $ hg init blackbox-chg |
|
406 | 417 | $ cd blackbox-chg |
|
407 | 418 | |
|
408 | 419 | $ cat > .hg/hgrc << EOF |
|
409 | 420 | > [blackbox] |
|
410 | 421 | > maxsize = 500B |
|
411 | 422 | > [extensions] |
|
412 | 423 | > # extension change forces chg to restart |
|
413 | 424 | > noop=$TESTTMP/noop.py |
|
414 | 425 | > EOF |
|
415 | 426 | |
|
416 | 427 | $ "$PYTHON" -c 'print("a" * 400)' > .hg/blackbox.log |
|
417 | 428 | $ chg noop |
|
418 | 429 | $ chg noop |
|
419 | 430 | $ chg noop |
|
420 | 431 | $ chg noop |
|
421 | 432 | $ chg noop |
|
422 | 433 | |
|
423 | 434 | $ cat > showsize.py << 'EOF' |
|
424 | 435 | > import os |
|
425 | 436 | > import sys |
|
426 | 437 | > limit = 500 |
|
427 | 438 | > for p in sys.argv[1:]: |
|
428 | 439 | > size = os.stat(p).st_size |
|
429 | 440 | > if size >= limit: |
|
430 | 441 | > desc = '>=' |
|
431 | 442 | > else: |
|
432 | 443 | > desc = '<' |
|
433 | 444 | > print('%s: %s %d' % (p, desc, limit)) |
|
434 | 445 | > EOF |
|
435 | 446 | |
|
436 | 447 | $ "$PYTHON" showsize.py .hg/blackbox* |
|
437 | 448 | .hg/blackbox.log: < 500 |
|
438 | 449 | .hg/blackbox.log.1: >= 500 |
|
439 | 450 | .hg/blackbox.log.2: >= 500 |
|
440 | 451 | |
|
441 | 452 | $ cd .. |
|
442 | 453 | |
|
443 | 454 | With chg, blackbox should not create the log file if the repo is gone |
|
444 | 455 | |
|
445 | 456 | $ hg init repo1 |
|
446 | 457 | $ hg --config extensions.a=! -R repo1 log |
|
447 | 458 | $ rm -rf $TESTTMP/repo1 |
|
448 | 459 | $ hg --config extensions.a=! init repo1 |
|
449 | 460 | |
|
450 | 461 | #endif |
|
451 | 462 | |
|
452 | 463 | blackbox should work if repo.ui.log is not called (issue5518) |
|
453 | 464 | |
|
454 | 465 | $ cat > $TESTTMP/raise.py << EOF |
|
455 | 466 | > from __future__ import absolute_import |
|
456 | 467 | > from mercurial import registrar, scmutil |
|
457 | 468 | > cmdtable = {} |
|
458 | 469 | > command = registrar.command(cmdtable) |
|
459 | 470 | > @command(b'raise') |
|
460 | 471 | > def raisecmd(*args): |
|
461 | 472 | > raise RuntimeError('raise') |
|
462 | 473 | > EOF |
|
463 | 474 | |
|
464 | 475 | $ cat >> $HGRCPATH << EOF |
|
465 | 476 | > [blackbox] |
|
466 | 477 | > track = commandexception |
|
467 | 478 | > [extensions] |
|
468 | 479 | > raise=$TESTTMP/raise.py |
|
469 | 480 | > EOF |
|
470 | 481 | |
|
471 | 482 | $ hg init $TESTTMP/blackbox-exception-only |
|
472 | 483 | $ cd $TESTTMP/blackbox-exception-only |
|
473 | 484 | |
|
474 | 485 | #if chg |
|
475 | 486 | (chg exits 255 because it fails to receive an exit code) |
|
476 | 487 | $ hg raise 2>/dev/null |
|
477 | 488 | [255] |
|
478 | 489 | #else |
|
479 | 490 | (hg exits 1 because Python default exit code for uncaught exception is 1) |
|
480 | 491 | $ hg raise 2>/dev/null |
|
481 | 492 | [1] |
|
482 | 493 | #endif |
|
483 | 494 | |
|
484 | 495 | $ head -1 .hg/blackbox.log |
|
485 | 496 | 1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> ** Unknown exception encountered with possibly-broken third-party extension "mock" (version N/A) |
|
486 | 497 | $ tail -2 .hg/blackbox.log |
|
487 | 498 | RuntimeError: raise |
|
488 | 499 |
General Comments 0
You need to be logged in to leave comments.
Login now