Resposta incorreta ao comando Storage - queria que o 2000 tivesse 2800 - Job TermCode = 69

Navegue suas respostas
3

Vou tentar explicar o problema que estou enfrentando:

Quando eu restauro o backup de um cliente que usa dois "volumes", recebo este erro: 

bacula-dir JobId 48945: Fatal error: Bad response to Storage command: wanted 2000 OK storage, got 2800 End Job TermCode=69 JobFiles=32293 ReadBytes=8946396913 JobBytes=10298059235 Errors=1 VSS=0 Encrypt=0 CommBytes=232 CompressCommBytes=232

Eu tentei encontrar uma solução para esse problema. Algumas pessoas dizem que é um erro do NFS, mas só ocorre quando a restauração atinge mais de um volume.

Se eu executar um trabalho de restauração a partir de um único volume, a restauração funcionará bem.

Quando executo bacula-fd no modo de depuração ( bacula-fd -v -c /etc/bacula/bacula-fd.conf -f -d 100 ), a saída é: 

bacula: restore.c:540-49097 === msglen=155 attrExlen=0 msg=287476 3 /var/www/midomain.com/shared/src/uploads/downloads/eusk706.mp3
bacula: create_file.c:208-49097 Create=/tmp/bacula-restores/var/www/midomain.com/shared/src/uploads/downloads/eusk706.mp3
bacula: attribs.c:558-49097 File size of restored file /tmp/bacula-restores/var/www/midomain.com/shared/src/uploads/downloads/eusk706.mp3 not correct. Original 2581274, restored 131072.
bacula: restore.c:1034-49097 End Do Restore. Files=19300 Bytes=7333538565
bacula: heartbeat.c:141-49097 Send kill to heartbeat id
bacula: job.c:2534-49097 filed>stored: read close session 160
bacula: job.c:2548-49097 Done in job.c
bacula: job.c:2551-49097 2000 OK storage end
bacula: job.c:2576-49097 end_restore_cmd
bacula: job.c:333-49097 Quit command loop. Canceled=1
bacula: job.c:456-49097 Calling term_find_files
bacula: job.c:459-49097 Done with term_find_files
bacula: jcr.c:174-49097 write_last_jobs seek to 192
bacula: job.c:462-0 Done with free_jcr

Isso pode ser causado por um erro de configuração? Alguma outra opção?

Eu comecei a ter esse problema no Bacula 7.0.4. Eu atualizei o Bacula para a versão 9.0.5, mas o problema ainda persiste.

Os clientes estão localizados em redes diferentes e eu tenho um armazenamento configurado para cada rede.

Arquivos de configuração:

Cliente 

Client {
    Name = myServer
    Address = 192.168.2.222
    Catalog = MyCatalog
    Password = "***"
    File Retention = 15 days
    Job Retention = 15 days
    Autoprune = yes
    Maximum Concurrent Jobs = 6
}

Job {
    Name = "myServer"
    Type = Backup
    Client = myServer
    FileSet = "myServer"
    Storage = FileRedDos
    Messages = Standard
    Pool = File
    Schedule = Miercoles
    Maximum Concurrent Jobs = 4
}

FileSet {
    Name = "myServer"
    Include {
        File = /var/www
        File = /etc
        Options {
            signature = MD5
            compression = GZIP
        }
    }
    Exclude {
    }
}

Armazenamento 

Storage {
    Name = FileRedDos
    Address = 192.168.2.25
    SDPort = 9103
    Password = "***"
    Device = Freenas
    Media Type = File
    Maximum Concurrent Jobs = 20
}

Pool 

Pool {
    Name = File
    Pool Type = Backup
    Recycle = yes
    AutoPrune = yes
    Volume Retention = 30 days
    Maximum Volume Bytes = 10G
    Maximum Volumes = 1000
    Label Format = "VolBacula-"
}

Agenda 

Schedule {
    Name = Miercoles
    Run = Full wednesday at 03:00
    Run = Incremental thursday-tuesday at 01:00
}

Dispositivo 

Device {
  Name = Freenas
  Media Type = File
  Archive Device = /backup/baculaVolumes
  LabelMedia = yes;
  Random Access = Yes;
  RemovableMedia = no;
  Maximum Concurrent Jobs = 20
}

EDITAR:

