Hi all
This master server has two clients. This error occurred only on one client.
While another can be backed up successfully. I found an error occurred on
one of my puredisk master server job backup this morning.
It failed to backed up its client completely. I have trying to restart the
puredisk agent service on the client.
But the same error still occurred when I try to run 'manually backup'
process.
Please find the detail job on the log attached file.
Can anyone fix this ?
Thanks in advance.
Regards,
Ahmad Abbas ilyas
PT Mitra Integrasi Informatika
Support Services Department
Wisma Metropolitan 1 Lt.6
Jl. Jend Sudirman Kav 29-31 Jakarta Indonesia
Mobile: (+62) 8788 3955558
[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
.
<?xml version =
"1.0"?><mbimportreport><failed>false</failed><successWithErrors>false</successWithErrors><logging><logline></logline><logline>POlist
gotten from CR...</logline><logline>Sorting... </logline><logline>Sorting
completed succesfully</logline><logline>Splitting into 2 smaller files...
</logline><logline>Importing
/Storage/tmp/bulkInsert48790</logline><logline>Importing
/Storage/tmp/bulkInsertPO48794</logline><logline>Importing
/Storage/tmp/errsplit48795</logline><logline>DataSelection 2 succesfully
evaluated.</logline></logging><registertime>1264038576</registertime><numberofpoprocessed>0</numberofpoprocessed></mbimportreport>
[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
_______________________________________________
Veritas-bu maillist - Veritas-bu@mailman.eng.auburn.edu
http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu