[Bacula-bugs] [Bacula Bug Reports 0002103]: The status storage command reports "Writing" for the source of a copy job

[Mantis B. T. <no...@bu...>]

The following issue has been ASSIGNED. 
====================================================================== 
http://bugs.bacula.org/view.php?id=2103 
====================================================================== 
Reported By:                martin
Assigned To:                ebollengier
====================================================================== 
Project:                    Bacula Bug Reports
Issue ID:                   2103
Category:                   Storage Daemon
Reproducibility:            always
Severity:                   minor
Priority:                   normal
Status:                     feedback
====================================================================== 
Date Submitted:             2014-09-25 14:25 BST
Last Modified:              2014-11-19 07:44 GMT
====================================================================== 
Summary:                    The status storage command reports "Writing" for the
source of a copy job
Description: 
I was running a copy job from volume DailyDisk001 to volume TestCopy.  During
the run, the status storage command below reported "Writing:" for DailyDisk001
under Running Jobs, but the volume is only being read.


*status storage=backupserver1-File
Connecting to Storage daemon backupserver1-File at vmserver1:9103

backupserver1-sd Version: 7.0.5 (28 July 2014) x86_64-unknown-freebsd10.0
freebsd 10.0-RELEASE-p7
Daemon started 25-Sep-14 12:36. Jobs: run=4, running=1.
 Heap: heap=0 smbytes=924,665 max_bytes=971,531 bufs=196 max_bufs=213
 Sizes: boffset_t=8 size_t=8 int32_t=4 int64_t=8 mode=0,0

Running Jobs:
Writing: Differential Backup job lwfs1-cam-users JobId=51449 Volume="TestCopy"
    pool="YearlyCopyPool" device="FileStorage-Dev2" (/var/bacula/volumes)
    spooling=0 despooling=0 despool_wait=0
    Files=192 Bytes=693,797,099 AveBytes/sec=69,379,709 LastBytes/sec=69,379,709
    FDReadSeqNo=32,274 in_msg=31782 out_msg=5 fd=6
Reading: Full Copy job CopyMonthly JobId=51448 Volume="DailyDisk001"
    pool="DailyPool" device="FileStorage-Dev1" (/var/bacula/volumes)
Writing: Full Copy job CopyMonthly JobId=51448 Volume="DailyDisk001"
    pool="DailyPool" device="FileStorage-Dev1" (/var/bacula/volumes)
    spooling=0 despooling=0 despool_wait=0
    Files=192 Bytes=694,219,710 AveBytes/sec=69,421,971 LastBytes/sec=69,421,971
    FDReadSeqNo=4 in_msg=4 out_msg=32290 fd=7
====

Jobs waiting to reserve a drive:
====

Terminated Jobs:
 JobId  Level    Files      Bytes   Status   Finished        Name 
===================================================================
 51305              247    999.3 K  OK       25-Sep-14 11:26
Verify-lwfs1-cam-hope
 51306           17,691    256.7 M  OK       25-Sep-14 11:27
Verify-lwfs1-cam-source-active
 51307              534    2.146 M  OK       25-Sep-14 11:27
Verify-lwfs1-cam-source-inactive
 51308                1    651.3 M  OK       25-Sep-14 11:27
Verify-BackupCatalog
 51313  Full          0         0   Cancel   25-Sep-14 11:47 PlayTime
 51312  Full          0         0   Cancel   25-Sep-14 11:47 CopyMonthly
 51317  Diff          0         0   Cancel   25-Sep-14 13:30 lwfs1-cam-users
 51316  Full          5    161.1 K  Cancel   25-Sep-14 13:30 CopyMonthly
 51319  Diff          0         0   Cancel   25-Sep-14 13:32 lwfs1-cam-hope
 51318  Full          8    144.3 K  Cancel   25-Sep-14 13:32 CopyMonthly
====

Device status:
Autochanger "FileStorage" with devices:
   "FileStorage-Dev1" (/var/bacula/volumes)
   "FileStorage-Dev2" (/var/bacula/volumes)

Device "FileStorage-Dev1" (/var/bacula/volumes) is mounted with:
    Volume:      DailyDisk001
    Pool:        YearlyCopyPool
    Media type:  File
    Total Bytes Read=695,052,288 Blocks Read=10,774 Bytes/block=64,512
    Positioned at File=0 Block=695,052,481
==

Device "FileStorage-Dev2" (/var/bacula/volumes) is mounted with:
    Volume:      TestCopy
    Pool:        YearlyCopyPool
    Media type:  File
    Total Bytes=694,600,894 Blocks=10,767 Bytes/block=64,512
    Positioned at File=0 Block=694,600,893
==
====

Used Volume status:
Reserved volume: TestCopy on file device "FileStorage-Dev2"
(/var/bacula/volumes)
    Reader=0 writers=1 reserves=0 volinuse=1
Volume: DailyDisk001 no device. volinuse=0
====

Attr spooling: 1 active jobs, 0 bytes; 0 total jobs, 0 max bytes.
====

*
====================================================================== 

---------------------------------------------------------------------- 
 (0007053) ebollengier (administrator) - 2014-11-19 07:44
 http://bugs.bacula.org/view.php?id=2103#c7053 
---------------------------------------------------------------------- 
The output of the storage command is really strange, can you attach your copy
job definition, the pool definition and the list of your media?

I would advise to use an other pool to copy your data, and very likely to add
more Devices in your Autochanger resource. 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2014-09-25 14:25 martin         New Issue                                    
2014-11-19 07:44 ebollengier    Note Added: 0007053                          
2014-11-19 07:44 ebollengier    Assigned To               => ebollengier     
2014-11-19 07:44 ebollengier    Status                   new => feedback     
======================================================================