[tahoe-dev] Error during file PUT: 500 Internal Server Error

Andrej Falout andrej at falout.org
Thu Aug 6 00:36:53 PDT 2009 

With current trunk, every hour or two I get the Internal Server Error.

Can anyone please suggest what can be done to debug/fix this?

I verified that "Connection was lost" does not indicate loss of TCP/IP
connection to allmydata.com by continuously pulling data from it, which does
not get interrupted in the same time interval where this error occurs.

uploading /data/audio/Music/A Capella/Voice Samples 2/APcounseling.wav..
Traceback (most recent call last):
  File "/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/support/bin/tahoe", line
8, in <module>
    load_entry_point('allmydata-tahoe==1.5.0-r4043', 'console_scripts',
'tahoe')()
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/runner.py",
line 91, in run
    rc = runner(sys.argv[1:])
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/runner.py",
line 78, in runner
    rc = cli.dispatch[command](so)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/cli.py",
line 456, in backup
    rc = tahoe_backup.backup(options)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 370, in backup
    return bu.run()
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 212, in run
    new_backup_dircap = self.process(options.from_dir, latest_backup_dircap)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 262, in process
    newchilddircap = self.process(childpath, oldchildcap)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 265, in process
    newfilecap, metadata = self.upload(childpath)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 352, in upload
    raiseHTTPError("Error during file PUT", resp)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 18, in raiseHTTPError
    raise HTTPError(msg)
allmydata.scripts.tahoe_backup.HTTPError: Error during file PUT: 500
Internal Server Error
<html><head><title>Exception</title></head><body><style type="text/css">
p.error {
  color: black;
  font-family: Verdana, Arial, helvetica, sans-serif;
  font-weight: bold;
  font-size: large;
  margin: 0.25em;
}

div {
  font-family: Verdana, Arial, helvetica, sans-serif;
}

strong.variableClass {
  font-size: small;
}

div.stackTrace {
}

div.frame {
  padding: 0.25em;
  background: white;
  border-bottom: thin black dotted;
}

div.firstFrame {
  padding: 0.25em;
  background: white;
  border-top: thin black dotted;
  border-bottom: thin black dotted;
}

div.location {
    font-size: small;
}

div.snippet {
  background: #FFFFDD;
  padding: 0.25em;
}

div.snippetHighlightLine {
  color: red;
}

span.lineno {
    font-size: small;
}

pre.code {
  margin: 0px;
  padding: 0px;
  display: inline;
  font-size: small;
  font-family: "Courier New", courier, monotype;
}

span.function {
  font-weight: bold;
  font-family: "Courier New", courier, monotype;
}

table.variables {
  border-collapse: collapse;
  width: 100%;
}

td.varName {
  width: 1in;
  vertical-align: top;
  font-style: italic;
  font-size: small;
  padding-right: 0.25em;
}

td.varValue {
  padding-left: 0.25em;
  padding-right: 0.25em;
  font-size: small;
}

div.variables {
  margin-top: 0.5em;
}

div.dict {
  background: #cccc99;
  padding: 2px;
  float: left;
}

td.dictKey {
  background: #ffff99;
  font-weight: bold;
}

td.dictValue {
  background: #ffff99;
}

div.list {
  background: #7777cc;
  padding: 2px;
  float: left;
}

div.listItem {
  background: #9999ff;
}

div.instance {
  width: 100%;
  background: #efefef;
  padding: 2px;
  float: left;
}

span.instanceName {
  font-size: small;
  display: block;
}

span.instanceRepr {
  font-family: "Courier New", courier, monotype;
}

div.function {
  background: orange;
  font-weight: bold;
  float: left;
}
</style><a href="#tracebackEnd"><p class="error">&lt;class
'foolscap.ipb.DeadReferenceError'&gt;: Connection was lost</p></a><div
class="stackTrace"></div><a name="tracebackEnd"><p class="error">&lt;class
'foolscap.ipb.DeadReferenceError'&gt;: Connection was
lost</p></a></body></html>





