This is an archive of the discontinued Mercurial Phabricator instance.

Differential D8640

ui: add option to timestamp status and diagnostic messages
ClosedPublic

Authored by joerg.sonnenberger on Jun 18 2020, 9:13 AM.

Details

Reviewers
pulkit
Group Reviewers
hg-reviewers
Commits
rHG24b1a8eb73aa: ui: add option to timestamp status and diagnostic messages

Diff Detail

Repository
rHG Mercurial
Branch
stable
Lint
No Linters Available
Unit
No Unit Test Coverage

Event Timeline

durin42 added a subscriber: durin42.Jun 22 2020, 9:25 AM
durin42 added inline comments.
mercurial/configitems.py
1394

maybe timestamp-output?

How does this interact with a command that uses the progress bar? Maybe add a check for that in test-progress.t?

pulkit added a subscriber: pulkit.Jun 25 2020, 10:56 AM
pulkit added inline comments.
mercurial/ui.py
1737

Any reason why we are passing self.showtimestamp when it can be accessed directly in self._writemsg?

joerg.sonnenberger added inline comments.Jun 25 2020, 2:54 PM
mercurial/ui.py
1737

_writemsg is also used by other functions, e.g. prompt, getpass etc. I'm not sure we want to timestamp those, they certainly don't apply to my use-case.

pulkit added inline comments.Jun 29 2020, 4:46 AM
mercurial/ui.py
1737

Hm, in that case we can check the type in self_writemsg.

if type in set(['status', 'note', 'warning', 'error']):
    ....
pulkit accepted this revision.Jun 29 2020, 2:20 PM
This revision is now accepted and ready to land.Jun 29 2020, 2:20 PM

Revision Contents
Changeset List

PathPackages
Mmercurial/configitems.py (3 lines)
Mmercurial/ui.py (18 lines)
Mtests/test-progress.t (42 lines)
Mtests/test-pull.t (6 lines)

Diff 21685

