[2010-Jan-21 08:47:09 WIT] *** Start: PrepareBackup *** [2010-Jan-21 08:47:09 WIT] Prepare Backup Client Side. [2010-Jan-21 08:47:09 WIT] --- Configure Progress Logging --- [2010-Jan-21 08:47:09 WIT] --- Retrieve Dataselection Rules --- . [2010-Jan-21 08:47:09 WIT]Dataselection rules downloaded: . . [2010-Jan-21 08:47:09 WIT]/data/backup/last/*|*|i . /data/backup/*|*|i . . [2010-Jan-21 08:47:09 WIT]Dataselection was set to dirty, fetching the state known to the Metabase... . . [2010-Jan-21 08:47:09 WIT]Fetching the polist corresponding with the current state using DSFind -i 2 . [2010-Jan-21 08:47:10 WIT]Download POList from metabase ended. Checking POList for errors. . [2010-Jan-21 08:47:10 WIT]Sorting resulting POList. . . [2010-Jan-21 08:47:10 WIT]PLSort Command: "/opt/pdag/bin/PLsort" -f "/opt/pdag/var/srd/2/current/SnapshotPOList.po" -r "/opt/pdag/var/srd/2/current/SnapshotPOList.po" --detect=directory,fileName -v --config="/etc/puredisk/Agent.cfg" --tempdir="/opt/pdag/tmp" . Option values: tempdir: /opt/pdag/tmp input : /opt/pdag/var/srd/2/current/SnapshotPOList.po output : /opt/pdag/var/srd/2/current/SnapshotPOList.po detect : directory,fileName decide : (option not specified) maxpos : 262144 maxsize: 10MiB sort start at : Thu Jan 21 08:47:10 2010 sort finished at: Thu Jan 21 08:47:10 2010 sort duration : 0d:0h:0m:0s . [2010-Jan-21 08:47:10 WIT]Result: . . . [2010-Jan-21 08:47:10 WIT]POList successfully fetched [2010-Jan-21 08:47:10 WIT] *** Stop: PrepareBackup *** *** Supportability Summary *** jobid = 10187 jobstepid = 33490 agentid = 2 hostname = dbspeedyradbdg-01 starttimejobstep = January 21, 2010, 8:47 am endtimejobstep = January 21, 2010, 8:47 am workflowstepname = PrepareBackup status = SUCCESS [2010-Jan-21 08:47:12 WIT] *** Start: ScanFilesystem *** [2010-Jan-21 08:47:12 WIT] --- ScanFileSystem --- . [2010-Jan-21 08:47:12 WIT]Executing PLscanFilesSystem with command: . "/opt/pdag/bin/PLscanFileSystem" -i "2" -v --drivetypes=fixed,network --config="/etc/puredisk/Agent.cfg" . PLscanFileSystem starting... +-------------+ |Configuration| +-------------+ +--------------------------+ |Data Specification Options| +--------------------------+ - clean : False - polistname : polist.po - dsidrangelist : 2 - statisticsfilename : /opt/pdag/var/srd +-----------+ |Scan Extent| +-----------+ - drive type : fixed,network - fingerprint : False - snapshotdrivelist : +----------------------+ |Modification Detection| +----------------------+ - mod : mtime,ctime,size +---------------------+ |System Responsiveness| +---------------------+ - maxscanspeed : 0 +-------------------+ |Running Application| +-------------------+ Dataselections to process: 2 Processing dataselection 2. Parsing dataselection file: /opt/pdag/var/srd/2/dataselection.cfg ... OK Dataselection include rules: /data/backup/last/*|*|I /data/backup/*|*|I Dataselection exclude rules: /opt/pdag/var/keys/*|*|E /opt/pdag/var/progress/*|*|E /opt/pdag/var/run/*|*|E /opt/pdag/var/rt/*|*|E /opt/pdag/var/srd/*|*|E /opt/pdag/tmp/*|*|E /opt/pdag/*|*|E Data selection 2 scan start at : Thu Jan 21 08:47:12 2010 Number of NEW POs: 5 Number of MODIFIED POs: 33 Number of DELETED POs: 6 Number of POs in PO list: 44 (of which 0 with error) Number of unmodified POs: 194 Number of parent POs: 2 Data selection 2 scan finished at : Thu Jan 21 08:47:12 2010 Data selection 2 scan duration : 0d:0h:0m:0s Some files in dataselection 2 are new, have changed, or are no longer present. 1 out of 1 dataselections processed Exit code: 0 [2010-Jan-21 08:47:12 WIT] *** Stop: ScanFilesystem *** *** Supportability Summary *** jobid = 10187 jobstepid = 33491 agentid = 2 hostname = dbspeedyradbdg-01 starttimejobstep = January 21, 2010, 8:47 am endtimejobstep = January 21, 2010, 8:47 am workflowstepname = Scan Filesystem status = SUCCESS [2010-Jan-21 08:47:14 WIT] *** Start: PutFiles *** [2010-Jan-21 08:47:14 WIT] --- Put Files (Multi Stream) --- [2010-Jan-21 08:47:14 WIT]Recommended Routing Tables: [2010-Jan-21 08:47:14 WIT]0000 ffff 172.16.201.35 0 [2010-Jan-21 08:47:14 WIT]Current Routing Tables: [2010-Jan-21 08:47:14 WIT]0000 ffff 172.16.201.35 0 . [2010-Jan-21 08:47:14 WIT]Adding content of /opt/pdag/var/srd/2/stats.txt to job variables . Info: Job Settings Info: Check prior existance : no Info: Enable Compression : no Info: Enable Encryption : yes Info: Preserve Access Time : yes Info: Offload encryption to Server: no Info: Don't segment threshold : not set Info: Don't segment types : not set Info: Maximum Bandwidth : no limit Info: Failed Operation Retry count: 5 Info: Segment Size : 131072 Info: Small File Threshold : 16kib Info: Number of Backup streams : 1 Info: Maximum Transaction Size : 4096 Info: Scanning input PO list: /opt/pdag/var/srd/2/polist.po Info: Scan completed, 44 PO entries, longest PO is approximately 256 bytes Info: Adjusting transaction size to 45 PO entries Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Info: 103: /data/backup/DOSSIER_RAD_BDG_20100119-197369.txt: skipped because it is marked as deleted Info: 103: /data/backup/binlog/dbspeedyradbdg-01-bin.000819: skipped because it is marked as deleted Info: 103: /data/backup/binlog/dbspeedyradbdg-01-bin.000820: skipped because it is marked as deleted Info: 103: /data/backup/binlog/dbspeedyradbdg-01-relay.000400: skipped because it is marked as deleted Info: 103: /data/backup/binlog/dbspeedyradbdg-01-relay.000401: skipped because it is marked as deleted Error: 5: data store failed: could not spool object: try again Error: 5: An unexpected error occurred during communication with a remote system. Please use the following information, examine the system or program log file to determine the exact cause of this error. Connection Type : Store Remote Address : XXXXXXXX Local Address : XXXXXXXX Session ID : 921684953 Data Selection ID: 2 Event code : 5 Event Description: try again Server response : data store failed: could not spool object: try again Error: 5: /data/backup/data/radius/radacct.ibd: could not be stored (try again) Warning: 42: /data/backup/data/radius/radacct.ibd: failed (aborted). Retrying in 5 seconds Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Error: 5: data store failed: could not spool object: try again Error: 5: An unexpected error occurred during communication with a remote system. Please use the following information, examine the system or program log file to determine the exact cause of this error. Connection Type : Store Remote Address : XXXXXXXX Local Address : XXXXXXXX Session ID : 3415858967 Data Selection ID: 2 Event code : 5 Event Description: try again Server response : data store failed: could not spool object: try again Error: 5: /data/backup/data/radius/radacct.ibd: could not be stored (try again) Warning: 42: /data/backup/data/radius/radacct.ibd: failed (aborted). Retrying in 10 seconds Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Error: 5: data store failed: could not spool object: try again Error: 5: An unexpected error occurred during communication with a remote system. Please use the following information, examine the system or program log file to determine the exact cause of this error. Connection Type : Store Remote Address : XXXXXXX Local Address : XXXXXXX Session ID : 697001619 Data Selection ID: 2 Event code : 5 Event Description: try again Server response : data store failed: could not spool object: try again Error: 5: /data/backup/data/radius/radacct.ibd: could not be stored (try again) Warning: 42: /data/backup/data/radius/radacct.ibd: failed (aborted). Retrying in 15 seconds Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Error: 5: data store failed: could not spool object: try again Error: 5: An unexpected error occurred during communication with a remote system. Please use the following information, examine the system or program log file to determine the exact cause of this error. Connection Type : Store Remote Address : XXXXXXXXX Local Address : XXXXXXXXX Session ID : 2020492672 Data Selection ID: 2 Event code : 5 Event Description: try again Server response : data store failed: could not spool object: try again Error: 5: /data/backup/data/radius/radacct.ibd: could not be stored (try again) Warning: 42: /data/backup/data/radius/radacct.ibd: failed (aborted). Retrying in 20 seconds Info: Server is Version 6.5.1.19343, Protocol Version 6.1 Error: 5: data store failed: could not spool object: try again Error: 5: An unexpected error occurred during communication with a remote system. Please use the following information, examine the system or program log file to determine the exact cause of this error. Connection Type : Store Remote Address : XXXX Local Address : XXXX Session ID : 1047958097 Data Selection ID: 2 Event code : 5 Event Description: try again Server response : data store failed: could not spool object: try again Error: 5: /data/backup/data/radius/radacct.ibd: could not be stored (try again) Error: 42: /data/backup/data/radius/radacct.ibd: did not succeed after 5 consecutive attempts, giving up (at line 30 in input). Error: 42: A fatal error was encountered while processing (unknown) (at line 30 in input). Cannot continue. Info: Backup completed successfully (0 PO processed, 0 bytes) Info: Duration : 132.74 seconds Info: Items Stored : 0 (0 bytes) Info: Items transferred to Storage: 0 (0 bytes) Info: Average Backup Speed : 0 bytes/sec Info: Average Transfer Rate : 0 Info: Average Processing Speed : 0.00 PO/sec Info: Files Stored : 0 of which 0 (0 bytes) new, 0 (0 bytes) changed and 0 (0 bytes) unchanged Info: Directories Stored : 0 Info: Hard Links Stored : 0 Info: Symbolic Links Stored : 0 Info: Devices Stored : 0 *** Error Message *** severity: 6 server: 2 source: PutFiles_PutFiles description: Command '"/opt/pdag/bin/pdbackup" -I "/opt/pdag/var/srd/2/polist.po" -O "/opt/pdag/tmp/wf_putFilesPOlist_2yEzOf7" -S "/opt/pdag/tmp/wf_putFilesStats_27ph9Jv" --options compress=0~encrypt=1~servercrypt=~checkifexists=~acl=0~noarchivebit=~segmentsize=131072~preserveaccesstime=1' unexpectedly terminated with exit status 1 *** End *** *** Supportability Summary *** jobid = 10187 jobstepid = 33492 agentid = 2 hostname = dbspeedyradbdg-01 starttimejobstep = January 21, 2010, 8:47 am endtimejobstep = January 21, 2010, 8:49 am workflowstepname = PutFiles status = ERROR [2010-Jan-21 08:49:29 WIT] *** Start: PutRecoveryPOList *** [2010-Jan-21 08:49:29 WIT] --- Get Recovery POList --- . [2010-Jan-21 08:49:29 WIT]Storing Recovery polist: /opt/pdag/tmp/wf_putFilesPOlist_2yEzOf7 . [2010-Jan-21 08:49:30 WIT] *** Stop: PutRecoveryPOList *** *** Supportability Summary *** jobid = 10187 jobstepid = 33493 agentid = 2 hostname = dbspeedyradbdg-01 starttimejobstep = January 21, 2010, 8:49 am endtimejobstep = January 21, 2010, 8:49 am workflowstepname = GetRecoveryPolist status = SUCCESS [2010-Jan-21 08:49:30 WIT] *** Start: MBImport *** . [2010-Jan-21 08:49:30 WIT]Start check limit on dataselection 2 . . [2010-Jan-21 08:49:30 WIT]Limit ok. . . [2010-Jan-21 08:49:30 WIT]Stop check limit on dataselection 2 . falsefalsePOlist gotten from CR...Sorting... Sorting completed succesfullySplitting into 2 smaller files... Importing /Storage/tmp/bulkInsert48790Importing /Storage/tmp/bulkInsertPO48794Importing /Storage/tmp/errsplit48795DataSelection 2 succesfully evaluated.12640385760 [2010-Jan-21 08:49:39 WIT] [2010-Jan-21 08:49:39 WIT]POlist gotten from CR... [2010-Jan-21 08:49:39 WIT]Sorting... [2010-Jan-21 08:49:39 WIT]Sorting completed succesfully [2010-Jan-21 08:49:39 WIT]Splitting into 2 smaller files... [2010-Jan-21 08:49:39 WIT]Importing /Storage/tmp/bulkInsert48790 [2010-Jan-21 08:49:39 WIT]Importing /Storage/tmp/bulkInsertPO48794 [2010-Jan-21 08:49:39 WIT]Importing /Storage/tmp/errsplit48795 [2010-Jan-21 08:49:39 WIT]DataSelection 2 succesfully evaluated. [2010-Jan-21 08:49:39 WIT]Processed 0 PO's in 9.077, 0 PO/s [2010-Jan-21 08:49:40 WIT] *** Stop: MBImport *** *** Supportability Summary *** jobid = 10187 jobstepid = 33494 agentid = 639000000 hostname = 172.16.201.35 starttimejobstep = January 21, 2010, 8:49 am endtimejobstep = January 21, 2010, 8:49 am workflowstepname = ImportMB_Error status = SUCCESS [2010-Jan-21 08:49:42 WIT] *** Start: FinishBackup *** [2010-Jan-21 08:49:42 WIT] --- Finish Progress Logging --- [2010-Jan-21 08:49:42 WIT] *** Stop: FinishBackup *** *** Supportability Summary *** jobid = 10187 jobstepid = 33495 agentid = 2 hostname = dbspeedyradbdg-01 starttimejobstep = January 21, 2010, 8:49 am endtimejobstep = January 21, 2010, 8:49 am workflowstepname = BackupStopError status = SUCCESS Execute WFAction: Mark Exit Execute WFAction: Mark Error Execute WFAction: Exit Job exited with 1 errors, 0 warnings, 6 successes *** Supportability Summary *** jobid = 10187 jobstepid = 33496 agentid = 639000000 hostname = 172.16.201.35 starttimejobstep = January 21, 2010, 8:49 am endtimejobstep = January 21, 2010, 8:49 am workflowstepname = MarkExit status = SUCCESS