NetBackup catalog failing VER 6.0

[erasyad]

Hi Friends

Product:  VERSION: 6.0,REV=2005.09.07.19.13

We are facing problem in Netbackup on tape drive, following is snap of logs from BPTM process , kindly syggest what could be the reason for it.

Thanks in Advance.
--------------------------------------
Customer detects an error with the catalog for Netbackup, it shows error in BPTM process.

Note: Kindly see the logs/screenshot attached



Following is the error snippet in bptm logs
----------------------------------------------------------

00:08:03.742 [2276] <16> deassign_media: (-) Translating EMM_ERROR_MediaAllocated(2001049) to 97 in the NetBackup context
00:08:03.753 [2276] <2> db_error_add_to_file: dberrorq.c:midnite = 1255809600
00:08:03.767 [2276] <16> deassign_media: Media Manager error 97, rule does not exist in rule database, host = TE1-A
00:08:03.767 [2276] <2> db_error_add_to_file: dberrorq.c:midnite = 1255809600
00:08:03.779 [2276] <16> deassign_media: Media Manager could not deassign media id A00257, retaining it in NetBackup database
00:08:03.784 [2276] <2> bptm: EXITING with status 177 <----------

02:47:06.295 [8901] <2> bptm: EMMserver_name = TE1-A
02:47:06.295 [8901] <2> bptm: EMMserver_port = 1556
02:47:06.794 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name
02:47:06.795 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A
02:47:06.795 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com
02:47:06.898 [8901] <16> delete_expired_media: (-) Translating EMM_ERROR_DBServerDown(4005006) to 220 in the NetBackup context
02:47:06.909 [8901] <2> bptm: EXITING with status 220 <----------
02:47:52.964 [9030] <2> bptm: INITIATING (VERBOSE = 1): -rptdrv -jobid -1255718320 -jm
02:47:52.964 [9014] <2> bptm: INITIATING (VERBOSE = 1): -unload -dn TE1-A-4mm -dp /dev/rmt/0cbn -dk 2000003 -m A00257 -mk 4000027 -mds 1 -alocid 83 -jobid -1255718319 -jm
02:47:52.983 [9014] <2> bptm: EMMserver_name = TE1-A
02:47:52.983 [9014] <2> bptm: EMMserver_port = 1556
02:47:52.984 [9030] <2> bptm: EMMserver_name = TE1-A
02:47:52.984 [9030] <2> bptm: EMMserver_port = 1556
02:47:52.986 [9014] <2> send_brm_msg: PID of bpxm = 9014
02:47:52.986 [9014] <2> nbjm_media_request: Passing job control to NBJM, type UNLOAD
02:47:52.998 [9030] <2> drivename_open: Called with Create 0, file TE1-A-4mm
02:47:52.998 [9030] <2> drivename_checklock: Called
02:47:53.010 [9030] <2> report_drives: MODE = 0
02:47:53.010 [9030] <2> report_drives: TIME = 1255803005
02:47:53.010 [9030] <2> report_drives: MASTER = TE1-A
02:47:53.010 [9030] <2> report_drives: PATH = /dev/rmt/0cbn
02:47:53.010 [9030] <2> report_drives: MEDIA = A00257
02:47:53.010 [9030] <2> report_drives: REQID = -1255718290
02:47:53.010 [9030] <2> report_drives: ALOCID = 83
02:47:53.010 [9030] <2> report_drives: PID = 27501
02:47:53.010 [9030] <2> report_drives: FILE = /usr/openv/netbackup/db/media/tpreq/drive_TE1-A-4mm
02:47:53.011 [9030] <2> main: Sending [EXIT STATUS 0] to NBJM
02:47:53.011 [9030] <2> bptm: EXITING with status 0 <----------
02:47:53.179 [9014] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name
02:47:53.180 [9014] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A
02:47:53.180 [9014] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com
02:47:53.204 [9014] <2> taolog: can't register signal handler
02:47:55.312 [9014] <2> RequestMultipleResources: returning

---------------------------------------

00:07:03.548 [7435] <16> delete_image: (-) Translating EMM_ERROR_MediaNotFound(2005031) to 95 in the NetBackup context

00:07:03.557 [7435] <2> bptm: EXITING with status 95 <----------