Option 1 - Configuration error

Firstly, have you done a restore before with this configuration?

Sim, até agora tudo funcionou bem, pudemos recuperar qualquer servidor.

Nosso trabalho de restauração: 

Job {
  Name = "RestoreFiles"
  Type = Restore
  Client=bacula-fd
  FileSet="Full Set"
  Storage = File
  Pool = File
  Messages = Standard
  Where = /tmp/bacula-restores
}

Option 2 - Protocol Error

from inconsistent name resolution (e.g. server and client have different ideas about what the name of each is), or

Os servidores de nomes e os IPs não foram alterados. De qualquer forma, eu posso restaurar alguns arquivos, ele só trava quando o armazenamento de volume muda.

protocol errors (e.g. or one is set for IPv4 whereas the other defaults to IPv6) or

Nós não mudamos nada sobre o protocolo IPv. Todos os arquivos de configuração têm apenas IPs IPv4, não usamos a resolução de DNS.

version errors (server and client need to be compatible versions)

Todas as versões do cliente são 7.0.5 (28 July 2014) e as versões do servidor ( fd , sd , dir ) são: 9.0.5 (02 November 2017)

There has been discussion about this particular scenario on the mailing list but, from my experience, it always boils down to one of these 3 (or 4) things.

Nós lemos alguns sobre isso, mas não encontramos nenhuma solução.

EDIT 2 - Tudo em depuração -:

can you include logs before Fatal Error server-side

erro bacula-fd: 

bacula: restore.c:540-50582 === msglen=163 attrExlen=0 msg=293522 3 /var/www/myhostname/shared/src/uploads/2012/05/frChicago_Built_0853_GP_PR.jpeg
bacula: create_file.c:208-50582 Create=/tmp/bacula-restores/var/www/myhostname/shared/src/uploads/2012/05/frChicago_Built_0853_GP_PR.jpeg
bacula: attribs.c:558-50582 File size of restored file /tmp/bacula-restores/var/www/myhostname/shared/src/uploads/2012/05/frChicago_Built_0853_GP_PR.jpeg not correct. Original 245356, restored 196608.
bacula: restore.c:1034-50582 End Do Restore. Files=28688 Bytes=9807931793
bacula: heartbeat.c:141-50582 Send kill to heartbeat id
bacula: job.c:2534-50582 filed>stored: read close session 1
bacula: job.c:2548-50582 Done in job.c
bacula: job.c:2551-50582 2000 OK storage end
bacula: job.c:2576-50582 end_restore_cmd
bacula: job.c:333-50582 Quit command loop. Canceled=1
bacula: job.c:456-50582 Calling term_find_files
bacula: job.c:459-50582 Done with term_find_files
bacula: jcr.c:174-50582 write_last_jobs seek to 192
bacula: job.c:462-0 Done with free_jcr

erro bacula-dir:

Não aparece um erro, eu anexei alguns traços: 

