[Box Backup] Re: [Box Backup] error:1409F07F:SSL routines:SSL3_WRITE_PENDING:bad write retry

[Johann Glaser]

Hi!

> bbackupd.conf.

Thanks!

I've added a FeatureRequest in the Wiki to add this option in the config
file template.

I've investigated this case more closely. The problem occurs every time
with the very same file with a size of (only) 360.724.480 bytes (we have
much larger files). I attached an strace to the bbackupd process and
found out that all files before this one are only checked using
lstat64() and llistxattr() but are never open()ed or ever read(). I
think this is because they already have been backuped in the night when
the backup ran the first time (approx. 3:50).

The particular file which triggers the problem on the other hand is read
quite often. It starts with the following:

...
23240 open("/backup/daily/mysql/mysql-InnoDB.tar", O_RDONLY|O_LARGEFILE) = 6
23240 fstat64(6, {st_mode=S_IFREG|0600, st_size=360724480, ...}) = 0
23240 _llseek(6, 0, [0], SEEK_CUR)      = 0
23240 mmap2(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb79e5000
23240 mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb79c4000
23240 mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb79a3000
23240 _llseek(6, 0, [0], SEEK_SET)      = 0
23240 read(6, "data/mysql/ib_arch_log_000000000"..., 1430) = 1430
... many read(6, ..., 1430) = 1430
23240 read(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1430) = 1260

Ok, the file was now completely read. There is nothing in between, only
lots of read()s. Then it starts over again with 

23240 _llseek(6, 0, [0], SEEK_SET)      = 0
23240 read(6, "data/mysql/ib_arch_log_000000000"..., 1511) = 1511
23240 read(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1511) = 1511
... many read(6, ..., 1511) = 1511
23240 read(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1511) = 428

So it was read a second time with a 81 bytes larger read buffer. Again
it reads the very same file with an increased read buffer

23240 _llseek(6, 0, [0], SEEK_SET)      = 0
23240 read(6, "data/mysql/ib_arch_log_000000000"..., 1525) = 1525
23240 read(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\302\0\0\0\0\0\n-/"..., 1525) = 1525
...

And this continues (until I stopped strace). The read buffer is always
increased irregularly by 3-152 bytes except once where it went from 2394
down to 1199 and then up to 2427. In the meantime bbstored already
compliant about the Protocol_Timeout.

Why is bbackupd reading this file so often?

Bye
  Hansi

-- 
Johann Glaser                          <glaser@ict.tuwien.ac.at>
             Institute of Computer Technology, E384
Vienna University of Technology, Gusshausstr. 27-29, A-1040 Wien
Phone: ++43/1/58801-38444                Fax: ++43/1/58801-38499