This is an archive of the discontinued Mercurial Phabricator instance.

Differential D650

blackbox: do not cache file objects
ClosedPublic

Authored by quark on Sep 7 2017, 1:32 AM.

Details

Reviewers
durham
yuja
Group Reviewers
hg-reviewers
Commits
rHGcf04db16f583: blackbox: do not cache file objects
Summary

Having the blackbox file objects cached in ui._bbfp could in theory be
troublesome if multiple processes (ex. chg servers) have file objects
referring to a same file. (Although I spent some time and failed to build a
convincing test case)

This patch makes blackbox re-open the file every time to make the situation
better. Ideally we also need proper locking.

The caching logic traces back to the commit introducing blackbox
(18242716a). That commit does not have details about why caching is
necessary. Consider the fact that blackbox logs are not many, it seems fine
to remove the fp cache to be more confident.

Diff Detail

Repository
rHG Mercurial
Lint
Lint Skipped
Unit
Unit Tests Skipped

Event Timeline

quark created this revision.Sep 7 2017, 1:32 AM
quark edited the summary of this revision. (Show Details)Sep 7 2017, 2:04 AM
quark retitled this revision from blackbox: do not cache file handler to blackbox: do not cache file objects.
durham accepted this revision.Sep 7 2017, 8:18 PM
durham added a subscriber: durham.
durham added inline comments.
hgext/blackbox.py
188

Might be worth mentioning this behavior change in the commit message.

yuja accepted this revision.Sep 12 2017, 10:02 AM
yuja added a subscriber: yuja.

Having the blackbox file objects cached in ui._bbfp could in theory be
troublesome if multiple processes (ex. chg servers) have file objects
referring to a same file. (Although I spent some time and failed to build a
convincing test case)

Perhaps it was okay because fseek(SEEK_END) was implied by the 'a' mode,
and we always called fwrite() followed by fflush().

But I like this change so queued, thanks.

This revision is now accepted and ready to land.Sep 12 2017, 10:02 AM
quark mentioned this in rHG4f60720cf0df: blackbox: fix rotation with chg.Sep 12 2017, 10:13 AM
Closed by commit rHGcf04db16f583: blackbox: do not cache file objects (authored by quark). · Explain Why
This revision was automatically updated to reflect the committed changes.

Revision Contents
Changeset List

PathPackages
Mhgext/blackbox.py (31 lines)

Diff 1653

hgext/blackbox.py

def wrapui(ui): def wrapui(ui):
class blackboxui(ui.__class__): class blackboxui(ui.__class__):
def __init__(self, src=None): def __init__(self, src=None):
super(blackboxui, self).__init__(src) super(blackboxui, self).__init__(src)
if src is None: if src is None:
self._partialinit() self._partialinit()
else: else:
self._bbfp = getattr(src, '_bbfp', None)
self._bbinlog = False self._bbinlog = False
self._bbrepo = getattr(src, '_bbrepo', None) self._bbrepo = getattr(src, '_bbrepo', None)
self._bbvfs = getattr(src, '_bbvfs', None) self._bbvfs = getattr(src, '_bbvfs', None)
def _partialinit(self): def _partialinit(self):
if util.safehasattr(self, '_bbvfs'): if util.safehasattr(self, '_bbvfs'):
return return
self._bbfp = None
self._bbinlog = False self._bbinlog = False
self._bbrepo = None self._bbrepo = None
self._bbvfs = None self._bbvfs = None
def copy(self): def copy(self):
self._partialinit() self._partialinit()
return self.__class__(self) return self.__class__(self)
def log(self, event, *msg, **opts): def log(self, event, *msg, **opts):
global lastui global lastui
super(blackboxui, self).log(event, *msg, **opts) super(blackboxui, self).log(event, *msg, **opts)
self._partialinit() self._partialinit()
if not '*' in self.track and not event in self.track: if not '*' in self.track and not event in self.track:
return return
if self._bbfp: if self._bbvfs:
ui = self
elif self._bbvfs:
try:
self._bbfp = self._openlogfile()
except (IOError, OSError) as err:
self.debug('warning: cannot write to blackbox.log: %s\n' %
err.strerror)
del self._bbvfs
self._bbfp = None
ui = self ui = self
else: else:
# certain ui instances exist outside the context of # certain ui instances exist outside the context of
# a repo, so just default to the last blackbox that # a repo, so just default to the last blackbox that
# was seen. # was seen.
ui = lastui ui = lastui
if not ui or not ui._bbfp: if not ui:
return return
if not lastui or ui._bbrepo: if not lastui or ui._bbrepo:
lastui = ui lastui = ui
if ui._bbinlog: if ui._bbinlog:
# recursion guard # recursion and failure guard
return return
try: try:
ui._bbinlog = True ui._bbinlog = True
default = self.configdate('devel', 'default-date') default = self.configdate('devel', 'default-date')
date = util.datestr(default, '%Y/%m/%d %H:%M:%S') date = util.datestr(default, '%Y/%m/%d %H:%M:%S')
user = util.getuser() user = util.getuser()
pid = '%d' % util.getpid() pid = '%d' % util.getpid()
formattedmsg = msg[0] % msg[1:] formattedmsg = msg[0] % msg[1:]
rev = '(unknown)' rev = '(unknown)'
changed = '' changed = ''
if ui._bbrepo: if ui._bbrepo:
ctx = ui._bbrepo[None] ctx = ui._bbrepo[None]
parents = ctx.parents() parents = ctx.parents()
rev = ('+'.join([hex(p.node()) for p in parents])) rev = ('+'.join([hex(p.node()) for p in parents]))
if (ui.configbool('blackbox', 'dirty') and if (ui.configbool('blackbox', 'dirty') and
ctx.dirty(missing=True, merge=False, branch=False)): ctx.dirty(missing=True, merge=False, branch=False)):
changed = '+' changed = '+'
if ui.configbool('blackbox', 'logsource'): if ui.configbool('blackbox', 'logsource'):
src = ' [%s]' % event src = ' [%s]' % event
else: else:
src = '' src = ''
try: try:
fp = ui._bbfp
fmt = '%s %s @%s%s (%s)%s> %s' fmt = '%s %s @%s%s (%s)%s> %s'
args = (date, user, rev, changed, pid, src, formattedmsg) args = (date, user, rev, changed, pid, src, formattedmsg)
with ui._openlogfile() as fp:
fp.write(fmt % args) fp.write(fmt % args)
fp.flush() except (IOError, OSError) as err:
except IOError as err:
self.debug('warning: cannot write to blackbox.log: %s\n' % self.debug('warning: cannot write to blackbox.log: %s\n' %
err.strerror) err.strerror)
finally: # do not restore _bbinlog intentionally to avoid failed
# logging again
durhamUnsubmitted
Not Done

Might be worth mentioning this behavior change in the commit message.

durham: Might be worth mentioning this behavior change in the commit message.
else:
ui._bbinlog = False ui._bbinlog = False
finally:
pass
def setrepo(self, repo): def setrepo(self, repo):
self._bbfp = None
self._bbinlog = False self._bbinlog = False
self._bbrepo = repo self._bbrepo = repo
self._bbvfs = repo.vfs self._bbvfs = repo.vfs
ui.__class__ = blackboxui ui.__class__ = blackboxui
uimod.ui = blackboxui uimod.ui = blackboxui
def uisetup(ui): def uisetup(ui):