bacula-dir: mysql.c:113-0 DB REopen bacula
bacula-dir: next_vol.c:111-0 find_next_vol_for_append: JobId=0 PoolId=2, MediaType=File index=1 create=0 prune=0
bacula-dir: sql_find.c:454-0 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,VolType,VolParts,VolCloudParts,LastPartBytes,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,CacheRetention FROM Media WHERE PoolId=2 AND MediaType='File' AND Enabled=1 AND VolStatus='Append'    ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1
bacula-dir: sql_find.c:536-0 Rtn numrows=1
bacula-dir: next_vol.c:227-0 VolJobs=4 FirstWritten=1511755556
bacula-dir: next_vol.c:320-0 Vol=VolBacula-0315 expired=0
bacula-dir: next_vol.c:242-0 return ok=1 find_next_vol
bacula-dir: mysql.c:325-0 closedb ref=1 connected=1 db=7f9bd404ca80
bacula-dir: job.c:1760-0 wstorage=FileRedDos
bacula-dir: job.c:1769-0 wstore=FileRedDos where=Job resource
bacula-dir: ua_output.c:938-0 complete_jcr open db
bacula-dir: mysql.c:113-0 DB REopen bacula
bacula-dir: next_vol.c:111-0 find_next_vol_for_append: JobId=0 PoolId=2, MediaType=File index=1 create=0 prune=0
bacula-dir: sql_find.c:454-0 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,VolType,VolParts,VolCloudParts,LastPartBytes,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,CacheRetention FROM Media WHERE PoolId=2 AND MediaType='File' AND Enabled=1 AND VolStatus='Append'    ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1
bacula-dir: sql_find.c:536-0 Rtn numrows=1
bacula-dir: next_vol.c:227-0 VolJobs=4 FirstWritten=1511755556
bacula-dir: next_vol.c:320-0 Vol=VolBacula-0315 expired=0
bacula-dir: next_vol.c:242-0 return ok=1 find_next_vol
bacula-dir: mysql.c:325-0 closedb ref=1 connected=1 db=7f9bd404ca80
bacula-dir: job.c:1760-0 wstorage=FileRedTres
bacula-dir: job.c:1769-0 wstore=FileRedTres where=Job resource
bacula-dir: ua_output.c:938-0 complete_jcr open db
bacula-dir: mysql.c:113-0 DB REopen bacula
bacula-dir: next_vol.c:111-0 find_next_vol_for_append: JobId=0 PoolId=2, MediaType=File index=1 create=0 prune=0
bacula-dir: sql_find.c:454-0 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,VolType,VolParts,VolCloudParts,LastPartBytes,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,CacheRetention FROM Media WHERE PoolId=2 AND MediaType='File' AND Enabled=1 AND VolStatus='Append'    ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1
bacula-dir: sql_find.c:536-0 Rtn numrows=1
bacula-dir: next_vol.c:227-0 VolJobs=4 FirstWritten=1511755556
bacula-dir: next_vol.c:320-0 Vol=VolBacula-0315 expired=0
bacula-dir: next_vol.c:242-0 return ok=1 find_next_vol
bacula-dir: mysql.c:325-0 closedb ref=1 connected=1 db=7f9bd404ca80
bacula-dir: job.c:1760-0 wstorage=FileRedDos
bacula-dir: job.c:1769-0 wstore=FileRedDos where=Job resource
bacula-dir: ua_output.c:938-0 complete_jcr open db
bacula-dir: mysql.c:113-0 DB REopen bacula
bacula-dir: next_vol.c:111-0 find_next_vol_for_append: JobId=0 PoolId=2, MediaType=File index=1 create=0 prune=0
bacula-dir: sql_find.c:454-0 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,VolType,VolParts,VolCloudParts,LastPartBytes,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,CacheRetention FROM Media WHERE PoolId=2 AND MediaType='File' AND Enabled=1 AND VolStatus='Append'    ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1
bacula-dir: sql_find.c:536-0 Rtn numrows=1
bacula-dir: next_vol.c:227-0 VolJobs=4 FirstWritten=1511755556
bacula-dir: next_vol.c:320-0 Vol=VolBacula-0315 expired=0
bacula-dir: next_vol.c:242-0 return ok=1 find_next_vol
bacula-dir: mysql.c:325-0 closedb ref=1 connected=1 db=7f9bd404ca80
bacula-dir: job.c:1760-0 wstorage=FileRedDos
bacula-dir: job.c:1769-0 wstore=FileRedDos where=Job resource
bacula-dir: ua_output.c:938-0 complete_jcr open db
bacula-dir: mysql.c:113-0 DB REopen bacula
bacula-dir: next_vol.c:111-0 find_next_vol_for_append: JobId=0 PoolId=2, MediaType=File index=1 create=0 prune=0
bacula-dir: sql_find.c:454-0 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,VolType,VolParts,VolCloudParts,LastPartBytes,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge,CacheRetention FROM Media WHERE PoolId=2 AND MediaType='File' AND Enabled=1 AND VolStatus='Append'    ORDER BY LastWritten IS NULL,LastWritten DESC,MediaId LIMIT 1
bacula-dir: sql_find.c:536-0 Rtn numrows=1
bacula-dir: next_vol.c:227-0 VolJobs=4 FirstWritten=1511755556
bacula-dir: next_vol.c:320-0 Vol=VolBacula-0315 expired=0
bacula-dir: next_vol.c:242-0 return ok=1 find_next_vol
bacula-dir: mysql.c:325-0 closedb ref=1 connected=1 db=7f9bd404ca80
bacula-dir: job.c:1760-0 wstorage=FileRedDos
bacula-dir: job.c:1769-0 wstore=FileRedDos where=Job resource
bacula-dir: ua_output.c:938-0 complete_jcr open db