mercurial/configitems.py

) )
coreconfigitem( coreconfigitem(
b'ui', b'timeout', default=b'600', b'ui', b'timeout', default=b'600',
) )
coreconfigitem( coreconfigitem(
b'ui', b'timeout.warn', default=0, b'ui', b'timeout.warn', default=0,
) )
coreconfigitem( coreconfigitem(
b'ui', b'timestamp-output', default=False,
durin42Unsubmitted
Not Done

maybe timestamp-output?

How does this interact with a command that uses the progress bar? Maybe add a check for that in test-progress.t?

durin42: maybe `timestamp-output`? How does this interact with a command that uses the progress bar?
)
coreconfigitem(
b'ui', b'traceback', default=False, b'ui', b'traceback', default=False,
) )
coreconfigitem( coreconfigitem(
b'ui', b'tweakdefaults', default=False, b'ui', b'tweakdefaults', default=False,
) )
coreconfigitem(b'ui', b'username', alias=[(b'ui', b'user')]) coreconfigitem(b'ui', b'username', alias=[(b'ui', b'user')])
coreconfigitem( coreconfigitem(
b'ui', b'verbose', default=False, b'ui', b'verbose', default=False,

mercurial/ui.py

# ui.py - user interface bits for mercurial # ui.py - user interface bits for mercurial
# #
# Copyright 2005-2007 Matt Mackall <mpm@selenic.com> # Copyright 2005-2007 Matt Mackall <mpm@selenic.com>
# #
# This software may be used and distributed according to the terms of the # This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version. # GNU General Public License version 2 or any later version.
from __future__ import absolute_import from __future__ import absolute_import
import collections import collections
import contextlib import contextlib
import datetime
import errno import errno
import getpass import getpass
import inspect import inspect
import os import os
import re import re
import signal import signal
import socket import socket
import subprocess import subprocess
self.insecureconnections = False self.insecureconnections = False
# Blocked time # Blocked time
self.logblockedtimes = False self.logblockedtimes = False
# color mode: see mercurial/color.py for possible value # color mode: see mercurial/color.py for possible value
self._colormode = None self._colormode = None
self._terminfoparams = {} self._terminfoparams = {}
self._styles = {} self._styles = {}
self._uninterruptible = False self._uninterruptible = False
self.showtimestamp = False
if src: if src:
self._fout = src._fout self._fout = src._fout
self._ferr = src._ferr self._ferr = src._ferr
self._fin = src._fin self._fin = src._fin
self._fmsg = src._fmsg self._fmsg = src._fmsg
self._fmsgout = src._fmsgout self._fmsgout = src._fmsgout
self._fmsgerr = src._fmsgerr self._fmsgerr = src._fmsgerr
self.debugflag = self.configbool(b'ui', b'debug') self.debugflag = self.configbool(b'ui', b'debug')
self.verbose = self.debugflag or self.configbool(b'ui', b'verbose') self.verbose = self.debugflag or self.configbool(b'ui', b'verbose')
self.quiet = not self.debugflag and self.configbool(b'ui', b'quiet') self.quiet = not self.debugflag and self.configbool(b'ui', b'quiet')
if self.verbose and self.quiet: if self.verbose and self.quiet:
self.quiet = self.verbose = False self.quiet = self.verbose = False
self._reportuntrusted = self.debugflag or self.configbool( self._reportuntrusted = self.debugflag or self.configbool(
b"ui", b"report_untrusted" b"ui", b"report_untrusted"
) )
self.showtimestamp = self.configbool(b'ui', b'timestamp-output')
self.tracebackflag = self.configbool(b'ui', b'traceback') self.tracebackflag = self.configbool(b'ui', b'traceback')
self.logblockedtimes = self.configbool(b'ui', b'logblockedtimes') self.logblockedtimes = self.configbool(b'ui', b'logblockedtimes')
if section in (None, b'trusted'): if section in (None, b'trusted'):
# update trust information # update trust information
self._trustusers.update(self.configlist(b'trusted', b'users')) self._trustusers.update(self.configlist(b'trusted', b'users'))
self._trustgroups.update(self.configlist(b'trusted', b'groups')) self._trustgroups.update(self.configlist(b'trusted', b'groups'))
return return
raise error.StdioError(err) raise error.StdioError(err)
finally: finally:
self._blockedtimes[b'stdio_blocked'] += ( self._blockedtimes[b'stdio_blocked'] += (
util.timer() - starttime util.timer() - starttime
) * 1000 ) * 1000
def _writemsg(self, dest, *args, **opts): def _writemsg(self, dest, *args, **opts):
timestamp = opts.pop('timestamp', False)
if timestamp:
args = (b'[%s] ' % bytes(datetime.datetime.now().isoformat(), 'ASCII'),) + args
_writemsgwith(self._write, dest, *args, **opts) _writemsgwith(self._write, dest, *args, **opts)
if timestamp:
dest.flush()
def _writemsgnobuf(self, dest, *args, **opts): def _writemsgnobuf(self, dest, *args, **opts):
_writemsgwith(self._writenobuf, dest, *args, **opts) _writemsgwith(self._writenobuf, dest, *args, **opts)
def flush(self): def flush(self):
# opencode timeblockedsection because this is a critical path # opencode timeblockedsection because this is a critical path
starttime = util.timer() starttime = util.timer()
try: try:
raise error.ResponseExpected() raise error.ResponseExpected()
def status(self, *msg, **opts): def status(self, *msg, **opts):
'''write status message to output (if ui.quiet is False) '''write status message to output (if ui.quiet is False)
This adds an output label of "ui.status". This adds an output label of "ui.status".
''' '''
if not self.quiet: if not self.quiet:
self._writemsg(self._fmsgout, type=b'status', *msg, **opts) self._writemsg(self._fmsgout, type=b'status', timestamp=self.showtimestamp, *msg, **opts)
pulkitUnsubmitted
Not Done

Any reason why we are passing self.showtimestamp when it can be accessed directly in self._writemsg?

pulkit: Any reason why we are passing `self.showtimestamp` when it can be accessed directly in `self.
joerg.sonnenbergerAuthorUnsubmitted
Not Done

_writemsg is also used by other functions, e.g. prompt, getpass etc. I'm not sure we want to timestamp those, they certainly don't apply to my use-case.

joerg.sonnenberger: _writemsg is also used by other functions, e.g. prompt, getpass etc. I'm not sure we want to…
pulkitUnsubmitted
Not Done

Hm, in that case we can check the type in self_writemsg.

if type in set(['status', 'note', 'warning', 'error']):
    ....
pulkit: Hm, in that case we can check the `type` in `self_writemsg`. ``` if type in set(['status'…
def warn(self, *msg, **opts): def warn(self, *msg, **opts):
'''write warning message to output (stderr) '''write warning message to output (stderr)
This adds an output label of "ui.warning". This adds an output label of "ui.warning".
''' '''
self._writemsg(self._fmsgerr, type=b'warning', *msg, **opts) self._writemsg(self._fmsgerr, type=b'warning', timestamp=self.showtimestamp, *msg, **opts)
def error(self, *msg, **opts): def error(self, *msg, **opts):
'''write error message to output (stderr) '''write error message to output (stderr)
This adds an output label of "ui.error". This adds an output label of "ui.error".
''' '''
self._writemsg(self._fmsgerr, type=b'error', *msg, **opts) self._writemsg(self._fmsgerr, type=b'error', timestamp=self.showtimestamp, *msg, **opts)
def note(self, *msg, **opts): def note(self, *msg, **opts):
'''write note to output (if ui.verbose is True) '''write note to output (if ui.verbose is True)
This adds an output label of "ui.note". This adds an output label of "ui.note".
''' '''
if self.verbose: if self.verbose:
self._writemsg(self._fmsgout, type=b'note', *msg, **opts) self._writemsg(self._fmsgout, type=b'note', timestamp=self.showtimestamp, *msg, **opts)
def debug(self, *msg, **opts): def debug(self, *msg, **opts):
'''write debug message to output (if ui.debugflag is True) '''write debug message to output (if ui.debugflag is True)
This adds an output label of "ui.debug". This adds an output label of "ui.debug".
''' '''
if self.debugflag: if self.debugflag:
self._writemsg(self._fmsgout, type=b'debug', *msg, **opts) self._writemsg(self._fmsgout, type=b'debug', timestamp=self.showtimestamp, *msg, **opts)
self.log(b'debug', b'%s', b''.join(msg)) self.log(b'debug', b'%s', b''.join(msg))
# Aliases to defeat check-code. # Aliases to defeat check-code.
statusnoi18n = status statusnoi18n = status
notenoi18n = note notenoi18n = note
warnnoi18n = warn warnnoi18n = warn
writenoi18n = write writenoi18n = write

tests/test-progress.t

> def __call__(self): > def __call__(self):
> self._time += 0.25 > self._time += 0.25
> return self._time > return self._time
> time.time = incrementingtime() > time.time = incrementingtime()
> >
> @command(b'loop', > @command(b'loop',
> [(b'', b'total', b'', b'override for total'), > [(b'', b'total', b'', b'override for total'),
> (b'', b'nested', False, b'show nested results'), > (b'', b'nested', False, b'show nested results'),
> (b'', b'parallel', False, b'show parallel sets of results')], > (b'', b'parallel', False, b'show parallel sets of results'),
> (b'', b'warn', False, b'show warning if step divisible by 3')],
> b'hg loop LOOPS', > b'hg loop LOOPS',
> norepo=True) > norepo=True)
> def loop(ui, loops, **opts): > def loop(ui, loops, **opts):
> loops = int(loops) > loops = int(loops)
> total = None > total = None
> if loops >= 0: > if loops >= 0:
> total = loops > total = loops
> if opts.get('total', None): > if opts.get('total', None):
> total = int(opts.get('total')) > total = int(opts.get('total'))
> nested = False > nested = False
> if opts.get('nested', None): > if opts.get('nested', None):
> nested = True > nested = True
> loops = abs(loops) > loops = abs(loops)
> showwarn = opts.get('warn', False)
> >
> progress = ui.makeprogress(topiclabel, unit=b'loopnum', total=total) > progress = ui.makeprogress(topiclabel, unit=b'loopnum', total=total)
> other = ui.makeprogress(b'other', unit=b'othernum', total=total) > other = ui.makeprogress(b'other', unit=b'othernum', total=total)
> for i in range(loops): > for i in range(loops):
> progress.update(i, item=getloopitem(i)) > progress.update(i, item=getloopitem(i))
> if opts.get('parallel'): > if opts.get('parallel'):
> other.update(i, item=b'other.%d' % i) > other.update(i, item=b'other.%d' % i)
> if nested: > if nested:
> nested_steps = 2 > nested_steps = 2
> if i and i % 4 == 0: > if i and i % 4 == 0:
> nested_steps = 5 > nested_steps = 5
> nested = ui.makeprogress(b'nested', unit=b'nestnum', > nested = ui.makeprogress(b'nested', unit=b'nestnum',
> total=nested_steps) > total=nested_steps)
> for j in range(nested_steps): > for j in range(nested_steps):
> nested.update(j, item=b'nested.%d' % j) > nested.update(j, item=b'nested.%d' % j)
> nested.complete() > nested.complete()
> if showwarn and i % 3 == 0:
> ui.warn(b'reached step %d\n' %i)
> progress.complete() > progress.complete()
> >
> topiclabel = b'loop' > topiclabel = b'loop'
> def getloopitem(i): > def getloopitem(i):
> return b'loop.%d' % i > return b'loop.%d' % i
> >
> EOF > EOF
loop [ ] 0/4\r (no-eol) (esc) loop [ ] 0/4\r (no-eol) (esc)
loop [===========> ] 1/4\r (no-eol) (esc) loop [===========> ] 1/4\r (no-eol) (esc)
loop [=======================> ] 2/4\r (no-eol) (esc) loop [=======================> ] 2/4\r (no-eol) (esc)
loop [===================================> ] 3/4\r (no-eol) (esc) loop [===================================> ] 3/4\r (no-eol) (esc)
loop [===============================================>] 4/4\r (no-eol) (esc) loop [===============================================>] 4/4\r (no-eol) (esc)
loop [ <=> ] 5/4\r (no-eol) (esc) loop [ <=> ] 5/4\r (no-eol) (esc)
\r (no-eol) (esc) \r (no-eol) (esc)
test interaction with ui.warn
$ hg loop --warn 6
\r (no-eol) (esc)
loop [ ] 0/6\r (no-eol) (esc)
\r (no-eol) (esc)
reached step 0
\r (no-eol) (esc)
loop [=======> ] 1/6\r (no-eol) (esc)
loop [===============> ] 2/6\r (no-eol) (esc)
loop [=======================> ] 3/6\r (no-eol) (esc)
\r (no-eol) (esc)
reached step 3
\r (no-eol) (esc)
loop [===============================> ] 4/6\r (no-eol) (esc)
loop [=======================================> ] 5/6\r (no-eol) (esc)
\r (no-eol) (esc)
test interaction with ui.timestamp-output
$ hg loop --warn --config ui.timestamp-output=true 6
\r (no-eol) (esc)
loop [ ] 0/6\r (no-eol) (esc)
\r (no-eol) (esc)
\[20[2-9][0-9]-[01][0-9]-[0-3][0-9]T[0-5][0-9]:[0-5][0-9]:[0-5][0-9]\.[0-9][0-9][0-9][0-9][0-9][0-9]\] reached step 0 (re)
\r (no-eol) (esc)
loop [=======> ] 1/6\r (no-eol) (esc)
loop [===============> ] 2/6\r (no-eol) (esc)
loop [=======================> ] 3/6\r (no-eol) (esc)
\r (no-eol) (esc)
\[20[2-9][0-9]-[01][0-9]-[0-3][0-9]T[0-5][0-9]:[0-5][0-9]:[0-5][0-9]\.[0-9][0-9][0-9][0-9][0-9][0-9]\] reached step 3 (re)
\r (no-eol) (esc)
loop [===============================> ] 4/6\r (no-eol) (esc)
loop [=======================================> ] 5/6\r (no-eol) (esc)
\r (no-eol) (esc)
test immediate progress completion test immediate progress completion
$ hg -y loop 0 $ hg -y loop 0
test delay time estimates test delay time estimates
#if no-chg #if no-chg

tests/test-pull.t

$ hg pull 'ssh://%2DoProxyCommand=touch${IFS}owned/path' $ hg pull 'ssh://%2DoProxyCommand=touch${IFS}owned/path'
pulling from ssh://-oProxyCommand%3Dtouch%24%7BIFS%7Downed/path pulling from ssh://-oProxyCommand%3Dtouch%24%7BIFS%7Downed/path
abort: potentially unsafe url: 'ssh://-oProxyCommand=touch${IFS}owned/path' abort: potentially unsafe url: 'ssh://-oProxyCommand=touch${IFS}owned/path'
[255] [255]
$ hg pull 'ssh://fakehost|touch${IFS}owned/path' $ hg pull 'ssh://fakehost|touch${IFS}owned/path'
pulling from ssh://fakehost%7Ctouch%24%7BIFS%7Downed/path pulling from ssh://fakehost%7Ctouch%24%7BIFS%7Downed/path
abort: no suitable response from remote hg! abort: no suitable response from remote hg!
[255] [255]
$ hg pull 'ssh://fakehost%7Ctouch%20owned/path' $ hg --config ui.timestamp-output=true pull 'ssh://fakehost%7Ctouch%20owned/path'
pulling from ssh://fakehost%7Ctouch%20owned/path \[20[2-9][0-9]-[01][0-9]-[0-3][0-9]T[0-5][0-9]:[0-5][0-9]:[0-5][0-9]\.[0-9][0-9][0-9][0-9][0-9][0-9]\] pulling from ssh://fakehost%7Ctouch%20owned/path (re)
abort: no suitable response from remote hg! \[20[2-9][0-9]-[01][0-9]-[0-3][0-9]T[0-5][0-9]:[0-5][0-9]:[0-5][0-9]\.[0-9][0-9][0-9][0-9][0-9][0-9]\] abort: no suitable response from remote hg! (re)
[255] [255]
$ [ ! -f owned ] || echo 'you got owned' $ [ ! -f owned ] || echo 'you got owned'
$ cd .. $ cd ..