00:08:03.711 [7524] <2> bptm: INITIATING (VERBOSE = 1): -change_exp_date -ev A00256 -date 0

00:08:03.719 [7524] <2> bptm: EMMserver_name = TE1-A

00:08:03.719 [7524] <2> bptm: EMMserver_port = 1556

00:08:03.795 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name

00:08:03.796 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A

00:08:03.796 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com

00:08:03.850 [7524] <16> deassign_media: (-) Translating EMM_ERROR_MediaAllocated(2001049) to 97 in the NetBackup context

00:08:03.859 [7524] <2> db_error_add_to_file: dberrorq.c:midnite = 1255723200

00:08:03.877 [7524] <16> deassign_media: Media Manager error 97, rule does not exist in rule database, host = TE1-A

00:08:03.877 [7524] <2> db_error_add_to_file: dberrorq.c:midnite = 1255723200

00:08:03.889 [7524] <16> deassign_media: Media Manager could not deassign media id A00256, retaining it in NetBackup database

00:08:03.895 [7524] <2> bptm: EXITING with status 177 <----------

[Zahid_Haseeb]

This may help you

https://www-secure.symantec.com/connect/forums/error-backuping-windows-client-over-wan

https://www-secure.symantec.com/connect/forums/ndmp-backups-failing-5284-media-errors

[Marianne]

First of all, please double-check your installed version - you say it's 5.1 MP4, but you're posting logs with reference to EMM, nbjm, etc... that only exist as from 6.0?
Have a look at these 2 TechNotes:
http://seer.entsupport.symantec.com/docs/294805.htm
http://seer.entsupport.symantec.com/docs/294806.htm

[erasyad]

Hello Marianne,

Thanks for your great help! I will confirm on the version, not sure right now.

However logs have following Exit status:
1) 00:41:57.502 [3791] <2> catch_signal: EXITING with status 82
2) 00:07:03.557 [7435] <2> bptm: EXITING with status 95 <----------
3) 00:08:03.895 [7524] <2> bptm: EXITING with status 177 <----------
4) 02:47:06.909 [8901] <2> bptm: EXITING with status 220 <----------


---------------------------------------------------------------------------
00:41:52.178 [3791] <2> io_open: SCSI RESERVE
00:41:52.180 [3791] <2> io_open: file /usr/openv/netbackup/db/media/tpreq/drive_TE1-A-4mm successfully opened (mode 0)
00:41:52.180 [3791] <2> io_ioctl: command (2)MTBSF 2 from (bptm.c.8383) on drive index 0
00:41:57.499 [3791] <2> io_ioctl: command (1)MTFSF 1 from (bptm.c.8385) on drive index 0
00:41:57.500 [3791] <2> io_close: closing /usr/openv/netbackup/db/media/tpreq/drive_TE1-A-4mm, from bptm.c.8391
00:41:57.502 [3791] <2> process_tapealert: TapeAlert returned 0x00000000 0x00000000 (from io_terminate_tape)
00:41:57.502 [3791] <2> catch_signal: EXITING with status 82

00:07:03.235 [7441] <2> bptm: EMMserver_name = TE1-A
00:07:03.235 [7441] <2> bptm: EMMserver_port = 1556
00:07:03.311 [7441] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name
00:07:03.311 [7441] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A
00:07:03.312 [7441] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com
00:07:03.521 [7441] <2> bptm: EXITING with status 0 <----------
00:07:03.548 [7435] <16> delete_image: (-) Translating EMM_ERROR_MediaNotFound(2005031) to 95 in the NetBackup context
00:07:03.557 [7435] <2> bptm: EXITING with status 95 <----------


00:07:03.548 [7435] <16> delete_image: (-) Translating EMM_ERROR_MediaNotFound(2005031) to 95 in the NetBackup context
00:07:03.557 [7435] <2> bptm: EXITING with status 95 <----------
00:08:03.711 [7524] <2> bptm: INITIATING (VERBOSE = 1): -change_exp_date -ev A00256 -date 0
00:08:03.719 [7524] <2> bptm: EMMserver_name = TE1-A
00:08:03.719 [7524] <2> bptm: EMMserver_port = 1556
00:08:03.795 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name
00:08:03.796 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A
00:08:03.796 [7524] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com
00:08:03.850 [7524] <16> deassign_media: (-) Translating EMM_ERROR_MediaAllocated(2001049) to 97 in the NetBackup context
00:08:03.859 [7524] <2> db_error_add_to_file: dberrorq.c:midnite = 1255723200
00:08:03.877 [7524] <16> deassign_media: Media Manager error 97, rule does not exist in rule database, host = TE1-A
00:08:03.877 [7524] <2> db_error_add_to_file: dberrorq.c:midnite = 1255723200
00:08:03.889 [7524] <16> deassign_media: Media Manager could not deassign media id A00256, retaining it in NetBackup database
00:08:03.895 [7524] <2> bptm: EXITING with status 177 <----------