erro bacula-sd

Eu anexei você all log: 

bacula-sd: label.c:987-50582 reclen=195 recdata=Bacula 1.0 immortal
bacula-sd: label.c:989-50582 reclen=195 recdata=Bacula 1.0 immortal

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : VolBacula-0553
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 195
PoolName          : File
MediaType         : File
PoolType          : Backup
HostName          : myhostname
Date label written: 12-jun-2016 00:56
bacula-sd: label.c:1027-50582 Leave: bool unser_volume_label(DEVICE*, DEV_RECORD*)
bacula-sd: label.c:149-50582 VolHdr.Id OK: Bacula 1.0 immortal

bacula-sd: label.c:188-50582 VolHdr.VerNum=11 OK.

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : VolBacula-0553
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 195
PoolName          : File
MediaType         : File
PoolType          : Backup
HostName          : myhostname
Date label written: 12-jun-2016 00:56
bacula-sd: label.c:258-50582 Leave read_volume_label() VOL_OK
bacula-sd: file_dev.c:71-50582 Enter: virtual bool DEVICE::rewind(DCR*)
bacula-sd: label.c:271-50582 Call reserve_volume=VolBacula-0553
bacula-sd: label.c:284-50582 Leave: virtual int DEVICE::read_dev_volume_label(DCR*)
bacula-sd: acquire.c:246-50582 Got correct volume. VOL_OK: VolBacula-0553
bacula-sd: acquire.c:354-50582 dcr=7fc86c008c48 dev=7fc86c001208
bacula-sd: acquire.c:355-50582 MediaType dcr=File dev=File
bacula-sd: acquire.c:357-50582 Leave: bool acquire_device_for_read(DCR*)
bacula-sd: file_dev.c:107-50582 ===== lseek to 6001227206
bacula-sd: file_dev.c:107-50582 ===== lseek to 6999808230
bacula-sd: file_dev.c:107-50582 ===== lseek to 8999744649
bacula-sd: file_dev.c:107-50582 ===== lseek to 9999422519
bacula-sd: block.c:563-50582 block.c:560 Read zero bytes Vol=VolBacula-0553 at 10737375259 on device "Freenas" (/backup/baculaVolumes).
bacula-sd: block.c:563-50582 block.c:560 Read zero bytes Vol=VolBacula-0553 at 10737375259 on device "Freenas" (/backup/baculaVolumes).
bacula-sd: mount.c:858-50582 NumReadVolumes=2 CurReadVolume=1
bacula-sd: dev.c:271-50582 close_dev vol=VolBacula-0553 fd=7 dev=7fc86c001208 adata=0 dev="Freenas" (/backup/baculaVolumes)
bacula-sd: file_dev.c:71-50582 Enter: virtual bool DEVICE::rewind(DCR*)
bacula-sd: dev.c:252-50582 Clear volhdr vol=VolBacula-0553
bacula-sd: acquire.c:54-50582 Enter: bool acquire_device_for_read(DCR*)
bacula-sd: acquire.c:58-50582 dcr=7fc86c008c48 dev=7fc86c001208
bacula-sd: acquire.c:59-50582 MediaType dcr=File dev=File
bacula-sd: acquire.c:92-50582 Want Vol=VolBacula-0294 Slot=0
bacula-sd: acquire.c:106-50582 MediaType dcr=File dev=File
bacula-sd: acquire.c:183-50582 MediaType dcr=File dev=File
bacula-sd: acquire.c:200-50582 dir_get_volume_info vol=VolBacula-0294
bacula-sd: mount.c:636-50582 No swap_dev set. dev->vol=0
bacula-sd: mount.c:591-50582 Must load dev="Freenas" (/backup/baculaVolumes)
bacula-sd: autochanger.c:105-50582 Device "Freenas" (/backup/baculaVolumes) is not an autochanger
bacula-sd: acquire.c:231-50582 open vol=VolBacula-0294
bacula-sd: file_dev.c:138-50582 Enter: virtual bool file_dev::open_device(DCR*, int)
bacula-sd: file_dev.c:184-50582 open disk: mode=OPEN_READ_ONLY open(/backup/baculaVolumes/VolBacula-0294, 0x0, 0640)
bacula-sd: file_dev.c:194-50582 Did open(/backup/baculaVolumes/VolBacula-0294,OPEN_READ_ONLY,0640)
bacula-sd: file_dev.c:211-50582 open dev: disk fd=7 opened
bacula-sd: file_dev.c:214-50582 Leave: virtual bool file_dev::open_device(DCR*, int)
bacula-sd: acquire.c:239-50582 opened dev "Freenas" (/backup/baculaVolumes) OK
bacula-sd: acquire.c:242-50582 calling read-vol-label
bacula-sd: label.c:72-50582 Enter: virtual int DEVICE::read_dev_volume_label(DCR*)
bacula-sd: label.c:75-50582 Enter read_volume_label adata=0 res=1 device="Freenas" (/backup/baculaVolumes) vol=VolBacula-0294 dev_Vol=*NULL*
bacula-sd: file_dev.c:71-50582 Enter: virtual bool DEVICE::rewind(DCR*)
bacula-sd: label.c:970-50582 Enter: bool unser_volume_label(DEVICE*, DEV_RECORD*)
bacula-sd: label.c:987-50582 reclen=195 recdata=Bacula 1.0 immortal
bacula-sd: label.c:989-50582 reclen=195 recdata=Bacula 1.0 immortal

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : VolBacula-0294
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 195
PoolName          : File
MediaType         : File
PoolType          : Backup
HostName          : myhostname
Date label written: 22-may-2016 19:10
bacula-sd: label.c:1027-50582 Leave: bool unser_volume_label(DEVICE*, DEV_RECORD*)
bacula-sd: label.c:149-50582 VolHdr.Id OK: Bacula 1.0 immortal