After the above error occurs, it seems that the Tahoe client is left in
unusable state, and restarting the backup command gets stuck at the
following point for maybe 20 minutes, after which the command crashes again
with the followinf messages:







 /data/audio/Music/A Capella/Acapella_Anonymous_Vol_2 changed, making new
directory
Traceback (most recent call last):
  File "/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/support/bin/tahoe", line
8, in <module>
    load_entry_point('allmydata-tahoe==1.5.0-r4043', 'console_scripts',
'tahoe')()
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/runner.py",
line 91, in run
    rc = runner(sys.argv[1:])
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/runner.py",
line 78, in runner
    rc = cli.dispatch[command](so)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/cli.py",
line 456, in backup
    rc = tahoe_backup.backup(options)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 370, in backup
    return bu.run()
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 212, in run
    new_backup_dircap = self.process(options.from_dir, latest_backup_dircap)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 262, in process
    newchilddircap = self.process(childpath, oldchildcap)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 282, in process
    newdircap = mkdir(newdircontents, self.options)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 100, in mkdir
    raiseHTTPError("error during set_children", resp)
  File
"/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/scripts/tahoe_backup.py",
line 18, in raiseHTTPError
    raise HTTPError(msg)
allmydata.scripts.tahoe_backup.HTTPError: error during set_children: 500
Internal Server Error
<html><head><title>Exception</title></head><body><style type="text/css">
p.error {
  color: black;
  font-family: Verdana, Arial, helvetica, sans-serif;
  font-weight: bold;
  font-size: large;
  margin: 0.25em;
}

div {
  font-family: Verdana, Arial, helvetica, sans-serif;
}

strong.variableClass {
  font-size: small;
}

div.stackTrace {
}

div.frame {
  padding: 0.25em;
  background: white;
  border-bottom: thin black dotted;
}

div.firstFrame {
  padding: 0.25em;
  background: white;
  border-top: thin black dotted;
  border-bottom: thin black dotted;
}

div.location {
    font-size: small;
}

div.snippet {
  background: #FFFFDD;
  padding: 0.25em;
}

div.snippetHighlightLine {
  color: red;
}

span.lineno {
    font-size: small;
}

pre.code {
  margin: 0px;
  padding: 0px;
  display: inline;
  font-size: small;
  font-family: "Courier New", courier, monotype;
}

span.function {
  font-weight: bold;
  font-family: "Courier New", courier, monotype;
}

table.variables {
  border-collapse: collapse;
  width: 100%;
}

td.varName {
  width: 1in;
  vertical-align: top;
  font-style: italic;
  font-size: small;
  padding-right: 0.25em;
}

td.varValue {
  padding-left: 0.25em;
  padding-right: 0.25em;
  font-size: small;
}

div.variables {
  margin-top: 0.5em;
}

div.dict {
  background: #cccc99;
  padding: 2px;
  float: left;
}

td.dictKey {
  background: #ffff99;
  font-weight: bold;
}

td.dictValue {
  background: #ffff99;
}

div.list {
  background: #7777cc;
  padding: 2px;
  float: left;
}

div.listItem {
  background: #9999ff;
}

div.instance {
  width: 100%;
  background: #efefef;
  padding: 2px;
  float: left;
}

span.instanceName {
  font-size: small;
  display: block;
}

span.instanceRepr {
  font-family: "Courier New", courier, monotype;
}

