Bacula-users

Re: [Bacula-users] segmentation fault after server crash

2012-08-07 08:59:19
Subject: Re: [Bacula-users] segmentation fault after server crash
From: Jürgen Echter <j.echter AT echter-kuechen-elektro DOT de>
To: bacula-users AT lists.sourceforge DOT net
Date: Tue, 07 Aug 2012 14:56:38 +0200
Am 07.08.2012 14:24, schrieb Jürgen Echter:
> and i get the following via email:
>
> ptrace: operation not allowed.
> /var/lib/bacula/30330: file or directory not found.
> $1 = 0
> /etc/bacula/scripts/btraceback.gdb:2: Error in sourced command file:
> No symbol table is loaded.  Use the "file" command.
>
> thanks.
>
> juergen
>
> ------------------------------------------------------------------------------
> Live Security Virtual Conference
> Exclusive live event will cover all the ways today's security and
> threat landscape has changed and how IT managers can respond. Discussions
> will include endpoint security, mobile security and the latest in malware
> threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
> _______________________________________________
> Bacula-users mailing list
> Bacula-users AT lists.sourceforge DOT net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
some more information this time with debug 100 ;)

i started fd,sd and director on server with debug 30 and also fd on client

result:

director:

sudo /usr/sbin/bacula-dir -c /etc/bacula/bacula-dir.conf -f -d 100
bacula-dir: dird.c:184-0 Debug level = 100
bacula-dir: jcr.c:138-0 read_last_jobs seek to 192
bacula-dir: jcr.c:145-0 Read num_items=0
bacula-dir: mysql.c:100-0 db_open first time
bacula-dir: mysql.c:129-0 initdb ref=1 connected=0 db=0
bacula-dir: mysql.c:165-0 mysql_init done
bacula-dir: mysql.c:186-0 mysql_real_connect done
bacula-dir: mysql.c:188-0 db_user=bacula db_name=bacula 
db_password=kkh38ktz_04iy9
bacula-dir: mysql.c:214-0 opendb ref=1 connected=1 db=873790
bacula-dir: mysql.c:235-0 closedb ref=0 connected=1 db=873790
bacula-dir: mysql.c:239-0 close db=873790
bacula-dir: pythonlib.c:104-0 No script dir. prog=DirStartUp
bacula-dir: bnet_server.c:96-0 Addresses host[ipv4:0.0.0.0:9101]
bacula-dir: job.c:1348-0 wstorage=File
bacula-dir: job.c:1357-0 wstore=File where=Job Ressource
bacula-dir: job.c:1009-0 JobId=0 created 
Job=*JobMonitor*.2012-08-07_14.53.43_01
bacula-dir: bnet.c:669-0 who=client host=127.0.0.1 port=36131
bacula-dir: job.c:1348-0 wstorage=File
bacula-dir: job.c:1357-0 wstore=File where=Job Ressource
bacula-dir: job.c:1009-0 JobId=0 created 
Job=-Console-.2012-08-07_14.54.16_02
bacula-dir: cram-md5.c:73-0 send: auth cram-md5 
<150781394.1344344056@bacula-dir> ssl=0
bacula-dir: cram-md5.c:133-0 cram-get received: auth cram-md5 
<1030598433.1344344056@bconsole> ssl=0
bacula-dir: cram-md5.c:152-0 sending resp to challenge: 
e1ERDwg0y0/7pQ+SHx/+8C
bacula-dir: ua_cmds.c:2080-0 UA Open database
bacula-dir: mysql.c:100-0 db_open first time
bacula-dir: mysql.c:129-0 initdb ref=1 connected=0 db=0
bacula-dir: mysql.c:165-0 mysql_init done
bacula-dir: mysql.c:186-0 mysql_real_connect done
bacula-dir: mysql.c:188-0 db_user=bacula db_name=bacula 
db_password=kkh38ktz_04iy9
bacula-dir: mysql.c:214-0 opendb ref=1 connected=1 db=876290
bacula-dir: ua_run.c:1325-0 Using pool File
bacula-dir: job.c:1348-0 wstorage=File
bacula-dir: job.c:1357-0 wstore=File where=Job Ressource
bacula-dir: job.c:1382-0 wstore=File where=Pool Ressource
bacula-dir: ua_run.c:178-0 JobId=0 using pool File priority=2
bacula-dir: job.c:1009-0 JobId=0 created Job=mule.2012-08-07_14.54.21_03
bacula-dir: job.c:126-0 Open database
bacula-dir: mysql.c:91-0 DB REopen 1 bacula
bacula-dir: mysql.c:95-0 initdb ref=2 connected=1 db=876290
bacula-dir: job.c:880-0 Created Client mule-fd record 5
bacula-dir: job.c:172-0 Created job record JobId=9 
Name=mule.2012-08-07_14.54.21_03 Type=B Level=F
bacula-dir: pythonlib.c:227-0 No startup module.
bacula-dir: fd_cmds.c:274-0 Level=F last start time=
bacula-dir: job.c:1348-0 wstorage=File
bacula-dir: job.c:1357-0 wstore=File where=Pool Ressource
bacula-dir: ua_run.c:182-0 JobId=9 NewJobId=9 using pool File priority=2
bacula-dir: backup.c:332-9 JobId=9 JobLevel=F
bacula-dir: msgchan.c:104-9 bnet_connect to Storage daemon 
192.168.0.200:9103
bacula-dir: bsock.c:220-9 Current host[ipv4:192.168.0.200:9103] All 
host[ipv4:192.168.0.200:9103]
bacula-dir: bsock.c:154-9 who=Storage daemon host=192.168.0.200 port=9103
bacula-dir: cram-md5.c:133-9 cram-get received: auth cram-md5 
<2130567998.1344344063@bacula-sd> ssl=0
bacula-dir: cram-md5.c:152-9 sending resp to challenge: 
Hw/Kd5hdvW/2XU+Vy2+jlB
bacula-dir: cram-md5.c:80-9 send: auth cram-md5 
<1781253406.1344344063@bacula-dir> ssl=0
bacula-dir: cram-md5.c:99-9 Authenticate OK Bm/0V0+i/1Z2N79CY9/IyB
bacula-dir: msgchan.c:198-9 >stored: JobId=9 
job=mule.2012-08-07_14.54.21_03 job_name=mule client_name=mule-fd 
type=66 level=70 FileSet=mule NoAttr=0 SpoolAttr=1 
FileSetMD5=cFsP7l/g1GEeH8/uw+AtnD SpoolData=0 WritePartAfterJob=1 
PreferMountedVols=1 SpoolSize=0 Resched=0
bacula-dir: getmsg.c:137-9 bget_dirmsg 91: 3000 OK Job SDid=1 
SDtime=1344344034 Authorization=JKNF-OGEC-ELKP-MCNP-KMDO-ABGH-KFFF-OIHM

