log+ transport apparently breaks readv iterator

Bug #340347 reported by Martin Pool
2
Affects Status Importance Assigned to Milestone
Bazaar
Fix Released
High
Martin Pool

Bug Description

I've a couple of times seen code calling in to to readv break with the log+ decorator but succeed otherwise. I think the decorator is not dealing with the iterator correctly.

mbp@lithe% ./bzr push -Dtransport log+sftp://bazaar.launchpad.net/~mbp/bzr/progress
/home/mbp/.bazaar/plugins/search/index.py:22: DeprecationWarning: the md5 module is deprecated; use hashlib instead
  import md5
/usr/lib/python2.6/dist-packages/Crypto/Hash/SHA.py:6: DeprecationWarning: the sha module is deprecated; use the hashlib module instead
  from sha import *
bzr: ERROR: exceptions.AttributeError: 'list' object has no attribute 'next'

Traceback (most recent call last):
  File "/home/mbp/bzr/progress/bzrlib/commands.py", line 716, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/commands.py", line 911, in run_bzr
    ret = run(*run_argv)
  File "/home/mbp/bzr/progress/bzrlib/commands.py", line 547, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/home/mbp/bzr/progress/bzrlib/builtins.py", line 1033, in run
    use_existing_dir=use_existing_dir)
  File "/home/mbp/bzr/progress/bzrlib/push.py", line 159, in _show_push_branch
    stop_revision=revision_id)
  File "/home/mbp/bzr/progress/bzrlib/decorators.py", line 138, in read_locked
    result = unbound(self, *args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 2071, in push
    _override_hook_source_branch=_override_hook_source_branch)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 2757, in _run_with_write_locked_target
    result = callable(*args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 2110, in _push_with_bound_branches
    result = self._basic_push(target, overwrite, stop_revision)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 2133, in _basic_push
    graph=graph)
  File "/home/mbp/bzr/progress/bzrlib/decorators.py", line 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 725, in update_revisions
    overwrite, graph)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 2828, in update_revisions
    self.target.fetch(self.source, stop_revision)
  File "/home/mbp/bzr/progress/bzrlib/decorators.py", line 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/branch.py", line 495, in fetch
    pb=nested_pb)
  File "/home/mbp/bzr/progress/bzrlib/repository.py", line 1133, in fetch
    find_ghosts=find_ghosts, fetch_spec=fetch_spec)
  File "/home/mbp/bzr/progress/bzrlib/decorators.py", line 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/home/mbp/bzr/progress/bzrlib/repository.py", line 2994, in fetch
    pb, find_ghosts, fetch_spec=fetch_spec)
  File "/home/mbp/bzr/progress/bzrlib/fetch.py", line 103, in __init__
    self.__fetch()
  File "/home/mbp/bzr/progress/bzrlib/fetch.py", line 130, in __fetch
    self._fetch_everything_for_search(search, pp)
  File "/home/mbp/bzr/progress/bzrlib/fetch.py", line 156, in _fetch_everything_for_search
    stream, from_format, [])
  File "/home/mbp/bzr/progress/bzrlib/repository.py", line 3590, in insert_stream
    return self._locked_insert_stream(stream, src_format)
  File "/home/mbp/bzr/progress/bzrlib/repository.py", line 3602, in _locked_insert_stream
    self.target_repo.texts.insert_record_stream(substream)
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1602, in insert_record_stream
    bytes = adapter.get_bytes(record)
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 229, in get_bytes
    [compression_parent], 'unordered', True).next()
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1327, in get_record_stream
    ordering, include_delta_closure):
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1432, in _get_remaining_record_stream
    for record in generator.get_record_stream():
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1953, in get_record_stream
    for record in self._work():
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1977, in _work
    'unordered', True):
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1327, in get_record_stream
    ordering, include_delta_closure):
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1431, in _get_remaining_record_stream
    global_map)
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 2149, in __init__
    allow_missing=True)
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1218, in _get_record_map_unparsed
    for key, data in self._read_records_iter_unchecked(records):
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 1884, in _read_records_iter_unchecked
    data = raw_records.next()
  File "/home/mbp/bzr/progress/bzrlib/knit.py", line 3144, in get_raw_records
    for names, read_func in reader.iter_records():
  File "/home/mbp/bzr/progress/bzrlib/pack.py", line 253, in iter_records
    self._read_format()
  File "/home/mbp/bzr/progress/bzrlib/pack.py", line 294, in _read_format
    format = self._read_line()
  File "/home/mbp/bzr/progress/bzrlib/pack.py", line 221, in _read_line
    line = self._source.readline()
  File "/home/mbp/bzr/progress/bzrlib/pack.py", line 185, in readline
    self._next()
  File "/home/mbp/bzr/progress/bzrlib/pack.py", line 172, in _next
    length, data = self.readv_result.next()
