Error during POST: 500 Internal Server Error

[killyourtv]

Using tahoe from the 1.9.2 darcs branch on I2P, I received the following copying files to the grid [edited for formatting]:

Error during POST: 500 Internal Server Error
"Traceback (most recent call last):
  File \"/usr/lib/python2.7/dist-packages/twisted/internet/base.py\", line 800, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File \"/usr/lib/pymodules/python2.7/foolscap/eventual.py\", line 26, in _turn
    cb(*args, **kwargs)
  File \"/usr/lib/python2.7/dist-packages/twisted/internet/defer.py\", line 362, in callback
    self._startRunCallbacks(result)
  File \"/usr/lib/python2.7/dist-packages/twisted/internet/defer.py\", line 458, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File \"/usr/lib/python2.7/dist-packages/twisted/internet/defer.py\", line 545, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/filenode.py\", line 859, in <lambda>
    self._modify_once(modifier, first_time))
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/filenode.py\", line 885, in _modify_once
    d = self._try_to_download_data()
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/filenode.py\", line 963, in _try_to_download_data
    d = self._read(c, fetch_privkey=True)
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/filenode.py\", line 985, in _read
    d = r.download(consumer, offset, size)
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/retrieve.py\", line 244, in download
    self._setup_download()
  File \"$HOME/i2p-tahoe/tahoe-lafs-i2p/src/allmydata/mutable/retrieve.py\", line 301, in _setup_download
    assert len(self.remaining_sharemap) >= k
exceptions.AssertionError: 
"

allmydata-tahoe: 1.9.0-r5497,
foolscap: 0.6.3,
pycryptopp: 0.6.0.1206569328141510525648634803928199668821045408958,
zfec: 1.4.24,
Twisted: 11.1.0,
Nevow: 0.10.0,
zope.interface: unknown,
python: 2.7.3rc2,
platform: Linux-debian_wheezy/sid-x86_64-64bit_ELF,
pyOpenSSL: 0.13,
simplejson: 2.5.2,
pycrypto: 2.5,
pyasn1: unknown,
mock: 0.8.0,
sqlite3: 2.6.0 [sqlite 3.7.11],
setuptools: 0.6c16dev3

[killyourtv]

possibly relevant incident

[killyourtv]

Of course, retrying the put operation completed successfully.

[killyourtv]

The top two operations failed over 12 hours ago

[killyourtv]

In the image below are four "active" operations:

The top two failed around twelve hours earlier but remain in the list.

[killyourtv]

FWIW, I have not seen this with the released v1.9.2---yet.

[zooko]

I just got a report from a customer (TV of Sv) with a matching stack trace, using 1.9.2 [edited for formatting]:

# time tahoe backup TestFiles1M tahoe:Ss1
Traceback (most recent call last):
  File "/root/allmydata-tahoe-1.9.2/support/bin/tahoe", line 9, in <module>
    load_entry_point('allmydata-tahoe==1.9.2', 'console_scripts', 'tahoe')()
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/runner.py", line 113, in run
    rc = runner(sys.argv[1:], install_node_control=install_node_control)
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/runner.py", line 99, in runner
    rc = cli.dispatch[command](so)
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/cli.py", line 569, in backup
    rc = tahoe_backup.backup(options)
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/tahoe_backup.py", line 325, in backup
    return bu.run()
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/tahoe_backup.py", line 123, in run
    put_child(archives_url, now, new_backup_dircap)
  File "/root/allmydata-tahoe-1.9.2/src/allmydata/scripts/tahoe_backup.py", line 57, in put_child
    raise HTTPError("Error during put_child", resp)
allmydata.scripts.common_http.HTTPError: Error during put_child: 500 Internal Server Error
"Traceback (most recent call last):
  File \"/root/allmydata-tahoe-1.9.2/support/lib/python2.6/site-packages/Twisted-12.0.0-py2.6-linux-i686.egg/twisted/internet/base.py\", line 800, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File \"/root/allmydata-tahoe-1.9.2/support/lib/python2.6/site-packages/foolscap-0.6.4-py2.6.egg/foolscap/eventual.py\", line 26, in _turn\
    cb(*args, **kwargs)\x0a  File \"/root/allmydata-tahoe-1.9.2/support/lib/python2.6/site-packages/Twisted-12.0.0-py2.6-linux-i686.egg/twisted/internet/defer.py\", line 368, in callback
    self._startRunCallbacks(result)
  File \"/root/allmydata-tahoe-1.9.2/support/lib/python2.6/site-packages/Twisted-12.0.0-py2.6-linux-i686.egg/twisted/internet/defer.py\", line 464, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File \"/root/allmydata-tahoe-1.9.2/support/lib/python2.6/site-packages/Twisted-12.0.0-py2.6-linux-i686.egg/twisted/internet/defer.py\", line 551, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/filenode.py\", line 859, in <lambda>
    self._modify_once(modifier, first_time))
  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/filenode.py\", line 885, in _modify_once
    d = self._try_to_download_data()\x0a  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/filenode.py\", line 963, in _try_to_download_data
    d = self._read(c, fetch_privkey=True)
  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/filenode.py\", line 985, in _read
    d = r.download(consumer, offset, size)
  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/retrieve.py\", line 244, in download
    self._setup_download()
  File \"/root/allmydata-tahoe-1.9.2/src/allmydata/mutable/retrieve.py\", line 301, in _setup_download
    assert len(self.remaining_sharemap) >= k
exceptions.AssertionError: 
"

[daira]

Similar traceback at ​https://tahoe-lafs.org/pipermail/tahoe-dev/2012-April/007273.html, where it occurred in conjunction with #1670 (but that could be a coincidence).