02:44:19.420 [8732] <2> main: Sending [EXIT STATUS 0] to NBJM
02:44:19.420 [8732] <2> bptm: EXITING with status 0 <----------
02:47:05.515 [8895] <2> bptm: INITIATING (VERBOSE = 1): -delete_expired
02:47:05.553 [8895] <2> bptm: EXITING with status 0 <----------
02:47:06.286 [8901] <2> bptm: INITIATING (VERBOSE = 1): -delete_all_expired
02:47:06.295 [8901] <2> bptm: EMMserver_name = TE1-A
02:47:06.295 [8901] <2> bptm: EMMserver_port = 1556
02:47:06.794 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name
02:47:06.795 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.3984: Function: VssGetFQDNHostName. Search name TE1-A
02:47:06.795 [8901] <2> VssGetFQDNHostName: vss_auth.cpp.4322: Function: VssGetFQDNHostName. Match te1-a.etisalat.com
02:47:06.898 [8901] <16> delete_expired_media: (-) Translating EMM_ERROR_DBServerDown(4005006) to 220 in the NetBackup context
02:47:06.909 [8901] <2> bptm: EXITING with status 220 <----------
02:47:52.964 [9030] <2> bptm: INITIATING (VERBOSE = 1): -rptdrv -jobid -1255718320 -jm
02:47:52.964 [9014] <2> bptm: INITIATING (VERBOSE = 1): -unload -dn TE1-A-4mm -dp /dev/rmt/0cbn -dk 2000003 -m A00257 -mk 4000027 -mds 1 -alocid 83 -jobid -1255718319 -jm

[Marianne]

You need to troubleshoot each error seperately - each of them has a different PID: [8901] exited with status 220. If you have a look at this status code in the Troubleshooting Guide, it points to a possible disk full condition. EMM will shut down to prevent database corruption.

PID [2276]  exited with 177.
According to the bptm log, media id A00257 was assigned to a job at 00:04 (PID 2066) :
00:04:19.553 [2066] <2> report_drives: MASTER = TE1-A
00:04:19.553 [2066] <2> report_drives: PATH = /dev/rmt/0cbn
00:04:19.553 [2066] <2> report_drives: MEDIA = A00257
00:04:19.553 [2066] <2> report_drives: REQID = -1255718290
00:04:19.553 [2066] <2> report_drives: ALOCID = 83
00:04:19.553 [2066] <2> report_drives: PID = 27501
00:04:19.553 [2066] <2> report_drives: FILE = /usr/openv/netbackup/db/media/tpreq/drive_TE1-A-4mm

While the job was running, a process or person tried to expire media id A00257:
00:08:03.600 [2276] <2> bptm: INITIATING (VERBOSE = 1): -change_exp_date -ev A00257 -date 0

The expiration failed because the media was in use / allocated:

00:08:03.742 [2276] <16> deassign_media: (-) Translating EMM_ERROR_MediaAllocated(2001049) to 97 in the NetBackup context
00:08:03.753 [2276] <2> db_error_add_to_file: dberrorq.c:midnite = 1255809600
00:08:03.767 [2276] <16> deassign_media: Media Manager error 97, rule does not exist in rule database, host = TE1-A
00:08:03.767 [2276] <2> db_error_add_to_file: dberrorq.c:midnite = 1255809600
00:08:03.779 [2276] <16> deassign_media: Media Manager could not deassign media id A00257, retaining it in NetBackup database
00:08:03.784 [2276] <2> bptm: EXITING with status 177 <----------

Status 82 means bptm was killed by the parent process - possibly bpbrm because a connection could not be established with a client. The real reason will be the status code in Activity Monitor.