AttributeError: 'list' object has no attribute 'next'

bzr 1.13dev on python 2.6.1 (linux2)
arguments: ['./bzr', 'push', '-Dtransport', 'log+sftp://bazaar.launchpad.net/~mbp/bzr/progress']
encoding: 'UTF-8', fsenc: 'UTF-8', lang: 'en_AU.UTF-8'
plugins:
  avahi /usr/lib/python2.6/dist-packages/bzrlib/plugins/avahi [0.3dev]
  builddeb /home/mbp/.bazaar/plugins/builddeb [2.1dev]
  bzrtools /home/mbp/.bazaar/plugins/bzrtools [1.11]
  dbus /usr/lib/python2.6/dist-packages/bzrlib/plugins/dbus [unknown]
  groupcompress /home/mbp/.bazaar/plugins/groupcompress [unknown]
  gtk /home/mbp/.bazaar/plugins/gtk [0.96.0.dev.1]
  launchpad /home/mbp/bzr/progress/bzrlib/plugins/launchpad [unknown]
  loggerhead /home/mbp/.bazaar/plugins/loggerhead [1.11]
  netrc_credential_store /home/mbp/bzr/progress/bzrlib/plugins/netrc_credential_store [unknown]
  pqm /home/mbp/.bazaar/plugins/pqm [1.4dev]
  revnocache /home/mbp/.bazaar/plugins/revnocache [unknown]
  search /home/mbp/.bazaar/plugins/search [1.6dev]
  usertest /home/mbp/.bazaar/plugins/usertest [unknown]
*** Bazaar has encountered an internal error.
    Please report a bug at https://bugs.launchpad.net/bzr/+filebug
    including this traceback, and a description of what you
    were doing when the error occurred.

Related branches

Martin Pool (mbp)
Changed in bzr:
importance: Undecided → High
status: New → Confirmed
Revision history for this message
Martin Pool (mbp) wrote :

One option is to change the debug code from being a decorator to a sideband, like -Dhpss is, so that if something's wrong it will default to not tracing, rather than interfering with correct operation. But that's a bit harder perhaps to fit in with all the different transport implementations.

description: updated
Revision history for this message
Robert Collins (lifeless) wrote : Re: [Bug 340347] Re: log+ transport apparently breaks readv iterator

On Wed, 2009-06-17 at 02:06 +0000, Martin Pool wrote:
> One option is to change the debug code from being a decorator to a
> sideband, like -Dhpss is, so that if something's wrong it will default
> to not tracing, rather than interfering with correct operation. But
> that's a bit harder perhaps to fit in with all the different transport
> implementations.

We also use decorators very heavily in the smart server and other places
and haven't seen errors there. I don't think decoration approach is
contributing to whatever is going on.

-Rob

Revision history for this message
Martin Pool (mbp) wrote :

I reproduced it today with trunk running
arguments: ['/usr/bin/bzr', 'branch', 'log+bzr+ssh://bazaar.launchpad.net/~bzr/bzr/trunk', '/tmp/newtrunk']

> I don't think decoration approach is contributing to whatever is going on.

I'm pretty sure the decorator is causing the breakage by eg turning an iterator into a list. That doesn't necessarily mean that the whole idea of using a decorator needs to be tossed out.

Changed in bzr:
assignee: nobody → Martin Pool (mbp)
Martin Pool (mbp)
Changed in bzr:
status: Confirmed → In Progress
Revision history for this message
Martin Pool (mbp) wrote :

Diagnosis: ReadVFile holds the readv_result and gradually returns data from within it. Its _next() method assumes it can call .next() on the readv_result to get the next chunk of it - in other words, that the readv_result holds state about how much of the result has so far been consumed.

Some confusion here about TransportLogDecorator vs TransportTraceDecorator...

TransportLogDecorator's _show_result folds generators into a list, and I think it needs to change so that it also keeps a copy as a generator so that it can return that.

That fixes it interactively, so I'll add a test.

Revision history for this message
Martin Pool (mbp) wrote :

A couple of thoughts while writing a test for this:

- Transport.readv() says it will return either a list or a generator, so probably ReadVFile is at fault in insisting that it must get a generator.

- On the other hand, TransportLogDecorator is a debugging aid so it is desirable that as much as possible it should pass data through unchanged. Therefore, if it gets a generator from the underlying transport, it should pass one back out.

Fixing either of these would close the bug but I think perhaps we should do both of them.

Revision history for this message
Martin Pool (mbp) wrote :
Changed in bzr:
status: In Progress → Fix Committed
Martin Pool (mbp)
Changed in bzr:
milestone: none → 1.17
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.