bacula-sd: label.c:188-50582 VolHdr.VerNum=11 OK.

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : VolBacula-0294
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 195
PoolName          : File
MediaType         : File
PoolType          : Backup
HostName          : myhostname
Date label written: 22-may-2016 19:10
bacula-sd: label.c:258-50582 Leave read_volume_label() VOL_OK
bacula-sd: file_dev.c:71-50582 Enter: virtual bool DEVICE::rewind(DCR*)
bacula-sd: label.c:271-50582 Call reserve_volume=VolBacula-0294
bacula-sd: label.c:284-50582 Leave: virtual int DEVICE::read_dev_volume_label(DCR*)
bacula-sd: acquire.c:246-50582 Got correct volume. VOL_OK: VolBacula-0294
bacula-sd: acquire.c:354-50582 dcr=7fc86c008c48 dev=7fc86c001208
bacula-sd: acquire.c:355-50582 MediaType dcr=File dev=File
bacula-sd: acquire.c:357-50582 Leave: bool acquire_device_for_read(DCR*)
bacula-sd: label.c:970-50582 Enter: bool unser_volume_label(DEVICE*, DEV_RECORD*)
bacula-sd: label.c:987-50582 reclen=195 recdata=Bacula 1.0 immortal
bacula-sd: label.c:989-50582 reclen=195 recdata=Bacula 1.0 immortal

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : VolBacula-0294
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 195
PoolName          : File
MediaType         : File
PoolType          : Backup
HostName          : myhostname
Date label written: 22-may-2016 19:10
bacula-sd: label.c:1027-50582 Leave: bool unser_volume_label(DEVICE*, DEV_RECORD*)
bacula-sd: file_dev.c:107-50582 ===== lseek to 129255
bacula-sd: file_dev.c:107-50582 ===== lseek to 1999987714
bacula-sd: file_dev.c:107-50582 ===== lseek to 3999924136
bacula-sd: file_dev.c:107-50582 ===== lseek to 4999795602
bacula-sd: file_dev.c:107-50582 ===== lseek to 5999731550
bacula-sd: file_dev.c:107-50582 ===== lseek to 6999602969
bacula-sd: file_dev.c:107-50582 ===== lseek to 9999604340
bacula-sd: mount.c:858-50582 NumReadVolumes=2 CurReadVolume=2
bacula-sd: mount.c:878-50582 End of Device reached.
bacula-sd: acquire.c:490-50582 release_device device "Freenas" (/backup/baculaVolumes) is disk
bacula-sd: askdir.c:452-50582 Update cat VolBytes=10737363502 VolABytes=0 Status=Full Vol=VolBacula-0294
bacula-sd: askdir.c:491-50582 >dird CatReq JobId=50582 UpdateMedia VolName=VolBacula-0294 VolJobs=1 VolFiles=2 VolBlocks=166440 VolBytes=10737363502 VolABytes=0 VolHoleBytes=0 VolHoles=0 VolMounts=25 VolErrors=0 VolWrites=3328862 MaxVolBytes=10737418240 EndTime=1511797676 VolStatus=Full Slot=0 relabel=0 InChanger=0 VolReadTime=65066085 VolWriteTime=4039786913 VolFirstWritten=0 VolType=1 VolParts=0 VolCloudParts=0 LastPartBytes=0 Enabled=1
bacula-sd: askdir.c:506-50582 get_volume_info() 1000 OK VolName=VolBacula-0294 VolJobs=1 VolFiles=2 VolBlocks=166440 VolBytes=10737363502 VolABytes=0 VolHoleBytes=0 VolHoles=0 VolMounts=25 VolErrors=0 VolWrites=3328862 MaxVolBytes=10737418240 VolCapacityBytes=0 VolStatus=Full Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=65066085 VolWriteTime=4039786913 EndFile=2 EndBlock=2101947949 VolType=1 LabelType=0 MediaId=294 ScratchPoolId=0 VolParts=0 VolCloudParts=0 LastPartBytes=0 Enabled=1
bacula-sd: acquire.c:552-50582 0 writers, 0 reserve, dev="Freenas" (/backup/baculaVolumes)
bacula-sd: dev.c:271-50582 close_dev vol=VolBacula-0294 fd=7 dev=7fc86c001208 adata=0 dev="Freenas" (/backup/baculaVolumes)
bacula-sd: file_dev.c:71-50582 Enter: virtual bool DEVICE::rewind(DCR*)
bacula-sd: dev.c:252-50582 Clear volhdr vol=VolBacula-0294
bacula-sd: acquire.c:571-50582 JobId=50582 broadcast wait_device_release at 27-nov-2017 16:47:56
bacula-sd: acquire.c:594-50582 Device "Freenas" (/backup/baculaVolumes) released by JobId=50582
bacula-sd: read.c:109-50582 Done reading.
bacula-sd: fd_cmds.c:178-50582 ==== 3099 Job RestoreFiles.2017-11-27_16.45.41_37 end JobStatus=84 JobFiles=28688 JobBytes=8470379438 JobErrors=0 ErrMsg=
bacula-sd: jcr.c:174-50582 write_last_jobs seek to 192
bacula-sd: bnet.c:569-0 socket=5 who=client host=192.168.2.25 port=9103
bacula-sd: dircmd.c:188-0 Got a DIR connection at 27-nov-2017 16:47:56
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge <1387407682.1511797676@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 <1407650774.1511797676@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: B4+pbn/l8w4jP8xP80/l5C
bacula-sd: dircmd.c:214-0 Message channel init completed.
bacula-sd: job.c:78-0 <dird: JobId=50582 job=RestoreFiles.2017-11-27_16.45.41_37 job_name=RestoreFiles client_name=bacula-fd type=82 level=70 FileSet=FullSet NoAttr=0 SpoolAttr=1 FileSetMD5=**Dummy** SpoolData=0 WritePartAfterJob=1 PreferMountedVols=1 SpoolSize=0 rerunning=0 VolSessionId=1 VolSessionTime=1511797387 sd_client=0 Authorization=
bacula-sd: job.c:100-0 rerunning=0 VolSesId=1 VolSesTime=1511797387
bacula-sd: acquire.c:658-50582 Attach 0x64001518 to dev "Freenas" (/backup/baculaVolumes)
bacula-sd: job.c:188-50582 sd_calls_client=0 sd_client=0
bacula-sd: job.c:210-50582 RestoreFiles.2017-11-27_16.45.41_37 waiting 1800 sec for FD to contact SD key=NPDJ-IBIL-AHLK-MBOI-NDGF-AKIF-BEPM-KEAK
bacula-sd: bnet.c:569-0 socket=6 who=client host=192.168.2.25 port=9103
bacula-sd: dircmd.c:188-0 Got a DIR connection at 27-nov-2017 16:47:57
bacula-sd: cram-md5.c:69-0 send: auth cram-md5 challenge <1037254028.1511797677@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 <600107543.1511797677@bacula-dir> ssl=0
bacula-sd: cram-md5.c:157-0 sending resp to challenge: sm/O5V/6O+5GC++Qb6/J9D
bacula-sd: dircmd.c:214-0 Message channel init completed.
bacula-sd: job.c:228-50582 === Auth=50582 jid=0 canceled=1 errstat=0
bacula-sd: jcr.c:174-0 write_last_jobs seek to 192
    