[erasyad]

Hello Marianne,

I really appreciate your kind help for this case and clearly mentioning the reason for all errors code received for the case.

Yes you are right the version is 6.0 for NetBackup

[root]TE1-A# pkginfo | grep -i netback
application VRTSnetbp VERITAS NetBackup and Media Manager
[root]TE1-A# pkginfo -l VRTSnetbp
PKGINST: VRTSnetbp
NAME: VERITAS NetBackup and Media Manager
CATEGORY: application,tools
ARCH: sparc
VERSION: 6.0,REV=2005.09.07.19.13
BASEDIR: /opt
VENDOR: VERITAS Software Corporation
DESC: NetBackup provides backup and restore services for client systems a
nager has device and media management components for handling tapes drives, opti
PSTAMP: code20050907191337
INSTDATE: Aug 30 2009 13:28
HOTLINE: Please contact your local service provider.
STATUS: completely installed
FILES: 946 installed pathnames
90 directories
409 executables
898202 blocks used (approx)

[Mike_Gavrilov]

1. Post here output of command: vxlogview -X jobid=your_job_id -d all
2. Post vmrule -listall
3. Post vmquery -pn CatalogBackup -bx
4. Post bpsyncinfo
5. Freeze this media and try to add new one from Scratch Pool

[erasyad]

Hello Gavrilov,

Thanks for help!

Are these commands read only? In fact we can only execute readonly commnad on the system, and rest we have to request to execute on the system.

I can find only bpsyncinfo & vxlogview. kindly help me with exact syntax for these commnds

bash-3.00# find . -name bpsyncinfo
./bin/admincmd/bpsyncinfo
bash-3.00# find . -name vmrule
bash-3.00# find . -name vmquery
bash-3.00# find . -name vxlogview
./bin/vxlogview


Thanks for your help!

Regards
erasyad

[Mike_Gavrilov]

1. Just bpsyncinfo without any keys
2. vxlogview -X jobid=`bpdbjobs -U |grep -i catal|head -1|awk '{ print $1}'`-d all  --- run this command after job finish.

This commands should be here:
/usr/openv/volmgr/bin/vmquery -pn CatalogBackup -bx
/usr/openv/volmgr/bin/vmrule -listall

[erasyad]

Hi Gavrilov,

since I am not aware of netbackup, Are these commands are readonly and will not harm any thing to the system?
Kindly confirm so that I can execute it on the system.

Thanks & regards
erasyad

[Marianne]

As you can see from the actual commands: they view, list, display info, etc... None of these commands make any changes to the configuration.
For more info on these commands, have a look at the Commands manual: ftp://exftpp.symantec.com/pub/support/products/NetBackup_Enterprise_Server/279299.pdf
List of all manuals: http://seer.entsupport.symantec.com/docs/287039.htm

Could you also please explain what your actual problem is -The title of the post says :

"NetBackup catalog failing VER 6.0", In the post you say "We are facing problem in Netbackup on tape drive" and then you attach bptm log that doesn't explain what your actual problem is. Every single error in bptm that you highlighted is from a different job/process.

If we understand what the real problem is, we can provide more useful assistance.

[Mike_Gavrilov]

I never advice to change something without warn about affects of it.
You can also run NBSU script to collect support data and give us a link to it.
seer.entsupport.symantec.com/docs/323434.htm

[erasyad]

Thanks a lot for Help!

Infact I am not very much aware of NetBackup and just working as a mediator, I am not there at acutal site where problem is, I request people there for information, thats the reason there could be delay getting information. 

As far as exact problem they are mentioning

They are reporting  that tapes is ok "Even after formatting of Tapes Catalog backup is failing daily"

[Mike_Gavrilov]

And what about job trace?
P.S. I really can't understand why guys can't send command output instead of they opinion.

[Marianne]

How do they 'format' tapes? There is no need to format tapes before NetBackup can use it.
We also need to know what the error message is.
Copy and paste from the Details tab will be a good beginning.
Please also let us know if this is a Hot or Cold Catalog backup. Media requirements for the two types are totally different.

[Mike_Gavrilov]

I expect to see answer "Everything is ok but  Catalog backup fails every day" :)

[erasyad]

screen shot of detailed status tab is attached with attachments provided with the problem.

