[Box Backup] housekeeping time

Jernej Porenta boxbackup@fluffy.co.uk
Tue, 12 Jun 2007 09:18:16 +0200 (CEST)


Hello,

What can I do about housekeeping taking way too much time?

The problem is that housekeeping takes more time than the client update
interval is configured. Usually housekeeping takes about several hours
(client is configured to update store in 12 hours). But when housekeeping
is accidentally interrupted with client trying to update the store, the
next housekeeping takes 25 hours!! And if I wouldnt stop the client, the
housekeeping would never finish, because of the 12 hour update interval.

The funny thing is that if I shut down the server after the first
interrupted housekeeping and run check&fix and set up the limits again,
housekeeping would take only about 2 hours (bbstoreaccount check 1 fix
takes about 2 hours as well). The client has quite a lot of files
(Maildir), but 25 hours is way too long.

So what is the deal with slow housekeeping after the hk interrupt?

Some info about the server:
- dual Xeon 2.66GHz, 2.5GB ram, U160 SCSI 136 hard drive dedicated for
bbackup

shell> bbstoreaccount info 1
                  Account ID: 00000001
              Last object ID: 6078056
                 Blocks used: 31452510 (122861.37Mb)
    Blocks used by old files: 9029810 (35272.70Mb)
Blocks used by deleted files: 10498170 (41008.48Mb)
  Blocks used by directories: 104938 (409.91Mb)
            Block soft limit: 31457280 (122880.00Mb)
            Block hard limit: 34603008 (135168.00Mb)
         Client store marker: 1181519035000000


Here is the log from the server(some parts are taken out, but not the
last 3 lines :)):
Jun  8 17:50:43 krpan bbstored[12748]: Starting daemon (config:
/etc/boxbackup/bbstored.conf) (version 0.10)
Jun  8 17:50:43 krpan bbstored/hk[12749]: Housekeeping process started
Jun  8 17:50:43 krpan bbstored/hk[12749]: Starting housekeeping
Jun  8 21:29:56 krpan bbstored/hk[12749]: Account 0x00000001, removed
38431 blocks (3603 files, 40 dirs)
Jun  8 21:29:56 krpan bbstored/hk[12749]: Finished housekeeping
... housekeeping...
Jun  9 17:50:43 krpan bbstored/hk[12749]: Starting housekeeping
Jun  9 21:29:05 krpan bbstored[12748]: Incoming connection from
212.235.240.122 port 35366 (handling in child 19978)
Jun  9 21:29:05 krpan bbstored[19978]: Certificate CN: BACKUP-1
Jun  9 21:29:09 krpan bbstored[19978]: Failed to get write lock (for
Client ID 00000001)
Jun  9 21:29:09 krpan bbstored[19978]: Connection statistics for BACKUP-1:
IN=60 OUT=60 TOTAL=120
Jun  9 21:29:09 krpan bbstored[19978]: in server child, exception
Connection TLSReadFailed (Probably a network issue between client and
server.) (7/34) -- terminating child
Jun  9 21:31:43 krpan bbstored/hk[12749]: Housekeeping giving way to
connection for account 0x00000001
Jun  9 21:31:43 krpan bbstored/hk[12749]: Account 0x00000001, removed
49708 blocks (3439 files, 0 dirs) was interrupted
Jun  9 21:31:44 krpan bbstored/hk[12749]: Finished housekeeping
Jun  9 21:36:50 krpan bbstored[12748]: Incoming connection from
212.235.240.122 port 38802 (handling in child 20948)
Jun  9 21:36:50 krpan bbstored[20948]: Certificate CN: BACKUP-1
Jun  9 21:36:50 krpan bbstored[20948]: Login: Client ID 00000001,
Read/Write
Jun  9 21:50:43 krpan bbstored/hk[12749]: Starting housekeeping
Jun  9 21:50:43 krpan bbstored/hk[12749]: Finished housekeeping
Jun 10 01:44:09 krpan bbstored[20948]: Session finished
Jun 10 01:44:09 krpan bbstored[20948]: Connection statistics for BACKUP-1:
IN=141304716 OUT=79655544 TOTAL=220960260

... other logs

Jun 10 22:00:08 krpan bbstored/hk[12749]: Starting housekeeping
Jun 10 22:04:26 krpan bbstored[12748]: Incoming connection from
212.235.240.122 port 41346 (handling in child 9500)
Jun 10 22:04:26 krpan bbstored[9500]: Certificate CN: BACKUP-1
Jun 10 22:04:26 krpan bbstored/hk[12749]: Housekeeping giving way to
connection for account 0x00000001
Jun 10 22:04:27 krpan bbstored/hk[12749]: Finished housekeeping
Jun 10 22:04:27 krpan bbstored[9500]: Login: Client ID 00000001,
Read/Write
Jun 11 01:44:43 krpan bbstored[9500]: Session finished
Jun 11 01:44:43 krpan bbstored[9500]: Connection statistics for BACKUP-1:
IN=127452172 OUT=80183825 TOTAL=207635997
Jun 11 02:00:08 krpan bbstored/hk[12749]: Starting housekeeping
Jun 12 03:33:28 krpan bbstored/hk[12749]: Account 0x00000001, removed
173612 blocks (21950 files, 12 dirs)
Jun 12 03:33:28 krpan bbstored/hk[12749]: Finished housekeeping


Have fun, Jernej