11-11-2019 12:36 AM
Hi,
catalog's backup fail with this error:
Critical bptm (pid=208914) sts_close_handle failed: 2060057 OpenStorage Proxy Plugin Error
Critical bptm (pid=208914) cannot write image to disk, media close failed with status 2060057
Critical bptm (pid=208914) sts_get_image_prop failed: error 2060057: OpenStorage Proxy Plugin Error
Critical bptm (pid=208914) sts_close_handle failed: 2060057 OpenStorage Proxy Plugin Error
Critical bptm (pid=208914) cannot write image to disk, media close failed with status 2060057 OpenStorage Proxy Plugin Error
Critical bptm (pid=208914) sts_get_server_prop failed: error 2060057 OpenStorage Proxy Plugin Error
Critical bptm (pid=208914) sts_get_server_prop failed: error 2060057 OpenStorage Proxy Plugin Error
Info bptm (pid=208914) EXITING with status 87 <----------
I looked for this error on VOX forums, but i've not found about for this error on catalog backup. Please someone can help me?
Attached full log.
Thanks and Regards
11-11-2019 01:23 AM
So, the STU is Advanced Disk on Media Server media_srv_appl_1, right?
You need bptm log (log level 3 or higher) on media_srv_appl_1 to troubleshoot.
11-11-2019 02:07 AM
11-11-2019 02:21 AM
The log that you posted shows bptm processes on media server media_srv_appl_1
Is this the media server that you checked?
If bptm log folder exist on the media server, then there has to be something in the log for that day.
I see this timestamp in your attachment: 1573136365 = 11/07/2019 @ 2:19pm
So, I am expecting to see something in bptm log for 7 Nov on media server media_srv_appl_1.
The only way to troubleshoot this is with media server bptm log.
11-11-2019 02:38 AM
Hi Marianne,
the log that you seen, i got it from GUI backup log. If i go on media server (media_srv_appl_1) bptm folder, i see this:
rw-r--r-- 1 root root 52428916 Aug 17 2019 root.081719_00007.log
-rw-r--r-- 1 root root 52428919 Aug 17 2019 root.081719_00008.log
-rw-r--r-- 1 root root 52428854 Aug 17 2019 root.081719_00009.log
-rw-r--r-- 1 root root 52428906 Aug 17 2019 root.081719_00010.log
-rw-r--r-- 1 root root 52428928 Aug 17 2019 root.081719_00011.log
-rw-r--r-- 1 root root 52428956 Aug 17 2019 root.081719_00012.log
-rw-r--r-- 1 root root 52428813 Aug 17 2019 root.081719_00013.log
-rw-r--r-- 1 root root 34088756 Aug 17 2019 root.081719_00014.log
I'm agreed with you for logs on media server, but why the directory is blocked to 08/17/2019. I configured BPT_VERBOSE = 5 on bp.conf.
Thanks in advance,
11-11-2019 02:42 AM
Is there a possibility that filesystems are full on this media server?
11-11-2019 05:01 AM
11-11-2019 05:13 AM
Check if bptm directory is in correct folder.
If bptm folder exists in /usr/openv/netbackup/logs, it WILL write to the log file when bptm process is started on the media server.
There is nothing to troubleshoot without bptm log.
11-13-2019 02:42 AM
Hi Marianne,
sorry for delayed response.
The bptm folder it's in correct path, the media server is an appliance and i found this on bp.conf:
USE_VXSS = PROHIBITED
VXSS_SERVICE_TYPE = INTEGRITYANDCONFIDENTIALITY
ENABLE_ROBUST_LOGGING = NO
VERBOSE = 4
NETBACKUP_APPLIANCE_MODE = MEDIA_SERVER
IP_ADDRESS_FAMILY = AF_UNSPEC
REVERSE_NAME_LOOKUP = PROHIBITED
CLIENT_CONNECT_TIMEOUT = 3600
CLIENT_READ_TIMEOUT = 3600
BPSTART_TIMEOUT = 3600
BPEND_TIMEOUT = 3600
USE_AUTHENTICATION = ON
HOST_CACHE_TTL = 3600
SERVER_CONNECT_TIMEOUT = 60
BPTM_VERBOSE = 4
KEEP_LOGS_SIZE_GB = 0
ENABLE_CRITICAL_PROCESS_LOGGING = YES
CLI_GA_RET_LOGS_DURATION = 0
MAX_LOGFILE_SIZE = 50
MAX_NUM_LOGFILES = 100
TELEMETRY_UPLOAD = YES
VXMS_VERBOSE = 1
Last bptm log on August 17. Somethings wrong?
Thanks and Regards
11-13-2019 03:15 AM
I see lots of bp.conf entries that are not normally there.
If you have a team of backup admins, then ask them.
For example : KEEP_LOGS_SIZE_GB does not exist by default.
See https://www.veritas.com/content/support/en_US/doc/18716246-126559472-0/v102811263-126559472
I cannot tell you what to change and what caused bptm logging to stop.
What about bpbrm logs? and bpdm? anything in these directories?
All of these processes are media server processes that run during backup and restore.
If you run 'ps -ef' on media server while a backup (or restore) is running, you will see one or more bptm process.
The PID of the process is what we see in square brackets in the log file.
Has anyone perhaps moved logs somewhere else and created incorrect symbolic links?
Can you show us output of 'df -h' ?
Then, 'cd /usr/openv/netbackup/logs', and show output of these commands:
pwd
ls -l *
du -sh *
You need someone with good Unix knowledge to 'walk' the filesystems with you to see what is causing the issue.
You should ideally log a support call with Veritas, but they may have an issue with your 7.7 version that has run out of support.
If you log a call with this description, you may be lucky:
"Failed Catalog backup in preparation of 8.x upgrade'.
11-14-2019 08:43 AM
Hi Marianne,
i verified and it's a link: lrwxrwxrwx 1 root root 14 Feb 23 2015 logs -> /log/netbackup
I got solution on logs, because i saw the date/hour wrong. I've updated date and now the logs are present.
Regarding Catalog backup error, i see this:
16:45:44.047 [130204] <32> bp_sts_close_target_image: sts_close_handle failed: 2060057
16:45:44.047 [130204] <2> set_job_details: Tfile (3153615): LOG 1573746344 32 bptm 130204 cannot write image to disk, media close failed with status 2060057 OpenStorage Proxy Plugin Error
16:45:44.047 [130204] <2> send_job_file: job ID 3153615, ftype = 3 msg len = 128, msg = LOG 1573746344 32 bptm 130204 cannot write image to disk, media close failed with status 2060057 OpenStorage Proxy Plugin Error
16:45:45.885 [130204] <2> ost_proxy_backup: should not be here
16:45:45.886 [130204] <2> signal_parent: sending SIGUSR1 to bpbrm (pid = 130162)
16:45:45.886 [130204] <2> bptm: EXITING with status 87 <----------
16:45:45.886 [130204] <2> set_job_details: Tfile (3153615): LOG 1573746345 4 bptm 130204 EXITING with status 87 <----------
16:45:45.886 [130204] <2> send_job_file: job ID 3153615, ftype = 3 msg len = 64, msg = LOG 1573746345 4 bptm 130204 EXITING with status 87 <----------
16:45:45.886 [130204] <2> bp_sts_close_server: STS session not initialized
Thanks and Regards,
11-14-2019 12:01 PM
Was this working at one point or is this a new configuration?
Could you please upload the entire BPTM logs for the failed job.
11-15-2019 12:51 AM
I agree with @Krutons - there is not enough info in the log snippet.
Even the log_backup.txt that you supplied - for some reason you deleted all timestamps.
I would've liked to compare this portion in Job details with bptm log :
Info bptm (pid=208914) start
Info bptm (pid=208914) using 262144 data buffer size
Info bptm (pid=208914) using 30 data buffers
Info media_srv_appl_1 (pid=208914) Using OpenStorage client direct to backup from client master_server_01 to media_srv_appl_1
Info dbclient (pid=4244) bpbkar waited 920 times for empty buffer, delayed 14568 times
Info dbclient (pid=4244) done. status: 0
Critical bptm (pid=208914) sts_close_handle failed: 2060057 OpenStorage Proxy Plugin Error
I have tried to search for information related to Advanced Disk and 'error 2060057 OpenStorage Proxy Plugin Error' or 'sts_open_server failed: error 2060057 ' or even just Advanced Disk and status 87.
I cannot find anything - all references are related to Dedupe and/or Accelerator.
Have you tried to backup something else to this STU? Just a small folder?
Is that working?
Any errors in bpdm log for this diskpool?
Do you have anywhere else to backup the Catalog while you are trying to find out what is wrong with this storage?
11-15-2019 01:06 AM
There is something else that is worrying me :
@albatroz19 wrote:
Hi Marianne,
i verified and it's a link: lrwxrwxrwx 1 root root 14 Feb 23 2015 logs -> /log/netbackup
I got solution on logs, because i saw the date/hour wrong. I've updated date and now the logs are present........
16:45:45.885 [130204] <2> ost_proxy_backup: should not be here
Can you please tell us what is/was wrong with date/time on this Appliance?
I am trying to figure out what this means - ' ost_proxy_backup: should not be here ' perhaps something to do with incorrect date/time on this appliance?
You really need to give us more info or else log a call with Veritas Support.
11-15-2019 06:13 AM - edited 11-15-2019 06:14 AM
Also noticed that it looks like he is doing client direct backups (client side dedupe) to an advanced disk pool which isn't a deduplicated disk pool. He did say he also tried to go to an MSDP pool though.
Have you tried this backup without client side dedupe?
11-22-2019 01:58 AM
Hi,
The Appliance's date was wrong due to NTP service misconfigured, and (I don't know how) the netbackup logs on this, was not updated. We corrected NTP sync and then the netbackup logs has been update and now run correctly.
For backup Catalog error, we configured on other media server msdp and now run correctly.
Many thanks to all, for ever support me.
Bye