Transport endpoint is not connected error & slow performance

[Tim Dunphy]

Hey guys,

I'm trying to use S3QL as a back end for my bacula backups. What I'd like to do is use an S3 bucket to actually hold the tapes that bacula writes to. One thing that I notice is that it's really really slow. I started a backup last night around 10pm, and this morning it hadn't even finished writing to a 5GB virutal tape. That's just ridiculously slow. If that were writing to EBS instead, it could have filled up in about 1/2 hour. It would be great to be able to backup to S3 without the expense of a huge EBS volume!!

Second thing I noticed is that when I went to list the directory I'm getting an error message:

[root@ops:~] #ls -lh /backup/tapes/
ls: /backup/tapes/: Transport endpoint is not connected

This is the second time I've seen that happen!

And these are the log entries I'm finding in syslog:

[root@ops:~] #grep s3ql /var/log/messages |grep "Feb  1"
Feb  1 01:57:00 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 04:21:32 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 04:23:10 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:08:18 ip-172-30-1-80 journal: mount.s3ql[11175] Dummy-18: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.open_read...
Feb  1 05:08:25 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-6: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.delete...
Feb  1 05:13:59 ip-172-30-1-80 journal: mount.s3ql[11175] Dummy-18: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.open_read...
Feb  1 05:17:19 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:17:29 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:19:11 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:19:13 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:20:36 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:20:37 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 07:54:59 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 07:56:51 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 07:59:14 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:01:57 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:04:09 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:06:22 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:09:02 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:10:54 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:12:53 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:15:25 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:17:04 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:19:45 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 08:22:50 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 15:00:22 ip-172-30-1-80 journal: mount.s3ql[11175] MainThread: [mount] Encountered exception, trying to clean up...
Feb  1 15:00:22 ip-172-30-1-80 journal: mount.s3ql[11175] MainThread: [mount] Unmounting file system...
Feb  1 15:04:29 ip-172-30-1-80 journal: mount.s3ql[11175] MainThread: [mount] Exception during cleanup:
Feb  1 15:04:30 ip-172-30-1-80 journal: mount.s3ql[11175] MainThread: [root] Uncaught top-level exception:

And what I find is that I'll have to run fsck.s3ql and enter 'continue' in order to get the s3 bucket mounted again on my local file system.

This is the s3ql mount command that I'm giving:

mount.s3ql --log=syslog --cachedir=/cache --allow-other s3://jf-backup /backup/tapes

I'm using S3QL 1.18.1.

I'd appreciate any help I can find on how to get s3 mounted using s3ql without running into the transport error! And if ther's some advice on how to speed things up so that backups don't take forever, I would appreciate that too! 

Thanks

[Nikolaus Rath]

On Feb 01 2016, Tim Dunphy <bluet...@gmail.com> wrote:
> Hey guys,
>
> I'm trying to use S3QL as a back end for my bacula backups. What
> I'd like to do is use an S3 bucket to actually hold the tapes
> that bacula writes to. One thing that I notice is that it's
> really really slow.

What does contrib/benchmark.py say?

> Second thing I noticed is that when I went to list the directory
> I'm getting an error message:
>
> [root@ops:~] #ls -lh /backup/tapes/ ls: /backup/tapes/:
> Transport endpoint is not connected

That means S3QL has crashed, look at ~/.s3ql/mount.log to find out
what went wrong.

[...]

> Feb 1 15:04:29 ip-172-30-1-80 journal: mount.s3ql[11175]
> MainThread: [mount ] Exception during cleanup: Feb 1 15:04:30
> ip-172-30-1-80 journal: mount.s3ql[11175] MainThread: [root]
> Uncaught top-level exception:

The most important information came after this - unfortunately you
didn't include it.

> And what I find is that I'll have to run fsck.s3ql and enter
> 'continue' in order to get the s3 bucket mounted again on my
> local file system.

Yes, because it crashed.

> I'm using S3QL 1.18.1.

That's rather old and receives only critical security updates. If
at all possible, switch to S3QL 2.x.


Best,
-Nikolaus

