bzr init crash: invalid decimal Unicode string

[Buck Evan]

I simply run `bzr init foo` after installing bzr and I always get the following error:

{{{
$ bzr init foo
bzr: ERROR: exceptions.UnicodeEncodeError: 'decimal' codec can't encode character u'\U00340031' in position 0: invalid decimal Unicode string

Traceback (most recent call last):
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/commands.py", line 930, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/commands.py", line 1121, in run_bzr
    ret = run(*run_argv)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/commands.py", line 673, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/commands.py", line 697, in run
    return self._operation.run_simple(*args, **kwargs)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/cleanup.py", line 136, in run_simple
    self.cleanups, self.func, *args, **kwargs)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/cleanup.py", line 166, in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/builtins.py", line 2116, in run
    force_new_tree=force_new_tree)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/controldir.py", line 642, in create_branch_convenience
    controldir = klass.create(base, format, possible_transports)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/controldir.py", line 840, in create
    return format.initialize_on_transport(t)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/bzrdir.py", line 1321, in initialize_on_transport
    return self._initialize_on_transport_vfs(transport)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/bzrdir.py", line 1463, in _initialize_on_transport_vfs
    control_files.lock_write()
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/lockable_files.py", line 164, in lock_write
    token_from_lock = self._lock.lock_write(token=token)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/lockdir.py", line 674, in lock_write
    return self.wait_lock()
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/lockdir.py", line 621, in wait_lock
    new_info)
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/lockdir.py", line 737, in __unicode__
    d = self.to_readable_dict()
  File "/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzrlib/lockdir.py", line 756, in to_readable_dict
    time.time() - int(self.info_dict['start_time']))
UnicodeEncodeError: 'decimal' codec can't encode character u'\U00340031' in position 0: invalid decimal Unicode string

bzr 2.6.0 on python 2.6.7 (Linux-3.13.0-39-generic-x86_64-with-
    Ubuntu-10.04-lucid)
arguments: ['/nail/home/buck/prefices/brew/Cellar/bazaar/2.6.0_2/libexec/bzr',
    'init', 'foo']
plugins: bash_completion[2.6.0], changelog_merge[2.6.0], grep[2.6.0],
    launchpad[2.6.0], netrc_credential_store[2.6.0], news_merge[2.6.0],
    po_merge[2.6.0], weave_fmt[2.6.0]
encoding: 'utf-8', fsenc: 'UTF-8', lang: 'en_US.UTF-8'

*** Bazaar has encountered an internal error. This probably indicates a
    bug in Bazaar. You can help us fix it by filing a bug report at
        https://bugs.launchpad.net/bzr/+filebug
    including this traceback and a description of the problem.
}}}

If I hack bzrlib.lockdir.to_readable_dict to avoid the int() of that unicode string, I see this:

{{{
$ strace -vvffF -o bzr.strace bzr init
Unable to obtain lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������m����� on ������������ (process #������8�罹n), acquired
(unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
Lock owner changed for lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������m�罹zr. on �����: l (process #������8�罹�), acquired (unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
Lock owner changed for lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������mbuck on ������罹er (process #������8�罹), acquired (unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
Lock owner changed for lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������m����� on ������罹er (process #������8�罹�), acquired
 (unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
Lock owner changed for lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������m�罹zr. on �����tree (process #������8�罹�), acquired (unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
Lock owner changed for lock file:///nail/home/buck/trees/mine/pip/tmp3/ held by ���������mbuck on ����� me (process #������8�罹), acquired (unknown).
Will continue to try until 13:53:54, unless you press Ctrl-C.
See "bzr help break-lock" for more.
^Cbzr: interrupted
}}}

There's a bunch of obvious trash data there. It seems the same snuck into the start_time field.

I've attached the strace in case it's helpful.

[Buck Evan (bukzor)]

Adding some debug statements, I get:

{{{
('PATH:', 'branch-lock/held/info')
('INFO FILE BYTES:', 'hostname: dev34-devc\nnonce: jau1x9ensppf7moblpne\npid: 3988219\nstart_time: 1454623896\nuser: <email address hidden>\n')
('LINES:', ['hostname: dev34-devc\n', 'nonce: jau1x9ensppf7moblpne\n', 'pid: 3988219\n', 'start_time: 1454623896\n', 'user: <email address hidden>\n'])
('STANZA:', Stanza([('hostname', u'\U00650064\U00330076\U002d0034\U00650064\U00630076\x00\U00340031\U00340035\U00320036\U00380033'), ('nonce', u'\U0061006a\U00310075\U00390078\U006e0065\U00700073\U00660070\U006d0037\U0062006f\U0070006c\U0065006e\U73640000\x00\U01b2cc30\x00\U00832140\x00\x04\x00\U23037588\u7f68'), ('pid', u'\U00390033\U00380038\U003100329\U23035270\u7f68\x00'), ('start_time', u'\U00340031\U00340035\U00320036\U00380033\U00360039\x00mine'), ('user', u'\U00750062\U006b0063\U00790040\U006c0065\U002e0070\U006f0063m\x00\U7473694c\U6b6e7520\U6e776f6e\U6c696620\U0a2e7365')]))
}}}

It goes haywire in bzrlib/_rio_pyx.pyx:_read_stanza_utf8, but I find that code inscrutable.

It's likely something to do with the fact that python on osx is built with "short unicode" (UCS2).

[Buck Evan (bukzor)]

If I change bzrlib.rio to use _rio_py rather than _rio_pyx, the bug is gone, so the issue seems to only exist in the cython code, not the pure-python implementation.

[Buck Evan (bukzor)]

If I enable pyximport and cythonize _rio_pyx myself, it also works. So my hypothesis is that a newer cython fixes this.

[Buck Evan (bukzor)]

Similarly, if I install bzr fully from source, rather than from the tarball, it works fine. This fits my hypothesis.

[Buck Evan (bukzor)]

So, apparently I was using python2.7 to compile, but python2.6 to run.
I'm supprised it didn't bomb out much earlier.

closed: invalid

[Vincent Ladeuil (vila)]

Wow, thanks for coming back for the explanation, the symptoms were totally cryptic.

Note that 2.6.0 is probably final on lucid, 2.7.0 is in the work for xenial so I don't think there will ever be a 2.6.1.

2.7.0 has been gated on a lucid chroot with python-2.6 though (so while 2.7.0 won't be released for lucid, you could run it from source, with a 'make' (to build the extensions), you'll get your own 2.7.0).

Out of curiosity, do you intend to upgrade that host to at least trusty or is it just a it-works-don't-touch-it kind of setup ?