[merge][rfc] log+ transport decorator

John Arbash Meinel john at arbash-meinel.com
Thu Oct 18 19:15:22 BST 2007


-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Martin Pool wrote:
> This lets you say
> 
>   bzr push log+sftp://blah
> 
> and it will write to .bzr.log a record of the calls that were made,
> the results, and how long they took.  A bit like strace (but for
> Bazaar transport io) and a bit like -Dhpss.
> 
> It's perhaps a bit strange that this is turned on through a url prefix
> and the other one through a global debug option, but not too strange,
> and it's easier this way.
> 
> This is a bit duplicative of the trace+ decorator Robert added a while
> ago for testing.  I think it's good to distinguish "capture things so
> tests can look at them" from "so  humans can look at them" and when
> they're combined it tends to make the tests fragile.  But there could
> be a little implementation in common.
> 
> This also somewhat duplicates Vincent's transportstats plugin, but it
> looks like that's meant more for machine analysis than display in real
> time.  I'd like to update the hacking file to mention all three
> options.
> 
> There aren't many tests for the actual tracing; the general transport
> tests should make sure that it doesn't break the underlying transport.
> 
> I'm not going to merge this yet but thought I'd post the patch.
> 
> 


+        for methodname in (
+            'append_bytes append_file '
+            'copy_to '
+            'delete '
+            'get '
+            'has '
+            'iter_files_recursive '
+            'open_write_stream '
+            'mkdir move '
+            'put_bytes put_bytes_non_atomic put_file put_file_non_atomic '
+            'list_dir lock_read lock_write '
+            'readv rename rmdir '
+            'stat '
+            'ulock '
+            ).strip().split():
+            setattr(self, methodname, _make_hook(methodname))

I don't really see this as any better than just doing
'append_bytes', 'append_file',
...

I suppose it meant you needed to type ', ' less.

You might also want to overload '__getattr__'. That would let you log any
functions that weren't locally defined. If you wanted, you could make it only
trigger on public functions. Something like:

def __getattr__(self, name):
  if not name.startswith('_'):
    mutter('accessing member: %s', name)

It actually should be fine, since callers will be only accessing the public
api, so you don't actually need the '_' check. (Since this is a decorator, not
something inheriting from the base class.)


You use:
+                return self._log_call(hookname, relpath, *args, **kw)

but have:
+    def _log_call(self, methodname, relpath, *args):

Which I think means if you use a kwarg in the hook (mode=XX comes to mind), the
_log_call function will break. Then again, maybe kwargs only holds the ones
that weren't defined. Which should always be the empty set.

+        try:
+            result = getattr(self._decorated, methodname)(*((relpath,) + args))
+        except Exception, e:
+            mutter("  --> %s" % e)
+            mutter("      %.03fs" % (time.time() - before))
+            raise
+        return self._show_result(before, methodname, result)

I'm pretty sure you can do:

result = getattr(self._decorated, methodname)(relpath, *args)

Which looks quite a bit nicer.

...
+        # XXX: the time is wrong when e.g. a generator object is returned from
+        # an http readv, because the object is returned before the bulk data
+        # is read.

I think for http it is actually correct, because our current HTTP.readv
implementation buffers all the data. SFTP.readv() certainly returns before it
has finished downloading everything.

For readv() specifically, you could just do:

start = time.time()
results = list(self._decorated.readv(*args))
return iter(results)

It would preserve the correctness of the api, and let you see how long the
actual downloading takes.
It is slightly inacurrate, because we will probably be doing at least some
processing while readv is going, which means there could be some slowdowns (if
the buffer fills while we are waiting, that is time not downloading, etc)

...
> diff -ur -Nx tags -x '*~' -x '.*.swp' -x .bzr ../pack-repository/bzrlib/transport/trace.py 

Is there a reason you used 'diff' rather than just using:

bzr diff -rancestor:../pack-repository

I'm just very surprised to see you using raw diff, and wondering if it means we
have some limitations for bzr diff.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.7 (Darwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org

iD8DBQFHF6K6JdeBCYSNAAMRAvBJAJ9XN0TJ8sYDh4YxanVGOqAyCZboWACgirVJ
gFXgac4BFse343JASYWpcXA=
=oikO
-----END PGP SIGNATURE-----



More information about the bazaar mailing list