(No Cc on replies please, I'm reading the list)
--
GPG encrypted emails preferred. Key id: 0xD113FCAC3C4E599F
Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

»Time flies like an arrow, fruit flies like a Banana.«

[Tim Dunphy]

Enter code here...

Hello,

 And thanks for your reply!

I can't seem to run contrib/benchmark.py. I get a divide by zero error when I do!

Traceback (most recent call last):
  File "/root/s3ql-1.18.1/contrib/benchmark.py", line 216, in <module>
    main(sys.argv[1:])
  File "/root/s3ql-1.18.1/contrib/benchmark.py", line 196, in main
    if speed / in_speed[alg] * out_speed[alg] > backend_speed:
ZeroDivisionError: float division by zero


This is the full output of the error:


Preparing test data...
Measuring throughput to cache...
Write took 0 seconds, retrying
Write took 2.28 seconds, retrying
Write took 2.79 seconds, retrying
Cache throughput: 72593 KiB/sec
Measuring raw backend throughput..
Connecting to jf-backup.s3.amazonaws.com...
_do_request(): start with parameters ('GET', '/s3ql_passphrase', None, None, None, None)
_send_request(): processing request for /s3ql_passphrase
_do_request(): request-id: F5129E17E9996ADD
Connecting to jf-backup.s3.amazonaws.com...
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 1048576}, <open file '<fdopen>', mode 'w+b' at 0x1a2d540>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: 974F0BB2D5CE56E2
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 2097152}, <open file '<fdopen>', mode 'w+b' at 0x1a2d5d0>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: F1DD2D9F91A530AE
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 4194304}, <open file '<fdopen>', mode 'w+b' at 0x1a2d540>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: 01B8D24AE0DE4F32
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 8388608}, <open file '<fdopen>', mode 'w+b' at 0x1a2d5d0>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: 09E1E29E055DDB92
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 16777216}, <open file '<fdopen>', mode 'w+b' at 0x1a2d540>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: AA53FCDC204694CA
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 33554432}, <open file '<fdopen>', mode 'w+b' at 0x1a2d5d0>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: C1FFB89E037195E4
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 67108864}, <open file '<fdopen>', mode 'w+b' at 0x1a2d540>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: 463DFBD5AD4D8C46
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 134217728}, <open file '<fdopen>', mode 'w+b' at 0x1a2d5d0>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: 41E37E95EE3669A6
open_write(s3ql_testdata): start
ObjectW(s3ql_testdata).close(): start
_do_request(): start with parameters ('PUT', '/s3ql_testdata', None, None, {'Content-Length': 268435456}, <open file '<fdopen>', mode 'w+b' at 0x1a2d540>)
_send_request(): sending request for /s3ql_testdata
_send_request(): Waiting for 100-cont..
Waiting for 100-continue...
_do_request(): request-id: C13046D35470E51C
Backend throughput: 16302 KiB/sec
delete(s3ql_testdata)
_do_request(): start with parameters ('DELETE', '/s3ql_testdata', None, None, None, None)
_send_request(): processing request for /s3ql_testdata
_do_request(): request-id: 81819FBD9EFB24B7
Test file size: 0.00 MiB
compressing with lzma...
lzma compression speed: 0 KiB/sec per thread (in)
lzma compression speed: 359 KiB/sec per thread (out)
compressing with bzip2...
bzip2 compression speed: 0 KiB/sec per thread (in)
bzip2 compression speed: 10 KiB/sec per thread (out)
compressing with zlib...
zlib compression speed: 0 KiB/sec per thread (in)
zlib compression speed: 130 KiB/sec per thread (out)
Uncaught top-level exception:
Traceback (most recent call last):
  File "/root/s3ql-1.18.1/contrib/benchmark.py", line 216, in <module>
    main(sys.argv[1:])
  File "/root/s3ql-1.18.1/contrib/benchmark.py", line 196, in main
    if speed / in_speed[alg] * out_speed[alg] > backend_speed:
ZeroDivisionError: float division by zero


Threads:                              1           2           4           8

I've captured the output to a file, while logging into the S3 bucket in another tab.

On Monday, February 1, 2016 at 10:49:37 AM UTC-5, Tim Dunphy wrote:

Hey guys,

I'm trying to use S3QL as a back end for my bacula backups. What I'd like to do is use an S3 bucket to actually hold the tapes that bacula writes to. One thing that I notice is that it's really really slow. I started a backup last night around 10pm, and this morning it hadn't even finished writing to a 5GB virutal tape. That's just ridiculously slow. If that were writing to EBS instead, it could have filled up in about 1/2 hour. It would be great to be able to backup to S3 without the expense of a huge EBS volume!!

Second thing I noticed is that when I went to list the directory I'm getting an error message:

[root@ops:~] #ls -lh /backup/tapes/
ls: /backup/tapes/: Transport endpoint is not connected

This is the second time I've seen that happen!

And these are the log entries I'm finding in syslog:

[root@ops:~] #grep s3ql /var/log/messages |grep "Feb  1"
Feb  1 01:57:00 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 04:21:32 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 04:23:10 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:08:18 ip-172-30-1-80 journal: mount.s3ql[11175] Dummy-18: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.open_read...
Feb  1 05:08:25 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-6: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.delete...
Feb  1 05:13:59 ip-172-30-1-80 journal: mount.s3ql[11175] Dummy-18: [backend] Encountered BadStatusLine exception (''), retrying call to Backend.open_read...
Feb  1 05:17:19 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:17:29 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:19:11 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:19:13 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:20:36 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-4: [backend] Encountered BadStatusLine exception (''), retrying call to ObjectW.close...
Feb  1 05:20:37 ip-172-30-1-80 journal: mount.s3ql[11175] Thread-3: [backend]

...

"The most important information came after this - unfortunately you 
didn't include it."

Whoops! Here's that line:

OSError: [Errno 2] No such file or directory: '/cache/s3:=2F=2Fjf-backup-cache/8-419'

>> I'm using S3QL 1.18.1. 

>That's rather old and receives only critical security updates. If 
>at all possible, switch to S3QL 2.x. 

I thought I read that only the 1.x branch will run under my operating system. I'm running CentOS 7. If the 2.x branch will work under that OS, then yeah I'll absolutely give that a try!!

Thanks,

Tim
  

 

[Nikolaus Rath]

On Feb 01 2016, Tim Dunphy <bluet...@gmail.com> wrote:

> Enter code here...
>
> Hello,
>
> And thanks for your reply!
>
> I can't seem to run contrib/benchmark.py. I get a divide by zero
> error when I do!
>
> Traceback (most recent call last):
> File "/root/s3ql-1.18.1/contrib/benchmark.py", line 216, in
> <module>
> main(sys.argv[1:])
> File "/root/s3ql-1.18.1/contrib/benchmark.py", line 196, in
> main
> if speed / in_speed[alg] * out_speed[alg] > backend_speed:
> ZeroDivisionError: float division by zero

Hmm, too bad. Unless you can fix this yourself, I'm afraid you'll
have to upgrade to S3QL 2.x.

[Tim Dunphy]

Hi Nikolaus,

Hmm, too bad. Unless you can fix this yourself, I'm afraid you'll have to upgrade to S3QL 2.x.

Ok. Will s3ql 2.x work under Centos 7.1?

Thanks,

Tim 

--
You received this message because you are subscribed to a topic in the Google Groups "s3ql" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/s3ql/bbfql0meFNg/unsubscribe.
To unsubscribe from this group and all its topics, send an email to s3ql+uns...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

GPG me!!

gpg --keyserver pool.sks-keyservers.net --recv-keys F186197B

[Nikolaus Rath]

On Feb 01 2016, Tim Dunphy <bluet...@gmail.com> wrote:
> Ok. Will s3ql 2.x work under Centos 7.1?

I have no idea. In principle, it works wherever you can get all
the dependencies to work (the biggest issue is probably the Python
>= 3.3 stack).

[Alexandre Gonçalves]

A few months ago I installed on centos 6, and the tricky part was, in deed, phyton 3.4. You have to compile it yourself, and cannot remove python 2.7 as yum and other stuff needs it.
So in centos 7, should be the same, I say.

Best