por Sakrow 09.11.2017 / 13:11

1 resposta

1

Opção 1 - Erro de configuração

Primeiramente, você fez uma restauração antes com essa configuração? Eu tenho um trabalho "RestoreFiles" para fazer este trabalho que se parece com isso: 

Job {
  Name = "RestoreFiles"
  Description = "Standard Restore template. Only one such job is needed for all standard Jobs/Clients/Storage ..."
  Type = Restore
  Client = bareos-fd
  FileSet = "Linux All"
  Storage = File
  Pool = Incremental
  Messages = Standard
  Where = /tmp/bareos-restores
}

Opção 2 - Erro de protocolo

Em segundo lugar, mais informações são necessárias. A comunicação entre o sd server e o fd client usa um protocolo que precisa estar em sincronia. Freqüentemente, um erro wanted 2000 OK storage, got 2800 End Job é resultado de uma incompatibilidade de protocolo que pode ser:

  • da resolução inconsistente de nomes (por exemplo, servidor e cliente têm ideias diferentes sobre o nome de cada um deles) ou
  • erros de protocolo (por exemplo, um deles é definido para IPv4, enquanto o outro é padronizado para IPv6) ou
  • erros de versão (o servidor e o cliente precisam ser versões compatíveis)

Haverá mais registros para explicar qual é, por exemplo 