div.function {
  background: orange;
  font-weight: bold;
  float: left;
}
</style><a href="#tracebackEnd"><p class="error">&lt;type
'exceptions.KeyError'&gt;: '\x9b\xd0\x97R\xef\xfd\xa2\no\xb2V
-\xc7KoR[\xcf='</p></a><div class="stackTrace"><div class="firstFrame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/Twisted-8.2.0-py2.6-linux-x86_64.egg/twisted/internet/defer.py,
line 328 in <span class="function">_runCallbacks</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">326</span><pre
class="code">                    self._runningCallbacks = True
</pre></div><div class="snippetLine"><span class="lineno">327</span><pre
class="code">                    try:
</pre></div><div class="snippetHighlightLine"><span
class="lineno">328</span><pre class="code">
self.result = callback(self.result, *args, **kw)
</pre></div><div class="snippetLine"><span class="lineno">329</span><pre
class="code">                    finally:
</pre></div></div><div class="variables"><strong
class="variableClass">Self</strong><table class="variables"><tr
class="varRow"><td class="varName">_runningCallbacks</td><td
class="varValue"><pre>False</pre></td></tr><tr class="varRow"><td
class="varName">result</td><td
class="varValue"><pre>None</pre></td></tr></table></div><div
class="variables"><strong class="variableClass">Locals</strong></div><table
class="variables"><tr class="varRow"><td class="varName">callback</td><td
class="varValue"><div class="function">Function &lt;lambda&gt; in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py
at line 385</div></td></tr><tr class="varRow"><td
class="varName">self</td><td class="varValue"><div class="instance"><span
class="instanceName">twisted.internet.defer.Deferred instance at
0x704d998</span><span class="instanceRepr">&lt;Deferred at 0x704d998
current result: None&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">args</td><td class="varValue"><pre>()</pre></td></tr><tr
class="varRow"><td class="varName">kw</td><td class="varValue"><div
class="dict"><span class="heading">Dictionary instance @
0x305c640</span><table
class="dict"></table></div></td></tr></table></div><div class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py,
line 387 in <span class="function">&lt;lambda&gt;</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">385</span><pre
class="code">            d2.addCallback(lambda ignored:
</pre></div><div class="snippetLine"><span class="lineno">386</span><pre
class="code">                           self._modify_and_retry(servermap,
modifier,
</pre></div><div class="snippetHighlightLine"><span
class="lineno">387</span><pre
class="code">                                                  backoffer,
False))
</pre></div><div class="snippetLine"><span class="lineno">388</span><pre
class="code">            return d2
</pre></div></div><div class="variables"><strong
class="variableClass">Locals</strong></div><table class="variables"><tr
class="varRow"><td class="varName">servermap</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServerMap instance at
0x4424200</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServerMap instance at
0x4424200&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">ignored</td><td
class="varValue"><pre>None</pre></td></tr><tr class="varRow"><td
class="varName">self</td><td class="varValue"><div class="instance"><span
class="instanceName">allmydata.mutable.filenode.MutableFileNode instance at
0x3b0f518</span><span class="instanceRepr">&lt;MutableFileNode 3b0f518 RW
rgwnmmnj&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">modifier</td><td class="varValue"><div class="method">Method
modify in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/dirnode.py at line
86</div></td></tr><tr class="varRow"><td class="varName">backoffer</td><td
class="varValue"><div class="method">Method delay in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py
at line 36</div></td></tr></table></div><div class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py,
line 381 in <span class="function">_modify_and_retry</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">379</span><pre
class="code">        return self._modify_and_retry(servermap, modifier,
backoffer, True)
</pre></div><div class="snippetLine"><span class="lineno">380</span><pre
class="code">    def _modify_and_retry(self, servermap, modifier, backoffer,
first_time):
</pre></div><div class="snippetHighlightLine"><span
class="lineno">381</span><pre class="code">        d =
self._modify_once(servermap, modifier, first_time)
</pre></div><div class="snippetLine"><span class="lineno">382</span><pre
class="code">        def _retry(f):
</pre></div></div><div class="variables"><strong
class="variableClass">Locals</strong></div><table class="variables"><tr
class="varRow"><td class="varName">servermap</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServerMap instance at
0x4424200</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServerMap instance at
0x4424200&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">first_time</td><td
class="varValue"><pre>False</pre></td></tr><tr class="varRow"><td
class="varName">self</td><td class="varValue"><div class="instance"><span
class="instanceName">allmydata.mutable.filenode.MutableFileNode instance at
0x3b0f518</span><span class="instanceRepr">&lt;MutableFileNode 3b0f518 RW
rgwnmmnj&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">modifier</td><td class="varValue"><div class="method">Method
modify in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/dirnode.py at line
86</div></td></tr><tr class="varRow"><td class="varName">backoffer</td><td
class="varValue"><div class="method">Method delay in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py
at line 36</div></td></tr></table></div><div class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py,
line 392 in <span class="function">_modify_once</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">390</span><pre
class="code">        return d
</pre></div><div class="snippetLine"><span class="lineno">391</span><pre
class="code">    def _modify_once(self, servermap, modifier, first_time):
</pre></div><div class="snippetHighlightLine"><span
class="lineno">392</span><pre class="code">        d =
self._update_servermap(servermap, MODE_WRITE)
</pre></div><div class="snippetLine"><span class="lineno">393</span><pre
class="code">        d.addCallback(self._once_updated_download_best_version,
servermap)
</pre></div></div><div class="variables"><strong
class="variableClass">Locals</strong></div><table class="variables"><tr
class="varRow"><td class="varName">servermap</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServerMap instance at
0x4424200</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServerMap instance at
0x4424200&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">self</td><td class="varValue"><div class="instance"><span
class="instanceName">allmydata.mutable.filenode.MutableFileNode instance at
0x3b0f518</span><span class="instanceRepr">&lt;MutableFileNode 3b0f518 RW
rgwnmmnj&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">modifier</td><td class="varValue"><div class="method">Method
modify in file
/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/dirnode.py at line
86</div></td></tr><tr class="varRow"><td class="varName">first_time</td><td
class="varValue"><pre>False</pre></td></tr></table><div
class="variables"><strong class="variableClass">Globals</strong></div><table
class="variables"><tr class="varRow"><td class="varName">MODE_WRITE</td><td
class="varValue">MODE_WRITE</td></tr></table></div><div class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/filenode.py,
line 421 in <span class="function">_update_servermap</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">419</span><pre
class="code">        if history:
</pre></div><div class="snippetLine"><span class="lineno">420</span><pre
class="code">            history.notify_mapupdate(u.get_status())
</pre></div><div class="snippetHighlightLine"><span
class="lineno">421</span><pre class="code">        return u.update()
</pre></div><div class="snippetLine"><span class="lineno">422</span><pre
class="code">
</pre></div></div><div class="variables"><strong
class="variableClass">Locals</strong></div><table class="variables"><tr
class="varRow"><td class="varName">u</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServermapUpdater instance
at 0x721a3f8</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServermapUpdater
instance at 0x721a3f8&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">history</td><td class="varValue"><div class="instance"><span
class="instanceName">allmydata.history.History instance at
0x19a35a8</span><span class="instanceRepr">&lt;allmydata.history.History
instance at 0x19a35a8&gt;</span></div></td></tr></table></div><div
class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/servermap.py,
line 453 in <span class="function">update</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">451</span><pre
class="code">            # seen epsilon that don't have a share.
</pre></div><div class="snippetLine"><span class="lineno">452</span><pre
class="code">            self.num_peers_to_query = N + self.EPSILON
</pre></div><div class="snippetHighlightLine"><span
class="lineno">453</span><pre class="code">
initial_peers_to_query, must_query = self._build_initial_querylist()
</pre></div><div class="snippetLine"><span class="lineno">454</span><pre
class="code">            self.required_num_empty_peers = self.EPSILON
</pre></div></div><div class="variables"><strong
class="variableClass">Self</strong><table class="variables"><tr
class="varRow"><td class="varName">num_peers_to_query</td><td
class="varValue"><pre>6</pre></td></tr><tr class="varRow"><td
class="varName">EPSILON</td><td
class="varValue"><pre>3</pre></td></tr></table></div><div
class="variables"><strong class="variableClass">Locals</strong></div><table
class="variables"><tr class="varRow"><td class="varName">self</td><td
class="varValue"><div class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServermapUpdater instance
at 0x721a3f8</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServermapUpdater
instance at 0x721a3f8&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">N</td><td
class="varValue"><pre>3</pre></td></tr></table></div><div class="frame"><div
class="location">/usr/src/tahoe/darcs/09-08-05_18-15/tahoe/src/allmydata/mutable/servermap.py,
line 485 in <span class="function">_build_initial_querylist</span></div><div
class="snippet"><div class="snippetLine"><span class="lineno">483</span><pre
class="code">        must_query = set()
</pre></div><div class="snippetLine"><span class="lineno">484</span><pre
class="code">        for peerid in self._servermap.all_peers():
</pre></div><div class="snippetHighlightLine"><span
class="lineno">485</span><pre class="code">            ss =
self._servermap.connections[peerid]
</pre></div><div class="snippetLine"><span class="lineno">486</span><pre
class="code">            # we send queries to everyone who was already in
the sharemap
</pre></div></div><div class="variables"><strong
class="variableClass">Self</strong><table class="variables"><tr
class="varRow"><td class="varName">_servermap</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServerMap instance at
0x4424200</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServerMap instance at
0x4424200&gt;</span></div></td></tr></table></div><div
class="variables"><strong class="variableClass">Locals</strong></div><table
class="variables"><tr class="varRow"><td class="varName">ss</td><td
class="varValue"><pre>&lt;RemoteReference at 0x1f5e750 [pb://
5trq7ywyfdwjhhh6t3bgmp4aasxpqrjg at 207.7.153.150:44227,
127.0.0.1:44227/34xo3wwr5mja5bbza3ivlzl3qcbeh2of]&gt;</pre></td></tr><tr
class="varRow"><td class="varName">must_query</td><td
class="varValue"><pre>set(['\r&lt;\xbf\xbc\xf7\xad!\xe4\xd5u\xe6\xf1\x08\xd7\xbf\xd2\xda\xd6\xac\xfe',
'X\xb5MD\xdf\t\x8b\xce\x9dJCf\x8b*\x9c\x1ctK\xe4R',
'5v\x13\x06O\xf6\xca,\xd8e\xa2vx\xbc+\x8b\xcf]\x0b\xcb',
'\xab\x8a\xa1\xfd\xef\x86\x99\xd51|\xec\x85X*5(\x9ab\x0e\xc4',
'\xec\xe3\x0f\xe2\xd8(\xec\x93\x9c\xfe\x9e\xc2f?\x80\x04\xae\xf8E&amp;',
'yAR\xb2\xbb\xe2\xda\x01\x1bpi9,\xbc\x17\x86\x85\xc5\xb9\xc8',
',\x9cTrn\x12\x00\x1b\x0b$\xe27Pu\xe0D\x98\xde#\xea'])</pre></td></tr><tr
class="varRow"><td class="varName">self</td><td class="varValue"><div
class="instance"><span
class="instanceName">allmydata.mutable.servermap.ServermapUpdater instance
at 0x721a3f8</span><span
class="instanceRepr">&lt;allmydata.mutable.servermap.ServermapUpdater
instance at 0x721a3f8&gt;</span></div></td></tr><tr class="varRow"><td
class="varName">peerid</td><td class="varValue">�ЗR���
o�V -�KoR[�=</td></tr></table></div></div><a name="tracebackEnd"><p
class="error">&lt;type 'exceptions.KeyError'&gt;:
'\x9b\xd0\x97R\xef\xfd\xa2\no\xb2V -\xc7KoR[\xcf='</p></a></body></html>





Thanks,
Andrej Falout
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://allmydata.org/pipermail/tahoe-dev/attachments/20090806/6ac764c1/attachment-0001.htm

More information about the tahoe-dev mailing list