--- Begin Message ---
- To: submit@bugs.debian.org
- Subject: burp client misreports backup size and uses 100% cpu for extended periods of time during backup operation
- From: Hal Martin <hal.martin@gmail.com>
- Date: Fri, 06 Feb 2015 16:31:42 +0100
- Message-id: <54D4DE5E.1030606@gmail.com>
Package: burp
Version: 1.3.8-1
Hello,
I have a few clients configured to backup to a burp server. They all
exhibit strange behaviour where they will randomly stop partially
through a backup run and use 100% CPU (on the client) for approximately
an hour before finalizing the backup. The server process is unaffected
during this time.
The burp client also misreports the size of the data backed up for every
host. Examples are contained below.
All burp.conf files are managed through puppet, and are identical on all
clients except for the client password. All servers are running Debian
Wheezy (7.7) and are xenhvm virtual machines.
Xen dom0:
uname -a:
Linux [redacted] 3.2.0-4-amd64 #1 SMP Debian 3.2.63-2+deb7u2 x86_64
GNU/Linux
dpkg -s libc6 | grep ^Version
Version: 2.13-38+deb7u6
dpkg -l | grep xen | awk '{print $2,$3}'
libxen-4.1 4.1.4-3+deb7u3
libxenstore3.0 4.1.4-3+deb7u3
xen-hypervisor-4.1-amd64 4.1.4-3+deb7u3
xen-linux-system-3.2.0-4-amd64 3.2.63-2+deb7u2
xen-linux-system-amd64 3.2+46
xen-system-amd64 4.1.4-3+deb7u3
xen-tools 4.3.1-1
xen-utils-4.1 4.1.4-3+deb7u3
xen-utils-common 4.1.4-3+deb7u3
xenstore-utils 4.1.4-3+deb7u3
Debian DomU VMs:
uname -a:
Linux [redacted] 3.2.0-4-amd64 #1 SMP Debian 3.2.63-2+deb7u2 x86_64
GNU/Linux
dpkg -s libc6 | grep ^Version
Version: 2.13-38+deb7u6
burp dependencies:
libacl1:amd64 2.2.51-8
libc6:amd64 2.13-38+deb7u6
libgcc1:amd64 1:4.7.2-5
libncurses5:amd64 5.9-10
librsync1:amd64 0.9.7-9
libssl1.0.0:amd64 1.0.1e-2+deb7u13
libtinfo5:amd64 5.9-10
zlib1g:amd64 1:1.2.7.dfsg-13
Host aaaaaa:
ii burp 1.3.8-1
burp client output:
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1472
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1536
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1600
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1664
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1728
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1792
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1856
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1920
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 1984
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2048
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2112
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2176
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2240
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2304
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2368
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2432
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2496
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2560
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2624
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2688
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2752
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2816
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2880
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 2944
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3008
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3072
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3136
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3200
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3264
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3328
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3392
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3456
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3520
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3584
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3648
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3712
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3776
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3840
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3904
ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff 3968
ffffffffffffffffffffffffffff
(output stops while CPU use increases for ~1 hour)
top during this time:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
21702 root 20 0 37016 4296 2816 R 99.1 0.4 5:21.73 burp
strace:
select(6, NULL, [5], [5], {1, 1}) = 1 (out [5], left {0, 999995})
write(5,
"\27\3\3\0002'\217)\36\354\306L\365\234MK\341\v\245~\240\377L\246\277\354;\36\304mB."...,
55) = 55
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
8192) = 8192
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
8192) = 8192
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
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\0\0\0\0\0"...,
4096) = 4096
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\0\0\0\0\0"...,
12288) = 12288
... (repeats)
finalizing message:
--------------------------------------------------------------------------------
Start time: 2015-02-06 14:34:23
End time: 2015-02-06 15:32:01
Time taken: 57:38
New Changed Unchanged Total | Scanned
--------------------------------------------------
Files: 39064 0 - 39064 | 39064
Directories: - - - - | 5474
Soft links: - - - - | 1011
Special files: - - - - | 31
Grand total: 39064 0 - 39064 | 45580
--------------------------------------------------
Warnings: 1
Bytes estimated: 421840023817 (392.87 GB)
Bytes in backup: 421840044575 (392.87 GB)
Bytes received: 0
Bytes sent: 421840044575 (392.87 GB)
--------------------------------------------------------------------------------
root@burp-srv:/var/spool/burp# du -sh aaaaaa
859M aaaaaa
Note that Bytes estimated, in backup, and sent are all incorrect. During
the period of high CPU-use there is negligible network traffic between
burp client and server.
Other hosts:
Host bbbbbb:
ii burp 1.3.8-1
finalizing message:
--------------------------------------------------------------------------------
Start time: 2015-02-06 14:36:45
End time: 2015-02-06 15:32:57
Time taken: 56:12
New Changed Unchanged Total | Scanned
--------------------------------------------------
Files: 4744 0 - 4744 | 4744
Directories: - - - - | 683
Soft links: - - - - | 846
Special files: - - - - | 7
Grand total: 4744 0 - 4744 | 6280
--------------------------------------------------
Warnings: 1
Bytes estimated: 421579052777 (392.63 GB)
Bytes in backup: 421579056792 (392.63 GB)
Bytes received: 0
Bytes sent: 421579056792 (392.63 GB)
--------------------------------------------------------------------------------
root@burp-srv:/var/spool/burp# du -sh bbbbbb
710M bbbbbb
Host cccccc:
ii burp 1.3.8-1
finalizing message:
--------------------------------------------------------------------------------
Start time: 2015-02-06 14:47:47
End time: 2015-02-06 15:46:34
Time taken: 58:47
New Changed Unchanged Total | Scanned
--------------------------------------------------
Files: 51602 0 - 51602 | 51602
Directories: - - - - | 7785
Soft links: - - - - | 1845
Hard links: - - - - | 1360
Special files: - - - - | 66
Grand total: 51602 0 - 51602 | 62658
--------------------------------------------------
Warnings: 1
Bytes estimated: 422311636355 (393.31 GB)
Bytes in backup: 422311639754 (393.31 GB)
Bytes received: 0
Bytes sent: 422311639754 (393.31 GB)
--------------------------------------------------------------------------------
2015-02-06 15:46:34: burp[21915] Phase 2 end (send file data)
2015-02-06 15:46:34: burp[21915] backup finished ok
2015-02-06 15:46:34: burp[21915] after client
root@burp-srv:/var/spool/burp# du -sh cccccc
1.2G cccccc
burp server:
ii burp 1.3.8-1
Client burp.conf (commented lines excluded):
mode = client
port = 4971
server = de1-p-backup01.eogs.de
password = [redacted]
cname = uk1-d-ci01
pidfile = /var/run/burp.client.pid
syslog = 1
stdout = 1
progress_counter = 1
server_can_restore = 0
cross_filesystem=/home
cross_all_filesystems=0
ca_burp_ca = /usr/sbin/burp_ca
ca_csr_dir = /etc/burp/CA-client
ssl_cert_ca = /etc/burp/ssl_cert_ca.pem
ssl_cert = /etc/burp/ssl_cert-client.pem
ssl_key = /etc/burp/ssl_cert-client.key
ssl_key_password = password
ssl_peer_cn = burpserver
include = /home
include = /etc
include = /var
include = /opt
include = /boot
exclude_fs = sysfs
exclude_fs = tmpfs
nobackup = .nobackup
exclude_comp=bz2
exclude_comp=gz
--- End Message ---
--- Begin Message ---
> Therefore this bug can be ignored. Problem was with my configuration,
> not the package.
Okay then, thanks for investigating!
Sorry for the delay, but this package has no maintainer currently, and thus
non-serious bug reports are looked at only occassionally as part of drive-by
QA.
Meow!
--
An imaginary friend squared is a real enemy.
--- End Message ---