21-Jan 00:07 xxxxxx-dir JobId 1199: Start Restore Job RestoreFiles.2016-01-21_00.07.44_16
21-Jan 00:07 xxxxxx-dir JobId 1199: Error: bsock.c:221 Socket open error. proto=28 port=9103. ERR=Protocol not supported
21-Jan 00:07 xxxxxx-dir JobId 1199: Using Device "DAT160" to read.
21-Jan 00:07 xxxxxx-sd JobId 1199: Ready to read from volume "Tape009" on tape device "DAT160" (/dev/nsa0).
21-Jan 00:07 xxxxxx-sd JobId 1199: Forward spacing Volume "Tape009" to file:block 12:0.
21-Jan 00:07 xxxxxx-fd JobId 1199: Error: bsock.c:221 Socket open error. proto=28 port=9103. ERR=Protocol not supported
21-Jan 00:55 xxxxxx-sd JobId 1199: Elapsed time=00:47:30, Transfer rate=6.099 M Bytes/second
21-Jan 00:07 xxxxxx-dir JobId 1199: Error: bsock.c:221 Socket open error. proto=28 port=9102. ERR=Protocol not supported
21-Jan 00:55 xxxxxx-dir JobId 1199: Using Device "Backup" to read.
21-Jan 00:55 xxxxxx-dir JobId 1199: Fatal error: Bad response to Storage command: wanted 2000 OK storage, got 2800 End Job TermCode=69 JobFiles=147756 ReadBytes=17353960553 JobBytes=17353960553 Errors=1 VSS=0 Encrypt=0 CommBytes=0 CompressCommBytes=0

** Observe o ERR=Protocol not supported que, nesse caso, era um cliente resolvido (incorretamente) via IPv6.

Houve discussão sobre este cenário específico na lista de discussão, mas, da minha experiência, sempre se resume a uma dessas 3 (ou 4) coisas.

Além disso, não se esqueça de que, após qualquer alteração na configuração do lado do servidor, você precisa reiniciar o Director e o Storage Manager ou eles podem não ter a mesma idéia sobre a configuração e erros aleatórios como este podem surgir. / p>

Eu revisarei essa resposta com base em quais informações adicionais podem ser fornecidas. :)

    
por 20.11.2017 / 07:30

Tags

Não é possível atualizar o PowerShell com o erro “não foi possível concluir as atualizações para desfazer as alterações” Apache 2.2 / CentOS: Negando Bad Bots