After run copy: Running Jobs: Console connected at 14-Jul-14 15:04 JobId Level Name Status ====================================================================== 2652 Increme backup.test.riege.de.2014-07-14_15.05.35_04 is running 2653 Full backup.test.riege.de.copy.2014-07-14_15.05.40_05 is waiting on max Client jobs 2654 Full backup.test.riege.de.copy.2014-07-14_15.05.40_06 is waiting on max Client jobs 2655 Increme backup.test.riege.de.2014-07-14_15.05.40_07 has been canceled 2656 Full backup.test.riege.de.copy.2014-07-14_15.05.40_08 is waiting on max Client jobs 2657 Increme backup.test.riege.de.2014-07-14_15.05.40_09 is waiting execution 2658 Full backup.test.riege.de.copy.2014-07-14_15.05.40_10 is waiting on max Client jobs 2659 Increme backup.test.riege.de.2014-07-14_15.05.40_11 is waiting execution 2660 Full backup.test.riege.de.copy.2014-07-14_15.05.40_12 is waiting on max Client jobs 2661 Increme backup.test.riege.de.2014-07-14_15.05.40_13 is waiting execution 2662 Full backup.test.riege.de.copy.2014-07-14_15.05.40_14 is waiting on max Client jobs 2663 Increme backup.test.riege.de.2014-07-14_15.05.40_15 is waiting execution 2664 Increme backup.test.riege.de.2014-07-14_15.05.40_16 is waiting execution ==== Job Enqueue: 14-Jul-2014 15:05:39 backup.test-dir: ua_run.c:1965-0 Using pool backup.test.riege.de 14-Jul-2014 15:05:39 backup.test-dir: ua_run.c:1983-0 Using next pool backup.test.riege.de 14-Jul-2014 15:05:39 backup.test-dir: job.c:1634-0 wstorage=backup.test.copy.filestorage 14-Jul-2014 15:05:39 backup.test-dir: job.c:1643-0 wstore=backup.test.copy.filestorage where=Job resource 14-Jul-2014 15:05:39 backup.test-dir: job.c:1667-0 wstore=backup.test.filestorage where=Pool resource 14-Jul-2014 15:05:39 backup.test-dir: job.c:1634-0 wstorage=library.test.filestorage 14-Jul-2014 15:05:39 backup.test-dir: job.c:1643-0 wstore=library.test.filestorage where=Storage from Run NextPool override 14-Jul-2014 15:05:40 backup.test-dir: ua_run.c:432-0 JobId=0 using pool backup.test.riege.de priority=10 14-Jul-2014 15:05:40 backup.test-dir: message.c:349-0 Copy message resource 24bbc78 to 7f05740101a8 14-Jul-2014 15:05:40 backup.test-dir: job.c:1290-0 JobId=0 created Job=backup.test.riege.de.copy.2014-07-14_15.05.40_05 14-Jul-2014 15:05:40 backup.test-dir: job.c:138-0 Open database 14-Jul-2014 15:05:40 backup.test-dir: sql_pooling.c:58-0 db_sql_get_non_pooled_connection allocating 1 new non pooled database connection to database bareos, backend type mysql 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename dbi, partly_compare = true 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename mysql, partly_compare = false 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:747-0 DB REopen bareos 14-Jul-2014 15:05:40 backup.test-dir: job.c:154-0 DB opened 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1160-0 Created Client backup.test.riege.de record 3 14-Jul-2014 15:05:40 backup.test-dir: job.c:190-0 Created job record JobId=2653 Name=backup.test.riege.de.copy.2014-07-14_15.05.40_05 Type=c Level=F 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:299-0 === enter new_plugins === 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:301-0 No dir plugin list! 14-Jul-2014 15:05:40 backup.test-dir: job.c:1039-0 entering apply_pool_overrides() 14-Jul-2014 15:05:40 backup.test-dir: job.c:738-0 get_or_create_pool=backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 20 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=5' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:663-0 Actual NumVols=11 Pool NumVols=11 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:138-0 Read pool=backup.test.riege.de (From Job resource) 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2653,'2014-07-14 15:05:40','backup.test-dir JobId 2653: Warning: FileSet MD5 digest not found.\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='EmptySet' AND MD5=''' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1197-0 Created FileSet EmptySet record 3 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1302-0 copy selection pattern=backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1304-0 get uncopied jobs query=SELECT DISTINCT Job.JobId,Job.StartTime FROM Job,Pool WHERE Pool.Name = 'backup.test.riege.de' AND Pool.PoolId = Job.PoolId AND Job.Type = 'B' AND Job.JobStatus IN ('T','W') AND Job.jobBytes > 0 AND Job.JobId NOT IN (SELECT PriorJobId FROM Job WHERE Type IN ('B','C') AND Job.JobStatus IN ('T','W') AND PriorJobId != 0) ORDER by Job.StartTime 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:406-0 db_sql_query starts with SELECT DISTINCT Job.JobId,Job.StartTime FROM Job,Pool WHERE Pool.Name = 'backup.test.riege.de' AND Pool.PoolId = Job.PoolId AND Job.Type = 'B' AND Job.JobStatus IN ('T','W') AND Job.jobBytes > 0 AND Job.JobId NOT IN (SELECT PriorJobId FROM Job WHERE Type IN ('B','C') AND Job.JobStatus IN ('T','W') AND PriorJobId != 0) ORDER by Job.StartTime 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:416-0 db_sql_query succeeded. checking handler 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=1 Ids=7f0574011e10 2049 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=2 Ids=7f0574011e10 2049,2115 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=3 Ids=7f0574011e10 2049,2115,2181 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=4 Ids=7f0574011e10 2049,2115,2181,2380 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=5 Ids=7f0574011e10 2049,2115,2181,2380,2448 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:753-0 dbid_hdlr count=6 Ids=7f0574011e10 2049,2115,2181,2380,2448,2516 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:440-0 db_sql_query finished 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2653,'2014-07-14 15:05:40','backup.test-dir JobId 2653: The following 6 JobIds were chosen to be copied: 2049,2115,2181,2380,2448,2516\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1112-0 Before loop count=6 ids=2049,2115,2181,2380,2448,2516 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1120-0 getJobid_no=1 status=1 JobId=2049 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1215-0 =============== Copying cmd=run job="backup.test.riege.de.copy" jobid=2049 ignoreduplicatecheck=yes 14-Jul-2014 15:05:40 backup.test-dir: ua_run.c:1965-0 Using pool backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: ua_run.c:1983-0 Using next pool backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: job.c:1634-0 wstorage=backup.test.copy.filestorage 14-Jul-2014 15:05:40 backup.test-dir: job.c:1643-0 wstore=backup.test.copy.filestorage where=Job resource 14-Jul-2014 15:05:40 backup.test-dir: job.c:1667-0 wstore=backup.test.filestorage where=Pool resource 14-Jul-2014 15:05:40 backup.test-dir: job.c:1634-0 wstorage=library.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: job.c:1643-0 wstore=library.test.filestorage where=Storage from Run NextPool override 14-Jul-2014 15:05:40 backup.test-dir: ua_run.c:432-0 JobId=0 using pool backup.test.riege.de priority=10 14-Jul-2014 15:05:40 backup.test-dir: message.c:349-0 Copy message resource 24bbc78 to 7f0574015478 14-Jul-2014 15:05:40 backup.test-dir: job.c:1290-0 JobId=0 created Job=backup.test.riege.de.copy.2014-07-14_15.05.40_06 14-Jul-2014 15:05:40 backup.test-dir: job.c:138-0 Open database 14-Jul-2014 15:05:40 backup.test-dir: sql_pooling.c:58-0 db_sql_get_non_pooled_connection allocating 1 new non pooled database connection to database bareos, backend type mysql 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename dbi, partly_compare = true 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename mysql, partly_compare = false 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:747-0 DB REopen bareos 14-Jul-2014 15:05:40 backup.test-dir: job.c:154-0 DB opened 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1160-0 Created Client backup.test.riege.de record 3 14-Jul-2014 15:05:40 backup.test-dir: job.c:190-0 Created job record JobId=2654 Name=backup.test.riege.de.copy.2014-07-14_15.05.40_06 Type=c Level=F 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:299-0 === enter new_plugins === 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:301-0 No dir plugin list! 14-Jul-2014 15:05:40 backup.test-dir: job.c:1039-0 entering apply_pool_overrides() 14-Jul-2014 15:05:40 backup.test-dir: job.c:738-0 get_or_create_pool=backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 20 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=5' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:663-0 Actual NumVols=11 Pool NumVols=11 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:138-0 Read pool=backup.test.riege.de (From Job resource) 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2654,'2014-07-14 15:05:40','backup.test-dir JobId 2654: Warning: FileSet MD5 digest not found.\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='EmptySet' AND MD5=''' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1197-0 Created FileSet EmptySet record 3 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:946-0 At Job start previous jobid=2049 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1151-0 Previous jobid=2049 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=2049' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 23 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2654,'2014-07-14 15:05:40','backup.test-dir JobId 2654: Copying using JobId=2049 Job=backup.test.riege.de.2014-07-04_23.05.01_33\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1166-0 Copying JobId=2654 using JobId=2049 Job=backup.test.riege.de.2014-07-04_23.05.01_33 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:158-0 Back from getJob_to_migrate JobId=2654 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=2049' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 23 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:436-0 VolNam=SELECT VolumeName,MediaType,FirstIndex,LastIndex,StartFile,JobMedia.EndFile,StartBlock,JobMedia.EndBlock,Slot,StorageId,InChanger FROM JobMedia,Media WHERE JobMedia.JobId=2049 AND JobMedia.MediaId=Media.MediaId ORDER BY VolIndex,JobMediaId 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT VolumeName,MediaType,FirstIndex,LastIndex,StartFile,JobMedia.EndFile,StartBlock,JobMedia.EndBlock,Slot,StorageId,InChanger FROM JobMedia,Media WHERE JobMedia.JobId=2049 AND JobMedia.MediaId=Media.MediaId ORDER BY VolIndex,JobMediaId' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 11 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 3 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:439-0 Num rows=3 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT Name from Storage WHERE StorageId=1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT Name from Storage WHERE StorageId=1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT Name from Storage WHERE StorageId=1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2654,'2014-07-14 15:05:40','backup.test-dir JobId 2654: Bootstrap records written to /var/lib/bareos/backup.test-dir.restore.1.bsr\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows Storage="backup.test.filestorage" Volume="backup.test.riege.de.0147" MediaType="backup.test.filestorage" Device="backup.test.filestorage-1" VolSessionId=747 VolSessionTime=1403690585 VolAddr=264-999935939 FileIndex=1-70957 Count=70957 Storage="backup.test.filestorage" Volume="backup.test.riege.de.0147" MediaType="backup.test.filestorage" Device="backup.test.filestorage-1" VolSessionId=747 VolSessionTime=1403690585 VolAddr=999935940-1244023910 FileIndex=70957-70991 Count=35 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:187-0 JobId=2654: Current: Name=backup.test.riege.de.copy JobId=2654 Type=c Level=F 14-Jul-2014 15:05:40 backup.test-dir: job.c:1634-0 wstorage=backup.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: job.c:1643-0 wstore=backup.test.filestorage where=Job resource 14-Jul-2014 15:05:40 backup.test-dir: job.c:1290-0 JobId=0 created Job=backup.test.riege.de.2014-07-14_15.05.40_07 14-Jul-2014 15:05:40 backup.test-dir: job.c:138-0 Open database 14-Jul-2014 15:05:40 backup.test-dir: sql_pooling.c:58-0 db_sql_get_non_pooled_connection allocating 1 new non pooled database connection to database bareos, backend type mysql 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename dbi, partly_compare = true 14-Jul-2014 15:05:40 backup.test-dir: cats_dynamic.c:55-0 db_init_database: Trying to find mapping of given interfacename mysql to mapping interfacename mysql, partly_compare = false 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:747-0 DB REopen bareos 14-Jul-2014 15:05:40 backup.test-dir: job.c:154-0 DB opened 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1160-0 Created Client backup.test.riege.de record 3 14-Jul-2014 15:05:40 backup.test-dir: job.c:190-0 Created job record JobId=2655 Name=backup.test.riege.de.2014-07-14_15.05.40_07 Type=B Level=I 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:299-0 === enter new_plugins === 14-Jul-2014 15:05:40 backup.test-dir: dir_plugins.c:301-0 No dir plugin list! 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT FileSetId,CreateTime FROM FileSet WHERE FileSet='FullSet' AND MD5='O8V3Sls15SlCn4/s7w/aNB'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: job.c:1197-0 Created FileSet FullSet record 1 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT StartTime, Job FROM Job WHERE JobStatus IN ('T','W') AND Type='B' AND Level='F' AND Name='backup.test.riege.de' AND ClientId=3 AND FileSetId=1 ORDER BY StartTime DESC LIMIT 1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT StartTime, Job FROM Job WHERE JobStatus IN ('T','W') AND Type='B' AND Level IN ('I','D','F') AND Name='backup.test.riege.de' AND ClientId=3 AND FileSetId=1 ORDER BY StartTime DESC LIMIT 1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_find.c:132-0 Got start time: 2014-07-13 23:05:02, job: backup.test.riege.de.2014-07-13_23.05.00_57 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT StartTime, Job FROM Job WHERE JobStatus IN ('T','W') AND Type='B' AND Level='F' AND Name='backup.test.riege.de' AND ClientId=3 AND FileSetId=1 ORDER BY StartTime DESC LIMIT 1' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 2 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_find.c:183-0 Got start time: 2014-07-06 23:05:32 14-Jul-2014 15:05:40 backup.test-dir: job.c:957-0 have_full=1 do_full=0 now=1405343140 full_time=1404680732 14-Jul-2014 15:05:40 backup.test-dir: job.c:1032-0 Level=I last start time=2014-07-13 23:05:02 job=backup.test.riege.de.2014-07-13_23.05.00_57 14-Jul-2014 15:05:40 backup.test-dir: job.c:1039-0 entering apply_pool_overrides() 14-Jul-2014 15:05:40 backup.test-dir: job.c:738-0 get_or_create_pool=backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.Name='backup.test.riege.de'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 20 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=5' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:663-0 Actual NumVols=11 Pool NumVols=11 14-Jul-2014 15:05:40 backup.test-dir: job.c:1634-0 wstorage=backup.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: job.c:1643-0 wstore=backup.test.filestorage where=Pool resource 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:256-0 mig_jcr: Name=backup.test.riege.de JobId=2655 Type=B Level=F 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.PoolId=5' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 20 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=5' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:663-0 Actual NumVols=11 Pool NumVols=11 14-Jul-2014 15:05:40 backup.test-dir: job.c:738-0 get_or_create_pool=TL 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.Name='TL'' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 20 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=27' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:473-0 we have 1 fields 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:475-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: sql_get.c:663-0 Actual NumVols=1 Pool NumVols=1 14-Jul-2014 15:05:40 backup.test-dir: job.c:1634-0 wstorage=library.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: job.c:1643-0 wstore=library.test.filestorage where=Storage from Pool's NextPool resource 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:362-0 Write pool=TL read rpool=backup.test.riege.de 14-Jul-2014 15:05:40 backup.test-dir: job.c:81-0 Add jrc to work queue 14-Jul-2014 15:05:40 backup.test-dir: ua_run.c:438-0 JobId=2654 NewJobId=2654 using pool TL priority=10 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2653,'2014-07-14 15:05:40','backup.test-dir JobId 2653: Job queued. JobId=2654\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:750-0 Rstore=backup.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:812-0 Inc rncj=2 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:759-0 Wstore=library.test.filestorage 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:762-0 Inc wncj=1 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:837-0 Dec wncj=0 14-Jul-2014 15:05:40 backup.test-dir: jobq.c:826-0 Dec rncj=1 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:453-0 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2653,'2014-07-14 15:05:40','backup.test-dir JobId 2653: Copying JobId 2654 started.\n\0')' 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:468-0 we have a result 14-Jul-2014 15:05:40 backup.test-dir: mysql.c:484-0 we have 1 rows 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1133-0 Back from start_migration_job 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1120-0 getJobid_no=2 status=1 JobId=2115 14-Jul-2014 15:05:40 backup.test-dir: migrate.c:1215-0 =============== Copying cmd=run job="backup.test.riege.de.copy" jobid=2115 ignoreduplicatecheck=yes Job Start: 14-Jul-2014 15:12:11 backup.test-dir: job.c:334-2654 =====Start Job========= 14-Jul-2014 15:12:11 backup.test-dir: job.c:352-2654 Warning, job->RunScripts is empty 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:453-2654 sql_query starts with 'UPDATE Job SET JobStatus='R',Level='F',StartTime='2014-07-14 15:12:11',ClientId=3,JobTDate=1405343531,PoolId=27,FileSetId=3 WHERE JobId=2654' 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:484-2654 we have 1 rows 14-Jul-2014 15:12:11 backup.test-dir: runscript.c:149-2654 runscript: running all RUNSCRIPT object (BeforeJob) JobStatus=R 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:453-2654 sql_query starts with 'UPDATE Job SET JobStatus='R',Level='F',StartTime='2014-07-14 15:12:11',ClientId=3,JobTDate=1405343531,PoolId=27,FileSetId=3 WHERE JobId=2654' 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:484-2654 we have 1 rows 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:453-2654 sql_query starts with 'SELECT VolSessionId,VolSessionTime,PoolId,StartTime,EndTime,JobFiles,JobBytes,JobTDate,Job,JobStatus,Type,Level,ClientId,Name,PriorJobId,RealEndTime,JobId,FileSetId,SchedTime,RealEndTime,ReadBytes,HasBase,PurgedFiles FROM Job WHERE JobId=2049' 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:473-2654 we have 23 fields 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:475-2654 we have 1 rows 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:453-2654 sql_query starts with 'INSERT INTO Log (JobId, Time, LogText) VALUES (2654,'2014-07-14 15:12:11','backup.test-dir JobId 2654: Start Copying JobId 2654, Job=backup.test.riege.de.copy.2014-07-14_15.05.40_06\n\0')' 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:11 backup.test-dir: mysql.c:484-2654 we have 1 rows 14-Jul-2014 15:12:11 backup.test-dir: migrate.c:421-2654 Read store=backup.test.filestorage, write store=library.test.filestorage 14-Jul-2014 15:12:11 backup.test-dir: migrate.c:427-2654 Open connection with storage daemon 14-Jul-2014 15:12:11 backup.test-dir: sd_cmds.c:102-2654 bnet_connect to Storage daemon 10.11.6.32:9103 14-Jul-2014 15:12:11 backup.test-dir: bsock.c:168-2654 All source addresses 14-Jul-2014 15:12:11 backup.test-dir: bsock.c:244-2654 Current host[ipv4:10.11.6.32:9103] All host[ipv4:10.11.6.32:9103] 14-Jul-2014 15:12:11 backup.test-dir: bsock.c:150-2654 who=Storage daemon host=10.11.6.32 port=9103 14-Jul-2014 15:12:11 backup.test-dir: cram-md5.c:123-2654 cram-get received: auth cram-md5 <87259199.1405343531@backup.test-sd> ssl=0 14-Jul-2014 15:12:11 backup.test-dir: cram-md5.c:142-2654 sending resp to challenge: tR+AqnUrb+/Wl14nB//NyB 14-Jul-2014 15:12:11 backup.test-dir: cram-md5.c:71-2654 send: auth cram-md5 <1790374427.1405343531@backup.test-dir> ssl=0 14-Jul-2014 15:12:11 backup.test-dir: cram-md5.c:90-2654 Authenticate OK C94Mk5+Wt38zO5JepiZ3xA 14-Jul-2014 15:12:11 backup.test-dir: authenticate.c:163-2654 >stored: 1000 OK auth 14-Jul-2014 15:12:11 backup.test-dir: authenticate.c:170-2654 stored: JobId=2654 job=backup.test.riege.de.copy.2014-07-14_15.05.40_06 job_name=backup.test.riege.de.copy client_name=backup.test.riege.de type=99 level=70 FileSet=EmptySet NoAttr=0 SpoolAttr=1 FileSetMD5=**Dummy** SpoolData=0 PreferMountedVols=1 SpoolSize=0 rerunning=0 VolSessionId=0 VolSessi onTime=0 Quota=0 Protocol=0 BackupFormat=Native DumpLevel=0 14-Jul-2014 15:12:11 backup.test-dir: getmsg.c:135-2654 bget_dirmsg 91: 3000 OK Job SDid=2 SDtime=1405343129 Authorization=PPCN-EAEA-HPJH-IDNE-JNHH-GHKA-HKDF-CNPA 14-Jul-2014 15:12:11 backup.test-dir: msgchan.c:200-2654 stored: use storage=backup.test.filestorage media_type=backup.test.filestorage pool_name=backup.test.riege.de pool_type=Backup append=0 copy=0 stripe=0 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-1 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-2 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-3 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-4 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-5 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-6 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-7 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-8 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-9 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:259-2654 >stored: use device=backup.test.filestorage-10 14-Jul-2014 15:12:12 backup.test-dir: getmsg.c:135-2654 bget_dirmsg 52: 3000 OK use device device=backup.test.filestorage-1 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:265-2654 stored: use storage=library.test.filestorage media_type=library.test.filestorage pool_name=TL pool_type=Backup append=1 copy=0 stripe=0 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:297-2654 >stored: use device=library.test.filestorage-1 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:297-2654 >stored: use device=library.test.filestorage-2 14-Jul-2014 15:12:12 backup.test-dir: getmsg.c:135-2654 bget_dirmsg 121: CatReq Job=backup.test.riege.de.copy.2014-07-14_15.05.40_06 FindMedia=1 pool_name=TL media_type=library.test.filestorage 14-Jul-2014 15:12:12 backup.test-dir: catreq.c:122-2654 catreq CatReq Job=backup.test.riege.de.copy.2014-07-14_15.05.40_06 FindMedia=1 pool_name=TL media_type=library.test.filestorage 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:453-2654 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge FROM Pool WHERE Pool.Name='TL'' 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:473-2654 we have 20 fields 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:475-2654 we have 1 rows 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:453-2654 sql_query starts with 'SELECT count(*) from Media WHERE PoolId=27' 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:473-2654 we have 1 fields 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:475-2654 we have 1 rows 14-Jul-2014 15:12:12 backup.test-dir: sql_get.c:663-2654 Actual NumVols=1 Pool NumVols=1 14-Jul-2014 15:12:12 backup.test-dir: next_vol.c:64-2654 find_next_vol_for_append: JobId=2654 PoolId=27, MediaType=library.test.filestorage 14-Jul-2014 15:12:12 backup.test-dir: sql_find.c:374-2654 fnextvol=SELECT MediaId,VolumeName,VolJobs,VolFiles,VolBlocks,VolBytes,VolMounts,VolErrors,VolWrites,MaxVolBytes,VolCapacityBytes,MediaType,VolStatus,PoolId,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,Recycle,Slot,FirstWritten,LastWritten,InChanger,EndFile,EndBlock,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,EncryptionKey FROM Media WHERE PoolId=27 AND MediaType='library.test.filestorage' AND Enabled=1 AND VolStatus='Append' ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:453-2654 sql_query starts with 'SELECT MediaId,VolumeName,VolJobs,VolFiles,VolBlocks,VolBytes,VolMounts,VolErrors,VolWrites,MaxVolBytes,VolCapacityBytes,MediaType,VolStatus,PoolId,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,Recycle,Slot,FirstWritten,LastWritten,InChanger,EndFile,EndBlock,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,EncryptionKey FROM Media WHERE PoolId=27 AND MediaType='library.test.filestorage' AND Enabled=1 AND VolStatus='Append' ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1' 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:468-2654 we have a result 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:473-2654 we have 38 fields 14-Jul-2014 15:12:12 backup.test-dir: mysql.c:475-2654 we have 1 rows 14-Jul-2014 15:12:12 backup.test-dir: sql_find.c:451-2654 Rtn numrows=1 14-Jul-2014 15:12:12 backup.test-dir: next_vol.c:176-2654 VolJobs=1 FirstWritten=1405338932 14-Jul-2014 15:12:12 backup.test-dir: next_vol.c:264-2654 Vol=library.test.0869 expired=0 14-Jul-2014 15:12:12 backup.test-dir: next_vol.c:191-2654 return ok=1 find_next_vol 14-Jul-2014 15:12:12 backup.test-dir: catreq.c:144-2654 find_media ok=1 idx=1 vol=library.test.0869 14-Jul-2014 15:12:12 backup.test-dir: catreq.c:97-2654 Vol Info for backup.test.riege.de.copy.2014-07-14_15.05.40_06: 1000 OK VolName=library.test.0869 VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=239 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=4000000000 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=27 EndFile=0 EndBlock=0 LabelType=0 MediaId=869 EncryptionKey= 14-Jul-2014 15:12:12 backup.test-dir: catreq.c:360-2654 >CatReq response: 1000 OK VolName=library.test.0869 VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=239 VolMounts=1 VolErrors=0 VolWrites=1 MaxVolBytes=4000000000 VolCapacityBytes=0 VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=27 EndFile=0 EndBlock=0 LabelType=0 MediaId=869 EncryptionKey= 14-Jul-2014 15:12:12 backup.test-dir: catreq.c:361-2654 Leave catreq jcr 0x740132d8 14-Jul-2014 15:12:12 backup.test-dir: getmsg.c:135-2654 bget_dirmsg 53: 3000 OK use device device=library.test.filestorage-1 14-Jul-2014 15:12:12 backup.test-dir: msgchan.c:303-2654