[merge][rfc] log+ transport decorator

[Martin Pool]

On Fri, Oct 19, 2007 at 4:15 AM, John Arbash Meinel
<john at arbash-meinel.com> wrote:
> -----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.

I'm cleaning up BB and this has been sitting almost finished for ages.

> +        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.

I did, I think I was having some kind of perl flashback. ;-) It was a
bit crazy so I've removed it.

> 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.)

Just using __getattr__ won't do, because it's only called if the
attribute isn't present on the object or class at all, and many
interesting ones are defined on TransportDecorator.

I think using getattr to populate them on demand might be useful but
it's not compelling for me for now so I'll stick with the current code
plus your above fix.

> 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.

I think it might well have failed if the caller specified the keyword.  Fixed.

>
> +        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.

Thanks.

>
> ...
> +        # 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)

For now I just changed the comment to say 'may be wrong.'

-- 
Martin <http://launchpad.net/~mbp/>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 20080902-transport-logging.diff
Type: text/x-diff
Size: 17799 bytes
Desc: not available
Url : https://lists.ubuntu.com/archives/bazaar/attachments/20080902/1a928e66/attachment-0001.bin