Hello,
I'm trying to use S3QL with Google Storage, but I'm consistently running
into a problem where blocks from the cache are not making it to the
backend. I'm running on Ubuntu 14.04 and using S3QL from the PPA (version
2.11.1+dfsg-1~trusty1).
My mount command looks like this:
$ mount.s3ql --threads 4 --metadata-upload-interval 7200 --allow-other
--debug --cachedir /data/s3ql-cache --cachesize 1048567
gs://MyBucket/MyPrefix /mnt/MyBucket
Here is a sample from the mount log sometime after copying 200+ files
(0.5-3MB each) into the mount point:
2014-10-19 09:57:42.902 28314:Dummy-23 (name)s.statfs: statfs(): start
2014-10-19 09:57:44.365 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:57:44.365 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:57:49.382 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:57:49.382 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:57:52.902 28314:Dummy-20 (name)s.statfs: statfs(): start
2014-10-19 09:57:53.237 28314:Thread-6 (name)s.close:
ObjectW(s3ql_data_4).close(): start
2014-10-19 09:57:53.238 28314:Thread-6 (name)s._do_request: preparing PUT
/MyPrefixs3ql_data_4?None, qs=None
2014-10-19 09:57:53.239 28314:Thread-6 (name)s._send_request:
_send_request(): PUT /MyPrefixs3ql_data_4
2014-10-19 09:57:53.351 28314:Thread-5 (name)s.close:
ObjectW(s3ql_data_3).close(): start
2014-10-19 09:57:53.352 28314:Thread-5 (name)s._do_request: preparing PUT
/MyPrefixs3ql_data_3?None, qs=None
2014-10-19 09:57:53.353 28314:Thread-5 (name)s._send_request:
_send_request(): PUT /MyPrefixs3ql_data_3
2014-10-19 09:57:54.383 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:57:54.383 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:57:54.702 28314:Thread-3 (name)s.close:
ObjectW(s3ql_data_1).close(): start
2014-10-19 09:57:54.702 28314:Thread-3 (name)s._do_request: preparing PUT
/MyPrefixs3ql_data_1?None, qs=None
2014-10-19 09:57:54.703 28314:Thread-3 (name)s._send_request:
_send_request(): PUT /MyPrefixs3ql_data_1
2014-10-19 09:57:59.384 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:57:59.384 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:57:59.793 28314:Thread-4 (name)s.close:
ObjectW(s3ql_data_2).close(): start
2014-10-19 09:57:59.794 28314:Thread-4 (name)s._do_request: preparing PUT
/MyPrefixs3ql_data_2?None, qs=None
2014-10-19 09:57:59.795 28314:Thread-4 (name)s._send_request:
_send_request(): PUT /MyPrefixs3ql_data_2
2014-10-19 09:58:02.902 28314:Dummy-24 (name)s.statfs: statfs(): start
2014-10-19 09:58:03.506 28314:Thread-6 (name)s.wrapped: Encountered
ConnectionTimedOut exception (send/recv timeout exceeded), retrying call to
ObjectW.close for the 33-th time...
2014-10-19 09:58:03.631 28314:Thread-5 (name)s.wrapped: Encountered
ConnectionTimedOut exception (send/recv timeout exceeded), retrying call to
ObjectW.close for the 33-th time...
2014-10-19 09:58:04.385 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:58:04.385 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:58:05.282 28314:Thread-3 (name)s.wrapped: Encountered
ConnectionTimedOut exception (send/recv timeout exceeded), retrying call to
ObjectW.close for the 33-th time...
2014-10-19 09:58:09.386 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:58:09.386 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:58:10.943 28314:Thread-4 (name)s.wrapped: Encountered
ConnectionTimedOut exception (send/recv timeout exceeded), retrying call to
ObjectW.close for the 33-th time...
2014-10-19 09:58:12.902 28314:Dummy-19 (name)s.statfs: statfs(): start
2014-10-19 09:58:14.387 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:58:14.387 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:58:19.388 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:58:19.388 28314:CommitThread (name)s.put: waiting for reader..
2014-10-19 09:58:22.902 28314:Dummy-18 (name)s.statfs: statfs(): start
2014-10-19 09:58:24.389 28314:CommitThread (name)s.put: timeout, returning
2014-10-19 09:58:24.389 28314:CommitThread (name)s.put: waiting for reader..
Here is what is on the back end:
$ gsutil ls -lh gs://MyBucket/
519.97 KB 2014-10-19T13:58:30Z gs://MyBucket/MyPrefixs3ql_data_3
557.45 KB 2014-10-19T13:58:23Z gs://MyBucket/MyPrefixs3ql_data_4
161 B 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_metadata
132 B 2014-10-19T12:15:12Z gs://MyBucket/MyPrefixs3ql_passphrase
132 B 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak1
132 B 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak2
132 B 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak3
108 B 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_seq_no_1
108 B 2014-10-19T12:15:16Z gs://MyBucket/MyPrefixs3ql_seq_no_2
TOTAL: 9 objects, 1104185 bytes (1.05 MB)
(note that the timestamps for the data blocks change, but the sizes do not)
I've tried leaving the file system mounted for days and see results similar
to the above.
When I run s3qlstat it will sometimes hang and sometimes crash:
$ s3qlstat --debug /mnt/MyBucket/
2014-10-19 10:08:09.369 4344 MainThread root.excepthook: Uncaught top-level
exception:
Traceback (most recent call last):
File "/usr/bin/s3qlstat", line 9, in <module>
load_entry_point('s3ql==2.11.1', 'console_scripts', 's3qlstat')()
File "/usr/lib/s3ql/s3ql/statfs.py", line 49, in main
buf = llfuse.getxattr(ctrlfile, 's3qlstat', size_guess=256)
File "fuse_api.pxi", line 206, in llfuse.capi.getxattr
(src/llfuse/capi_linux.c:21045)
OSError: [Errno 5] Input/output error: '/mnt/MyBucket/.__s3ql__ctrl__'
If I manually kill mount.s3ql and umount the filesystem, then run
fsck.s3ql, the cache does get uploaded (with some difficulty):
$ fsck.s3ql --cachedir /data/s3ql-cache
gs://MyBucket/MyPrefix
Starting fsck of gs://MyBucket/MyPrefix
Using cached metadata.
Remote metadata is outdated.
Checking DB integrity...
Creating temporary extra indices...
Checking lost+found...
Checking cached objects...
Committing block 0 of inode 143 to backend
Committing block 0 of inode 289 to backend
Committing block 0 of inode 212 to backend
Committing block 0 of inode 338 to backend
Committing block 0 of inode 334 to backend
Committing block 0 of inode 154 to backend
Committing block 0 of inode 350 to backend
Committing block 0 of inode 354 to backend
Committing block 0 of inode 224 to backend
Committing block 0 of inode 215 to backend
Committing block 0 of inode 221 to backend
Committing block 0 of inode 339 to backend
Committing block 0 of inode 278 to backend
Committing block 0 of inode 178 to backend
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 3-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 4-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 5-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 6-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 7-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 8-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 9-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 10-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 11-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 12-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 13-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 14-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 15-th time...
Encountered ConnectionTimedOut exception (send/recv timeout exceeded),
retrying call to ObjectW.close for the 16-th time...
2014-10-19 10:45:45.960 4472:MainThread (name)s.log_error: Committing block
0 of inode 344 to backend
2014-10-19 10:45:54.484 4472:MainThread (name)s.log_error: Committing block
0 of inode 240 to backend
Looking at the backend shows the blocks that arrived:
$ gsutil ls -l gs://MyBucket/
568128 2014-10-19T14:15:12Z gs://MyBucket/MyPrefixs3ql_data_10
589184 2014-10-19T14:15:22Z gs://MyBucket/MyPrefixs3ql_data_11
560472 2014-10-19T14:15:32Z gs://MyBucket/MyPrefixs3ql_data_12
561512 2014-10-19T14:15:42Z gs://MyBucket/MyPrefixs3ql_data_13
2354084 2014-10-19T14:16:21Z gs://MyBucket/MyPrefixs3ql_data_14
2149064 2014-10-19T14:16:58Z gs://MyBucket/MyPrefixs3ql_data_15
2283988 2014-10-19T14:18:04Z gs://MyBucket/MyPrefixs3ql_data_16
581288 2014-10-19T14:18:15Z gs://MyBucket/MyPrefixs3ql_data_17
587040 2014-10-19T14:18:25Z gs://MyBucket/MyPrefixs3ql_data_18
4901596 2014-10-19T14:26:56Z gs://MyBucket/MyPrefixs3ql_data_19
532452 2014-10-19T14:08:46Z gs://MyBucket/MyPrefixs3ql_data_3
570828 2014-10-19T14:08:54Z gs://MyBucket/MyPrefixs3ql_data_4
541664 2014-10-19T14:12:14Z gs://MyBucket/MyPrefixs3ql_data_6
2131608 2014-10-19T14:12:50Z gs://MyBucket/MyPrefixs3ql_data_7
2164868 2014-10-19T14:14:42Z gs://MyBucket/MyPrefixs3ql_data_8
539144 2014-10-19T14:15:02Z gs://MyBucket/MyPrefixs3ql_data_9
161 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_metadata
132 2014-10-19T12:15:12Z gs://MyBucket/MyPrefixs3ql_passphrase
132 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak1
132 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak2
132 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_passphrase_bak3
108 2014-10-19T12:15:13Z gs://MyBucket/MyPrefixs3ql_seq_no_1
108 2014-10-19T12:15:16Z gs://MyBucket/MyPrefixs3ql_seq_no_2
108 2014-10-19T14:12:05Z gs://MyBucket/MyPrefixs3ql_seq_no_3
TOTAL: 23 objects, 16716337 bytes (15.94 MB)
I'm stumped. Has anyone got an idea of what might be causing my problem?
Thanks,
Rich B
--
You received this message because you are subscribed to the Google Groups
"s3ql" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/d/optout.
