google-code-export / s3ql

Automatically exported from code.google.com/p/s3ql
0 stars 0 forks source link

AttributeError in get_S3Error() #422

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
Hi Niko,

This is from another server than from the one I posted from to the forum, so 
this is on multiple machines now. Below is the log. Let me know how I can help.

Thanks
Balazs

2013-10-04 05:45:46.855 [pid=1204, thread='Thread-14', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to Backend._delete_multi...
2013-10-04 05:45:47.356 [pid=1204, thread='Thread-15', module='root', 
fn='excepthook', line=123]: Uncaught top-level exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/mount.py", line 54, in run_with_except_hook
    run_old(*args, **kw)
  File "/usr/lib/python3.3/threading.py", line 596, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/block_cache.py", line 492, in _removal_loop
    backend.delete_multi(['s3ql_data_%d' % i for i in ids])
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/backends/common.py", line 765, in delete_multi
    return self.backend.delete_multi(keys, force=force)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/backends/s3.py", line 80, in delete_multi
    self._delete_multi(tmp, force=force)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/backends/common.py", line 65, in wrapped
    return method(*a, **kw)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/backends/s3.py", line 128, in _delete_multi
    raise get_S3Error(errcode, 'Error deleting %s: %s' % (errkey, errmsg))
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.4-py3.3-linux-x86_64.egg/s3ql/backends/s3c.py", line 732, in get_S3Error
    if code.endswith('Error'):
AttributeError: 'xml.etree.ElementTree.Element' object has no attribute 
'endswith'
2013-10-04 05:46:01.853 [pid=1204, thread='Thread-8', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-04 05:47:02.985 [pid=1204, thread='Thread-4', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-04 05:47:11.408 [pid=1204, thread='Thread-3', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-04 05:48:01.298 [pid=1204, thread='Thread-6', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-04 05:49:02.854 [pid=1204, thread='Thread-3', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-04 05:49:21.165 [pid=1204, thread='MainThread', module='s3ql.mount', 
fn='unmount', line=129]: Unmounting file system...

Original issue reported on code.google.com by czv...@gmail.com on 4 Oct 2013 at 7:48

GoogleCodeExporter commented 9 years ago
Thanks for the report. I don't have much time this weekend, but I'll try to get 
a patch together that gives some more information and avoids the crash.

Original comment by Nikolaus@rath.org on 4 Oct 2013 at 4:03

GoogleCodeExporter commented 9 years ago
Ok, attached is a patch that should give more information about what's 
happening. Could you please apply and post the logs when the issue occurs again?

I have also changed the code to not unmount the file system when this problem 
occurs. This should be safe, as the issue occurs during deletion of objects, so 
in the worst case the next fsck will later delete anything that should have 
been deleted but wasn't.

Note that this patch does *not* fix the problem. It's just a temporary 
workaround to avoid crashing and give more debugging info.

Original comment by Nikolaus@rath.org on 4 Oct 2013 at 4:19

Attachments:

GoogleCodeExporter commented 9 years ago
Thank you. Can you please let me know which s3.py you are using? I have tried a 
few, and I am getting: 

cloudbackupau@cloudbackupau:~/software/temp/s3ql-2.4$ patch p1< 
patch-attriberror.diff
patching file p1
Hunk #1 FAILED at 125.
1 out of 1 hunk FAILED -- saving rejects to file p1.rej

I am such a patch noob :-(
Thanks for the awesome fast response.
B

Original comment by czv...@gmail.com on 4 Oct 2013 at 4:39

GoogleCodeExporter commented 9 years ago
This patch should apply just fine on both release 2.4 and the most recent hg 
checkout. Where did your s3.py come from? If you attach it to this issue, I can 
take a look.

Original comment by Nikolaus@rath.org on 4 Oct 2013 at 6:20

GoogleCodeExporter commented 9 years ago
Ok, sorry, I went ahead and edited s3.py by hand. It was just not worth wasting 
more of your time, so I recompiled, and running fsck now. Will report back if 
the error shows up again.
Thanks

Original comment by czv...@gmail.com on 4 Oct 2013 at 7:23

GoogleCodeExporter commented 9 years ago
Have you had a chance to collect more information about this problem? Or has 
not yet occured again?

Thanks!

Original comment by Nikolaus@rath.org on 13 Oct 2013 at 9:23

GoogleCodeExporter commented 9 years ago
Hi Niko, has not occured since. Not sure why. I am keepeing an eye on it. Thanks

Original comment by czv...@gmail.com on 14 Oct 2013 at 8:22

GoogleCodeExporter commented 9 years ago
Dear Niko,

Here is today's challenge. After this the FS dismounts...

2013-10-30 08:55:25.330 [pid=29385, thread='Thread-22', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BrokenPipeError exception ([Errno 32] Broken pipe), retrying call to 
Backend._delete_multi...
2013-10-30 08:55:28.409 [pid=29385, thread='Dummy-25', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BrokenPipeError exception ([Errno 32] Broken pipe), retrying call to 
Backend.open_read...
2013-10-30 08:55:31.189 [pid=29385, thread='Thread-18', 
module='s3ql.backends.s3', fn='_delete_multi', line=130]: Dazed and confused! 
Got errcode <Element '{http://s3.amazonaws.com/doc/2006-03-01/}Code' at 
0x7fbe001a8c58>
2013-10-30 08:55:31.191 [pid=29385, thread='Thread-18', 
module='s3ql.backends.s3', fn='_delete_multi', line=131]: Full response is:
b'<ns0:DeleteResult 
xmlns:ns0="http://s3.amazonaws.com/doc/2006-03-01/"><ns0:Deleted><ns0:Key>s3ql_d
ata_311939</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311929</ns0:Ke
y></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311930</ns0:Key></ns0:Deleted><n
s0:Deleted><ns0:Key>s3ql_data_311917</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Ke
y>s3ql_data_311932</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311898
</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311935</ns0:Key></ns0:De
leted><ns0:Deleted><ns0:Key>s3ql_data_311923</ns0:Key></ns0:Deleted><ns0:Deleted
><ns0:Key>s3ql_data_311944</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_dat
a_311899</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311910</ns0:Key>
</ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311924</ns0:Key></ns0:Deleted><ns0
:Deleted><ns0:Key>s3ql_data_311921</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>
s3ql_data_311941</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311896</
ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311950</ns0:Key></ns0:Dele
ted><ns0:Deleted><ns0:Key>s3ql_data_311946</ns0:Key></ns0:Deleted><ns0:Deleted><
ns0:Key>s3ql_data_311931</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_
311915</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311920</ns0:Key></
ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311934</ns0:Key></ns0:Deleted><ns0:D
eleted><ns0:Key>s3ql_data_311916</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3
ql_data_311945</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311905</ns
0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311942</ns0:Key></ns0:Delete
d><ns0:Deleted><ns0:Key>s3ql_data_311925</ns0:Key></ns0:Deleted><ns0:Deleted><ns
0:Key>s3ql_data_311891</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_31
1911</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311893</ns0:Key></ns
0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311927</ns0:Key></ns0:Deleted><ns0:Del
eted><ns0:Key>s3ql_data_311936</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql
_data_311907</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311902</ns0:
Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311937</ns0:Key></ns0:Deleted>
<ns0:Deleted><ns0:Key>s3ql_data_311897</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:
Key>s3ql_data_311933</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_3119
18</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311904</ns0:Key></ns0:
Deleted><ns0:Deleted><ns0:Key>s3ql_data_311906</ns0:Key></ns0:Deleted><ns0:Delet
ed><ns0:Key>s3ql_data_311908</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_d
ata_311892</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311912</ns0:Ke
y></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311949</ns0:Key></ns0:Deleted><n
s0:Deleted><ns0:Key>s3ql_data_311940</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Ke
y>s3ql_data_311919</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311903
</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311943</ns0:Key></ns0:De
leted><ns0:Deleted><ns0:Key>s3ql_data_311951</ns0:Key></ns0:Deleted><ns0:Deleted
><ns0:Key>s3ql_data_311928</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_dat
a_311938</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311947</ns0:Key>
</ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311922</ns0:Key></ns0:Deleted><ns0
:Deleted><ns0:Key>s3ql_data_311901</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>
s3ql_data_311900</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311895</
ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311890</ns0:Key></ns0:Dele
ted><ns0:Deleted><ns0:Key>s3ql_data_311913</ns0:Key></ns0:Deleted><ns0:Deleted><
ns0:Key>s3ql_data_311948</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_
311909</ns0:Key></ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311894</ns0:Key></
ns0:Deleted><ns0:Deleted><ns0:Key>s3ql_data_311926</ns0:Key></ns0:Deleted><ns0:E
rror><ns0:Key>s3ql_data_311914</ns0:Key><ns0:Code>InternalError</ns0:Code><ns0:M
essage>We encountered an internal error. Please try 
again.</ns0:Message></ns0:Error></ns0:DeleteResult>'
2013-10-30 08:55:31.192 [pid=29385, thread='Thread-18', module='root', 
fn='excepthook', line=157]: Uncaught top-level exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/mount.py", line 54, in run_with_except_hook
    run_old(*args, **kw)
  File "/usr/lib/python3.3/threading.py", line 596, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/block_cache.py", line 492, in _removal_loop
    backend.delete_multi(['s3ql_data_%d' % i for i in ids])
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/backends/common.py", line 785, in delete_multi
    return self.backend.delete_multi(keys, force=force)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/backends/s3.py", line 80, in delete_multi
    self._delete_multi(tmp, force=force)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/backends/common.py", line 65, in wrapped
    return method(*a, **kw)
  File "/usr/local/lib/python3.3/dist-packages/s3ql-2.5-py3.3-linux-x86_64.egg/s3ql/backends/s3.py", line 132, in _delete_multi
    raise RuntimeError("Internal error, please report to "
RuntimeError: Internal error, please report to 
http://code.google.com/p/s3ql/issues/detail?id=422
2013-10-30 08:55:53.301 [pid=29385, thread='Thread-8', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BadStatusLine exception (''), retrying call to ObjectW.close...
2013-10-30 08:55:53.310 [pid=29385, thread='Thread-6', 
module='s3ql.backends.common', fn='wrapped', line=77]: Encountered 
BrokenPipeError exception ([Errno 32] Broken pipe), retrying call to 
ObjectW.close...

Thanks
Balazs

Original comment by czv...@gmail.com on 30 Oct 2013 at 1:51

GoogleCodeExporter commented 9 years ago
This issue was closed by revision 39bee65a921b.

Original comment by Nikolaus@rath.org on 30 Oct 2013 at 4:18

GoogleCodeExporter commented 9 years ago
Sorry, the actual problem should have been obvious to me from the first log you 
posted. Guess I must have been a bit overworked.

Original comment by Nikolaus@rath.org on 30 Oct 2013 at 4:19

GoogleCodeExporter commented 9 years ago
No worries, I'm glad you found the bug. I am a big contributor to you being 
overworked, so I cannot complain :-D 

I have recompiled, and will rerun the syncs. If this comes up again, will let 
you know. Thanks for the fast response! :-)
B

Original comment by czv...@gmail.com on 30 Oct 2013 at 5:10

GoogleCodeExporter commented 9 years ago
Your reports are certainly much appreciated. I am curious how you manage to 
find that many bugs that quickly though. Mind if I ask how many S3QL file 
systems you run, and how much activity there is on them?

Original comment by Nikolaus@rath.org on 30 Oct 2013 at 11:38

GoogleCodeExporter commented 9 years ago
Not sure either...I think it's just the type of activity that my backups do is 
what brings these out. I have six systems backing up to about ten s3 buckets. 
Total data before s3ql does its compression and dedup is maybe a few TB of 
data, all kinds of different filetypes, (but millions of those). Daily backups, 
with incremential changes sent only (rdiff-backup). I will have more of these 
going in the future... :-) 

Original comment by czv...@gmail.com on 31 Oct 2013 at 10:11