[Box Backup] Cleanup after accidently hitting the 2GB problem

Sun, 11 May 2008 18:55:20 -0400

Cleanup after accidently hitting the 2GB problem.

Here's a quick note about how to clean up after hitting the 2GB file
size problem.  I do not normally have any files > 2GB, but an Apache
'access.log'  file was not being rotated, and I ran into the problem. 
The 'access.log' file was > 2GB.  I fixed the file rotation problem and
got rid of the file that was > 2GB by running 'logrotate -f' twice,
which compressed the large file and left it in 'access.log.2.gz', but
still had a file named 'access.log'. Running
/usr/local/bin/bbackup-daily on the client still generated the error
message, apparently because attempting to diff the stored version of the
file (>2GB) against the version on the client (<2GB) still caused a
problem.  Renaming 'access.log' to 'access_good.log' did not correct the
situation.  Apparently bbackup is detecting that the file is still the
same file (I guess from the inode ???), and still trys to diff against
the stored version.  Copying the file to a temp directory and deleting
it from the directory that bbackup was trying to store got rid of the
error message.  Copying it back to the original directory and original
filename did not reintroduce the error.  Looking at the output from
bbackquery 'ls -odt', apparently the >2GB file is still in the store,
marked as deleted, with the name 'access_good.log', but is not causing
problems because nothing in the current backup is diff'd against it.

I am running bbackupd version 0.09, and recent version of Debian Linux
and Apache. The following operation we done with Apache not running.

Relevant portions of syslog and bbackquery output are below. It took me
several hours to figure this out. Maybe this will help someone else
deal with this more quickly.

Bill West

BWI
887 Main Street, Suite D
Monroe, Connecticut  06468-2800
877 567-7450, 203 261-6027
FAX  203 261-5061
info@bwi.com
http://www.bwi.com

BWI and RackPaq are registered trademarks of Bill West Incorporated
Destwin is a trademark of DESTWIN, LLC.

---------------Extracted from syslog file on client, with comments --------------------------------------
### Original error, after rotating logs so there is no file > 2GB
May 11 17:28:06 shearwater bbackupd[3888]: Incoming connection from local (UNIX socket)
May 11 17:28:06 shearwater bbackupd[3888]: Connection from command socket
May 11 17:28:06 shearwater bbackupd[3888]: Beginning scan of local files
May 11 17:28:06 shearwater bbackupd[3888]: Opening connection to server backup.bogus.net...
May 11 17:28:06 shearwater bbackupd[3888]: Connection made, login successful
May 11 17:28:07 shearwater bbackupd[3888]: Backup object failed, error when reading /www/logs/access.log
May 11 17:28:07 shearwater bbackupd[3888]: Error code when uploading was (4/11), BackupStore BadBackupStoreFile
May 11 17:28:07 shearwater bbackupd[3888]: Finished scan of local files
May 11 17:28:07 shearwater bbackupd[3888]: File statistics: total file size uploaded 2066, bytes already on server 0, encoded size 1040

### After 'mv -i access.log access_good.log'
May 11 17:48:57 shearwater bbackupd[3888]: Incoming connection from local (UNIX socket)
May 11 17:48:57 shearwater bbackupd[3888]: Connection from command socket
May 11 17:48:57 shearwater bbackupd[3888]: Beginning scan of local files
May 11 17:48:57 shearwater bbackupd[3888]: Opening connection to server backup.bogus.net...
May 11 17:48:59 shearwater bbackupd[3888]: Connection made, login successful
May 11 17:49:01 shearwater bbackupd[3888]: Backup object failed, error when reading /www/logs/access_good.log
May 11 17:49:01 shearwater bbackupd[3888]: Error code when uploading was (4/11), BackupStore BadBackupStoreFile
May 11 17:49:10 shearwater bbackupd[3888]: Finished scan of local files
May 11 17:49:10 shearwater bbackupd[3888]: File statistics: total file size uploaded 6956, bytes already on server 0, encoded size 2104

### After 'cp -p access_good.log /tmp/access_good.log; rm access_good.log'
May 11 17:50:56 shearwater bbackupd[3888]: Incoming connection from local (UNIX socket)
May 11 17:50:56 shearwater bbackupd[3888]: Connection from command socket
May 11 17:50:56 shearwater bbackupd[3888]: Beginning scan of local files
May 11 17:50:56 shearwater bbackupd[3888]: Opening connection to server backup.bogus.net...
May 11 17:50:56 shearwater bbackupd[3888]: Connection made, login successful
May 11 17:50:57 shearwater bbackupd[3888]: Finished scan of local files
May 11 17:50:57 shearwater bbackupd[3888]: File statistics: total file size uploaded 0, bytes already on server 0, encoded size 0

### After 'cp -p /tmp/access_good.log access.log'
May 11 17:52:32 shearwater bbackupd[3888]: Incoming connection from local (UNIX socket)
May 11 17:52:32 shearwater bbackupd[3888]: Connection from command socket
May 11 17:52:32 shearwater bbackupd[3888]: Beginning scan of local files
May 11 17:52:32 shearwater bbackupd[3888]: Opening connection to server backup.bogus.net...
May 11 17:52:32 shearwater bbackupd[3888]: Connection made, login successful
May 11 17:52:34 shearwater bbackupd[3888]: Finished scan of local files
May 11 17:52:34 shearwater bbackupd[3888]: File statistics: total file size uploaded 588880, bytes already on server 0, encoded size 114423

---------------------- output from bbackupquery, interactive mode -----------------------

query > ls -odt
------- snip irrelevant stuff ---------------
00018c0e f--o-- 2008-05-03T23:49:35 error.log
00018c0f f-Xo-- 2008-05-04T04:17:09 access_good.log
00018c18 f--o-- 2008-05-04T22:50:50 error.log
00018c19 f-Xo-- 2008-05-05T04:16:38 access_good.log
00018c2f f--o-- 2008-05-06T01:23:18 error.log
00018c30 f-Xo-- 2008-05-06T04:16:40 access_good.log
00018c45 f-Xo-- 2008-05-07T04:16:38 access_good.log
00018c54 f--o-- 2008-05-08T00:32:06 error.log
00018c55 f-Xo-- 2008-05-08T04:16:30 access_good.log
00018c6e f--o-- 2008-05-08T22:58:46 error.log
00018c6f f-X--- 2008-05-09T04:16:39 access_good.log
00018cb4 f--o-- 2008-05-11T03:01:36 error.log
00018ce7 f----- 2008-05-11T20:44:35 error.log
00018ce8 f----- 2008-05-11T20:44:14 access.log.2.gz
00018ce9 f----- 2008-05-11T20:46:18 access.log.1
00018cea f----- 2008-05-11T18:58:43 error.log.1
00018d03 f----- 2008-05-11T21:45:39 access.log
query > quit

--------------------------------------------------------------------------------------------