bacula-dir: msgchan.c:200-9 <stored: 3000 OK Job SDid=1 
SDtime=1344344034 Authorization=JKNF-OGEC-ELKP-MCNP-KMDO-ABGH-KFFF-OIHM
bacula-dir: msgchan.c:287-9 wstore >stored: use storage=File 
media_type=File pool_name=File pool_type=Backup append=1 copy=0 stripe=0
bacula-dir: msgchan.c:294-9 >stored: use device=File
bacula-dir: getmsg.c:137-9 bget_dirmsg 82: CatReq 
Job=mule.2012-08-07_14.54.21_03 FindMedia=1 pool_name=File media_type=File

bacula-dir: catreq.c:125-9 catreq CatReq Job=mule.2012-08-07_14.54.21_03 
FindMedia=1 pool_name=File media_type=File
bacula-dir: next_vol.c:62-9 find_next_vol_for_append: JobId=9 PoolId=2, 
MediaType=File
bacula-dir: sql_find.c:366-9 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,VolParts,LabelType,LabelDate,StorageId,Enabled,LocationId,RecycleCount,InitialWrite,ScratchPoolId,RecyclePoolId,VolReadTime,VolWriteTime,ActionOnPurge
 
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:444-9 Rtn numrows=1
bacula-dir: next_vol.c:164-9 VolJobs=1 FirstWritten=1344333638
bacula-dir: catreq.c:147-9 find_media ok=1 idx=1 vol=file-0001
bacula-dir: catreq.c:99-9 Vol Info for mule.2012-08-07_14.54.21_03: 1000 
OK VolName=file-0001 VolJobs=1 VolFiles=0 VolBlocks=10403 
VolBytes=671116225 VolMounts=1 VolErrors=0 VolWrites=10404 
MaxVolBytes=21474836480 VolCapacityBytes=0 VolStatus=Append Slot=0 
MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 
VolWriteTime=1991052 EndFile=0 EndBlock=671116224 VolParts=0 LabelType=0 
MediaId=1
bacula-dir: getmsg.c:137-9 bget_dirmsg 31: 3000 OK use device device=File

bacula-dir: msgchan.c:300-9 <stored: 3000 OK use device device=File
bacula-dir: msgchan.c:337-9 Start SD msg_thread.
bacula-dir: msgchan.c:389-9 Start msg_thread loop
bacula-dir: msgchan.c:349-9 SD msg_thread started. use=2
bacula-dir: getmsg.c:137-9 bget_dirmsg 52: Status 
Job=mule.2012-08-07_14.54.21_03 JobStatus=70

Bacula interrupted by signal 11: Segmentation violation
Kaboom! bacula-dir, bacula-dir got signal 11 - Segmentation violation. 
Attempting traceback.
Kaboom! exepath=/usr/sbin/
Calling: /usr/sbin/btraceback /usr/sbin/bacula-dir 6847 /var/lib/bacula

fd:

sudo /usr/sbin/bacula-fd -c /etc/bacula/bacula-fd.conf -f -d 100
bacula-fd: filed_conf.c:452-0 Inserting director res: bacula-mon
bacula-fd: jcr.c:138-0 read_last_jobs seek to 192
bacula-fd: jcr.c:145-0 Read num_items=0
bacula-fd: pythonlib.c:104-0 No script dir. prog=FDStartUp
bacula-fd: filed.c:274-0 filed: listening on port 9102
bacula-fd: bnet_server.c:96-0 Addresses host[ipv4:0.0.0.0:9102]

sd:

sudo /usr/sbin/bacula-sd -c /etc/bacula/bacula-sd.conf -f -d 100
bacula-sd: stored_conf.c:698-0 Inserting director res: bacula-mon
bacula-sd: stored_conf.c:698-0 Inserting device res: Tape
bacula-sd: jcr.c:138-0 read_last_jobs seek to 192
bacula-sd: jcr.c:145-0 Read num_items=3
bacula-sd: pythonlib.c:104-0 No script dir. prog=SDStartUp
bacula-sd: stored.c:535-0 calling init_dev /bacula/archivefiles
bacula-sd: dev.c:284-0 init_dev: tape=0 dev_name=/bacula/archivefiles
bacula-sd: stored.c:537-0 SD init done /bacula/archivefiles
bacula-sd: stored.c:550-0 calling first_open_device "File" 
(/bacula/archivefiles)
bacula-sd: stored.c:535-0 calling init_dev /dev/nst0
bacula-sd: dev.c:284-0 init_dev: tape=1 dev_name=/dev/nst0
bacula-sd: stored.c:537-0 SD init done /dev/nst0
bacula-sd: bnet_server.c:96-0 Addresses host[ipv4:0.0.0.0:9103]
bacula-sd: bnet.c:669-0 who=client host=192.168.0.200 port=36643
bacula-sd: cram-md5.c:73-0 send: auth cram-md5 
<2130567998.1344344063@bacula-sd> ssl=0
bacula-sd: cram-md5.c:133-0 cram-get received: auth cram-md5 
<1781253406.1344344063@bacula-dir> ssl=0
bacula-sd: cram-md5.c:152-0 sending resp to challenge: 
Bm/0V0+i/1Z2N79CY9/IyB
bacula-sd: dircmd.c:211-0 Message channel init completed.
bacula-sd: job.c:96-0 <dird: JobId=9 job=mule.2012-08-07_14.54.21_03 
job_name=mule client_name=mule-fd type=66 level=70 FileSet=mule NoAttr=0 
SpoolAttr=1 FileSetMD5=cFsP7l/g1GEeH8/uw+AtnD SpoolData=0 
WritePartAfterJob=1 PreferMountedVols=1 SpoolSize=0 Resched=0
bacula-sd: job.c:171-0 >dird jid=9: 3000 OK Job SDid=1 SDtime=1344344034 
Authorization=JKNF-OGEC-ELKP-MCNP-KMDO-ABGH-KFFF-OIHM
bacula-sd: pythonlib.c:227-0 No startup module.
bacula-sd: askdir.c:277-0 >dird CatReq Job=mule.2012-08-07_14.54.21_03 
FindMedia=1 pool_name=File media_type=File
bacula-sd: askdir.c:182-0 <dird 1000 OK VolName=file-0001 VolJobs=1 
VolFiles=0 VolBlocks=10403 VolBytes=671116225 VolMounts=1 VolErrors=0 
VolWrites=10404 MaxVolBytes=21474836480 VolCapacityBytes=0 
VolStatus=Append Slot=0 MaxVolJobs=0 MaxVolFiles=0 InChanger=0 
VolReadTime=0 VolWriteTime=1991052 EndFile=0 EndBlock=671116224 
VolParts=0 LabelType=0 MediaId=1
bacula-sd: askdir.c:206-0 do_reqest_vol_info return true slot=0 
Volume=file-0001
bacula-sd: askdir.c:286-0 Call reserve_volume. Vol=file-0001
bacula-sd: askdir.c:293-0 dir_find_next_appendable_volume return true. 
vol=file-0001
bacula-sd: job.c:204-0 mule.2012-08-07_14.54.21_03 waiting 1800 sec for 
FD to contact SD key=JKNF-OGEC-ELKP-MCNP-KMDO-ABGH-KFFF-OIHM

fd on client:

sudo /usr/sbin/bacula-fd -f -d 100 -c /etc/bacula/bacula-fd.conf
bacula-fd: filed_conf.c:452-0 Inserting director res: bacula-mon
mule-fd: jcr.c:138-0 read_last_jobs seek to 192
mule-fd: jcr.c:145-0 Read num_items=10
mule-fd: pythonlib.c:104-0 No script dir. prog=FDStartUp
mule-fd: filed.c:274-0 filed: listening on port 9102
mule-fd: bnet_server.c:96-0 Addresses host[ipv4:192.168.0.205:9102]

i hope this helps.

sorry for not reading manual for debugging first.

juergen

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users