ErrorMessage.jpg  is latest one I received.

[Marianne]

The screenshot is NOT from a Catalog backup, but for a policy called Full_EM2-A_Daily.
The backup is failing with status 57, meaning that either NetBackup is not installed on client EM2-A, or NetBackup Client Service is not running (bpcd not LISTENing).

Extract from Troubleshooting Guide:
client connection refused
The client refused a connection on the port number for bpcd. This can occur because there is no process listening on the bpcd port or there are more connections to the bpcd port than the network subsystem can handle with the listen() call.

Try the following:

1.  For Windows NetBackup servers:
   a.  Make sure the NetBackup client software is installed.
   b.  Verify that the bpcd and bprd port numbers in the %SystemRoot%system32driversetcservices file on the server matches the setting on the client.
   c.  Verify that the NetBackup Client Service Port number and NetBackup Request Service Port number on the Network tab in the NetBackup Client Properties dialog match the bpcd and bprd settings in the services file. To display this dialog, start the Backup, Archive, and Restore  interface on the server and click NetBackup Client Properties on the File menu.
   The values on the Network tab are written to the services file when the NetBackup Client service starts.
   d.  Verify that the NetBackup client service is running.
   e.  Use the following command to see if the master server returns correct information for the client:
   install_pathVERITASNetBackupbinbpclntcmd -pn
2.  For UNIX servers:
   a.  Make sure the NetBackup client software is installed.
   b.  Verify that the bpcd port number on the server (either NIS services map or in /etc/services) matches the number in the client's services file.
   c.  Run the NetBackup Configuration Validation Utility (NCVU) for the associated NetBackup nodes. Note the NetBackup services port number
 checks in section one.
3.  For a Macintosh or NetWare target client, verify that the server is not trying to connect when a backup or restore is already in progress on the client. These clients can handle only one NetBackup job at a time.
4.  Perform "Resolving Network Communication Problems" in the Troubleshooting Guide.

[erasyad]

Kindly see the output of commands


bash-3.00# /usr/openv/netbackup/bin/admincmd/bpsyncinfo

Frequency of Offline Catalog Backup:  after any successful backup/archive

  Server: TE1-A
  Sequence # 1    Last Media Used: /var/opt/BGw/Backupdg/Netbackup/Catalog_Backup

    Written             Allocated           Type   Density  Media
    ------------------- ------------------- ----   -------  -----
  1 11/01/2009 15:34:13 n/a                 Disk            "/var/opt/BGw/Backupdg/Netbackup/Catalog_Backup"
  2 10/31/2009 09:05:22 n/a                 Disk            "/netbackup_catalog"

  Paths Included:
    /usr/openv/netbackup/db
    /usr/openv/volmgr/database
    /usr/openv/var
    TE1-A:NETBACKUP_RELATIONAL_DATABASE_FILES


bash-3.00# /usr/openv/volmgr/bin/vmrule -listall
===================================================================
bash-3.00#


bash-3.00# /usr/openv/volmgr/bin/vmrule -listall
===================================================================
bash-3.00# /usr/openv/volmgr/bin/vmquery -pn CatalogBackup -bx
media   media     robot  robot  robot  side/  volume      optical  # mounts/        last            assigned       pool
 ID     type      type     #    slot   face   group       partner  cleanings     mount time          time
---------------------------------------------------------------------------------------------------------------------------
bash-3.00#

Thanks & regards
erasyad


 

[Mike_Gavrilov]

As you understand it's not a CatalogBackup issue cause you use a Disk SU for it:

Written             Allocated           Type   Density  Media
    ------------------- ------------------- ----   -------  -----
  1 11/01/2009 15:34:13 n/a                 Disk            "/var/opt/BGw/Backupdg/Netbackup/Catalog_Backup"
  2 10/31/2009 09:05:22 n/a                 Disk            "/netbackup_catalog"

Another step should be put VERBOSE into bottom of vm.conf
create:
/usr/openv/volmgr/debug/ltid
/usr/openv/volmgr/debug/reqlib
/usr/openv/volmgr/debug/tpcommand
and restart ltid.
rerun affected policy and check logs.

You should ensure does only one policy affected or all policies. if only one - check volume pool for it. If all it can be drive issue.
You should check how many tapes affected. If only one - freez it any monitor job's logs.