Image cleanup jobs failing with "media manager - system error occurred(174)" and backups jobs failing with "media open error(83)"

[Juasiepo]

Hi,

I have Image cleanup jobs failing with "media manager - system error occurred(174)" and backups jobs failing with "media open error(83)"

This two events are related as the Cleanup image job is failing in th image svpfil05_1363977060_C1_F1 and the backup failing is from server svpfil05

Here you are the failing Cleanup image job logs:

17/05/2013 06:29:15 - begin
17/05/2013 06:29:17 - Info nbdelete(pid=14502) deleting expired images. Media Server: ochlp-bak002 Media: @aaabn     
17/05/2013 06:29:17 - requesting resource @aaabn
17/05/2013 06:29:17 - granted resource MediaID=@aaabn;DiskVolume=PureDiskVolume;DiskPool=dbPoolBO;Path=PureDiskVolume;StorageServer=ochlp-bak002;MediaServer=ochlp-bak002
17/05/2013 06:29:18 - Info bpdm(pid=7511) started            
17/05/2013 06:29:18 - started process bpdm (7511)
17/05/2013 06:29:18 - Info bpdm(pid=7511) initial volume PureDiskVolume: Kbytes total capacity: 35060438608, used space: 19538642492, free space: 15521796116
17/05/2013 06:29:18 - Critical bpdm(pid=7511) sts_delete_image of image svpfil05_1363977060_C1_F1 failed: error 2060029 authorization failure    
17/05/2013 06:29:19 - Critical bpdm(pid=7511) image delete failed: error 2060029: authorization failure      
17/05/2013 06:29:19 - Info bpdm(pid=7511) ending volume PureDiskVolume: Kbytes total capacity: 35060438608, used space: 19538642492, free space: 15521796116
17/05/2013 06:29:19 - end ; elapsed time: 00:00:04
media manager - system error occurred(174)

And here the failing backup job logs:

17/05/2013 06:26:21 - Info nbjm(pid=22176) starting backup job (jobid=305307) for client svpfil05, policy win_prod_PST, schedule Daily_CInc  
17/05/2013 06:26:21 - Info nbjm(pid=22176) requesting STANDARD_RESOURCE resources from RB for backup job (jobid=305307, request id:{ED3CE2F6-BEA9-11E2-B2B2-576F894D4C1C})  
17/05/2013 06:26:21 - requesting resource DEDUP-BO-STU
17/05/2013 06:26:21 - requesting resource server.NBU_CLIENT.MAXJOBS.svpfil05
17/05/2013 06:26:21 - requesting resource server.NBU_POLICY.MAXJOBS.win_prod_PST
17/05/2013 06:26:22 - granted resource server.NBU_CLIENT.MAXJOBS.svpfil05
17/05/2013 06:26:22 - granted resource server.NBU_POLICY.MAXJOBS.win_prod_PST
17/05/2013 06:26:22 - granted resource MediaID=@aaabn;DiskVolume=PureDiskVolume;DiskPool=dbPoolBO;Path=PureDiskVolume;StorageServer=ochlp-bak002;MediaServer=ochlp-bak002
17/05/2013 06:26:22 - granted resource DEDUP-BO-STU
17/05/2013 06:26:27 - estimated 289682469 Kbytes needed
17/05/2013 06:26:27 - Info nbjm(pid=22176) started backup (backupid=svpfil05_1368764787) job for client svpfil05, policy win_prod_PST, schedule Daily_CInc on storage unit DEDUP-BO-STU
17/05/2013 06:26:27 - started process bpbrm (6518)
17/05/2013 06:26:55 - Info bpbrm(pid=6518) svpfil05 is the host to backup data from     
17/05/2013 06:26:55 - Info bpbrm(pid=6518) reading file list from client        
17/05/2013 06:27:05 - Info bpbrm(pid=6518) accelerator enabled           
17/05/2013 06:27:09 - connecting
17/05/2013 06:27:19 - Info bpbrm(pid=6518) starting bpbkar on client         
17/05/2013 06:27:19 - Info bpbkar(pid=8604) Backup started           
17/05/2013 06:27:19 - Info bpbrm(pid=6518) bptm pid: 6773          
17/05/2013 06:27:19 - connected; connect time: 00:00:10
17/05/2013 06:27:20 - Info bptm(pid=6773) start            
17/05/2013 06:27:20 - Info bptm(pid=6773) using 262144 data buffer size        
17/05/2013 06:27:20 - Info bptm(pid=6773) setting receive network buffer to 1048576 bytes      
17/05/2013 06:27:20 - Info bptm(pid=6773) using 32 data buffers         
17/05/2013 06:27:20 - Info ochlp-bak002(pid=6773) Using OpenStorage client direct to backup from client svpfil05 to ochlp-bak002  
17/05/2013 06:28:02 - begin writing
17/05/2013 06:28:04 - Info bpbkar(pid=8604) change journal enabled for <K:\pst\g*>        
17/05/2013 06:28:04 - Info bpbkar(pid=8604) NOT using change journal data for <K:\pst\g*>: unable to locate journal data
17/05/2013 06:29:15 - Critical bptm(pid=6773) image open failed: error 2060029: authorization failure      
17/05/2013 06:29:19 - Info bptm(pid=6773) EXITING with status 83 <----------        
17/05/2013 06:29:23 - Info bpbkar(pid=8604) done. status: 83: media open error       
17/05/2013 06:29:23 - end writing; write time: 00:01:21
media open error(83)

I have already tried with the procedure Image Cleanup job failing with error "media manager - system error occurred(174)" with no luck

Any idea?

Best regards.

[Jaykullar]

Can you post a bpps and crcontrol --dsstat from your storage server please.

[Marianne]

Was there more than one backup done for this client? Mixed case in client name for the different backups?

I had the same error when I ran a backup for my laptop as Marianne-Win7 as Client name, and then a couple of weeks later as marianne-win7:

05/08/2013 17:06:54 - begin writing
05/08/2013 17:06:55 - Critical bptm (pid=11991) image open failed: error 2060029: authorization failure
05/08/2013 17:07:01 - Critical bptm (pid=11991) sts_close_server failed: error 2060057 OpenStorage Proxy Plugin Error
05/08/2013 17:07:01 - Critical bptm (pid=11991) sts_get_server_prop failed: error 2060057 OpenStorage Proxy Plugin Error
05/08/2013 17:07:59 - Info bptm (pid=11991) EXITING with status 83 <----------

Fixed when I created a symbolic link on the appliance in dedupe database folder:
 

cd /disk/databases/catalog/2

drwx------ 3 root root  96 Oct  9  2012 Marianne-Win7

lrwxrwxrwx 1 root root  13 May  8 17:36 marianne-win7 -> Marianne-Win7

[Juasiepo]

Hi

[root@server 2]# crcontrol --dsstat
************ Data Store statistics ************
Data storage      Raw    Size   Used   Avail  Use%
                  34,0T  32,7T  17,4T  15,2T  54%
Number of containers             : 139420
Average container size           : 180050943 bytes (171,71MB)
Space allocated for containers   : 25102702483401 bytes (22,83TB)
Space used within containers     : 24643599549191 bytes (22,41TB)
Space available within containers: 459102934210 bytes (427,57GB)
Space needs compaction           : 6003808602015 bytes (5,46TB)
Reserved space                   : 1511901052928 bytes (1,38TB)
Reserved space percentage        : 4,0%
Records marked for compaction    : 152153556
Active records                   : 285180597
Total records                    : 437334153

[root@server 2]# bpps
root      5174     1  0 10:29 ?        00:00:00 /usr/openv/netbackup/bin/vnetd -standalone
root      5181     1  0 10:29 ?        00:00:00 /usr/openv/netbackup/bin/bpcd -standalone
root      5298     1  0 10:29 ?        00:00:33 /usr/openv/pdde/pdcr/bin/spad
pddb      5488     1  0 10:29 ?        00:00:00 /usr/openv/pdde/pddb/bin/postmaster -D /deduplication/databases/pddb/data -N 512 -B 1024 -i -p10085
root      5851     1 33 10:30 ?        01:59:37 /usr/openv/pdde/pdcr/bin/spoold
root      5918     1  0 10:30 ?        00:00:00 /usr/openv/netbackup/bin/bpcompatd
root      5951     1  0 10:30 ?        00:00:08 /usr/openv/netbackup/bin/nbrmms
root      6000     1  0 10:30 ?        00:00:17 /usr/openv/netbackup/bin/nbsl
root      6046     1  0 10:30 ?        00:00:01 /usr/openv/netbackup/bin/nbcssc -a NetBackup
root      6071     1  0 10:30 ?        00:00:02 /usr/openv/netbackup/bin/nbsvcmon
root      6431  5951  0 10:31 ?        00:00:11 /usr/openv/netbackup/bin/admincmd/bpstsinfo -DPSPROXY
 

Thank you for your time

Best Regards

[Juasiepo]

Hello,

Was there more than one backup done for this client? Mixed case in client name for the different backups?

Yes, there are several polices running for this server:

• Normal backup policy: system state, C: and D: drives. This one runs without problems
• Customized backup for drive K: which contains many PSTs files. This one is the failing one

It seems the same error you described, but I have already checked the path you provided and soft links already exists

drwx------ 12 root root 4096 may  2 09:50 svpfil05
lrwxrwxrwx  1 root root    8 may 10 13:04 SVPFIL05 -> svpfil05
lrwxrwxrwx  1 root root    8 may 11 10:44 svpfil05.domain.tld -> svpfil05
lrwxrwxrwx  1 root root    8 may 11 10:44 SVPFIL05.domain.tld -> svpfil05

Did you have the same problem with the Image cleaup jobs?

Thank you for your time

Best regards

[Mark_Solutions]

OK - I have seen this get even worse recently!

First it must be said that client names in policies using mixed case with MSDP is not classed as unsupported so you do need to actually sort those out

Next, go one step deeper into the catalog

Inside the clients folder you will see a folder with the policy name (and if i remeber right the schedule name is under that (maybe!)

Her you can get an issue if a policy has been re-created so look carefully at the current policy name and see if it is in exactly the same case as the current folders - you may need to create soft links within the client folders too

Hope this helps - all confusing and really hard to spot the error - sometime you need to look at the actual image name and how that relates to the folder names to spot where the difference is and how the softlink needs to be done

[Juasiepo]

Hello

I have checked the policy names and they are the same in the netbackup console and in the /deduplication/databases/catalog/2/svpfil05 path.

The failing backup policy is win_prod_PST (special policy por PSTs files) and the other policy that runs OK  in this server is Win_Prod_Daily (standard policy for C:/D: drives and System State)

Within the Win_Prod_Daily folder there are several files named as the failing image in the Image cleanup jobs

17/05/2013 06:29:18 - Critical bpdm(pid=7511) sts_delete_image of image svpfil05_1363977060_C1_F1 failed: error 2060029 authorization failure

./win_prod_PST/svpfil05_1363977060_C1_F1.info
./win_prod_PST/svpfil05_1363977060_C1_F1.img
./win_prod_PST/svpfil05_1363977060_C1_F1.hdr
./win_prod_PST/svpfil05_1363977060_C1_F1.map
./win_prod_PST/svpfil05_1363977060_C1_F2.img
./win_prod_PST/svpfil05_1363977060_C1_F2.hdr
./win_prod_PST/svpfil05_1363977060_C1_F2.map
./win_prod_PST/svpfil05_1363977060_C1_HDR.img

The bizarre thing about this is that the failing policy folders doesn't have these folders. They are located in the policy that runs OK

Any other Idea?

Thank you for your time

Best Regards

[Mark_Solutions]

Sounds like your softlinks are not working somewhere then - double check it all again

If they are right then when you look in the upper and lower case folders what you see should be the same

If you cannot see the failing policy folder then you need to search for them - there may be yet another folder that needs to be softlinked

So you may have svpfil05, Svpfil05 and svpFil05 or similar if you see what i mean

Hope this helps

[Juasiepo]

Hi

At server name folder level, soft link seem to work fine:

[root@ochlp-bak002 2]# ls -l|grep svpfil05
drwx------ 12 root root 4096 may  2 09:50 svpfil05
lrwxrwxrwx  1 root root    8 may 10 13:04 SVPFIL05 -> svpfil05
lrwxrwxrwx  1 root root    8 may 11 10:44 svpfil05.domain.tld -> svpfil05
lrwxrwxrwx  1 root root    8 may 11 10:44 SVPFIL05.domain.tld -> svpfil05
[root@ochlp-bak002 2]# cd SVPFIL05
[root@ochlp-bak002 SVPFIL05]# pwd
/deduplication/databases/catalog/2/SVPFIL05
[root@ochlp-bak002 SVPFIL05]# ls
__dirpo__       Win_Prod_Daily1              Win_Prod_Daily_NoAccel   win_prod_PST    win_prod_PST_2        Win-prueba
Win_Prod_Daily  Win_Prod_Daily_Fax_No_Accel  Win_Prod_Daily_svpfil05  win_prod_PST_1  win_prod_PST_Archive

[root@ochlp-bak002 SVPFIL05]# cd ..
[root@ochlp-bak002 2]# cd svpfil05.domain.tld
[root@ochlp-bak002 svpfil05.domain.tld]# pwd
/deduplication/databases/catalog/2/svpfil05.domain.tld
[root@ochlp-bak002 svpfil05.domain.tld]# ls
__dirpo__       Win_Prod_Daily1              Win_Prod_Daily_NoAccel   win_prod_PST    win_prod_PST_2        Win-prueba
Win_Prod_Daily  Win_Prod_Daily_Fax_No_Accel  Win_Prod_Daily_svpfil05  win_prod_PST_1  win_prod_PST_Archive
[root@ochlp-bak002 svpfil05.domain.tld]# cd ..

[root@ochlp-bak002 2]# cd SVPFIL05.domain.tld
[root@ochlp-bak002 SVPFIL05.domain.tld]# ls
__dirpo__       Win_Prod_Daily1              Win_Prod_Daily_NoAccel   win_prod_PST    win_prod_PST_2        Win-prueba
Win_Prod_Daily  Win_Prod_Daily_Fax_No_Accel  Win_Prod_Daily_svpfil05  win_prod_PST_1  win_prod_PST_Archive

At policy name folder level:

[root@ochlp-bak002 SVPFIL05.domain.tld]# ls -ltr
total 484
-rw-r----- 1 root root     76 dic  8 17:33 __dirpo__
drwx------ 2 root root     22 dic  8 19:00 Win_Prod_Daily1
drwx------ 2 root root     22 mar 10 10:36 Win-prueba
drwx------ 2 root root  40960 abr 20 22:10 win_prod_PST_1
drwx------ 2 root root  40960 abr 22 02:03 win_prod_PST_2
drwx------ 2 root root     22 abr 24 19:39 Win_Prod_Daily_Fax_No_Accel
drwx------ 2 root root   4096 abr 25 13:08 Win_Prod_Daily_NoAccel
drwx------ 2 root root  12288 may 10 01:13 win_prod_PST_Archive
drwx------ 2 root root 131072 may 16 06:36 Win_Prod_Daily_svpfil05
drwx------ 2 root root 184320 may 16 23:49 win_prod_PST
drwx------ 2 root root   8192 may 17 11:44 Win_Prod_Daily

at policy name catalog level:

[root@ochlp-bak002 SVPFIL05.domain.tld]# bppllist |grep Win_Prod_Daily
Win_Prod_Daily
Win_Prod_Daily1
Win_Prod_Daily10
Win_Prod_Daily2
Win_Prod_Daily3
Win_Prod_Daily4
Win_Prod_Daily5
Win_Prod_Daily6
Win_Prod_Daily7
Win_Prod_Daily8
Win_Prod_Daily9
Win_Prod_Daily_Fax_No_Accel
Win_Prod_Daily_NoAcel
Win_Prod_Daily_Tape
Win_Prod_Daily_svpfil05
Win_Prod_Daily_test
[root@ochlp-bak002 SVPFIL05.domain.tld]# bppllist |grep win_prod_PST
win_prod_PST
win_prod_PST_1
win_prod_PST_2
win_prod_PST_Archive

So they have the same policy name too. ¿? I don't see any differences.

Thank you for your time

[Marianne]

I did not have any image cleanup failure as my first backup with lowercase name failed.

It took me overnight to remember Mark's similar experience.
I immediately created the symlink in the dedupe database folder as well as in /usr/openv/netbackup/db/images folder.
Subsequent backups and image cleanups were successful.
Sorry if that doesn't help you.

[Juasiepo]

In order to work around the problem with policy win_prod_PST I have copied it to a renamed one win_prod_PST_svpfil05. This workaround works ok but The problem is still there.

[huanglao2002]

From the image clean log

"

17/05/2013 06:29:18 - Critical bpdm(pid=7511) sts_delete_image of image svpfil05_1363977060_C1_F1 failed: error 2060029 authorization failure
17/05/2013 06:29:19 - Critical bpdm(pid=7511) image delete failed: error 2060029: authorization failure     

"

It's mean Netbackup can't use STS server access Puredisk pool,please try to readd the credential.

tpconfig -add -storage_server "STS server" -stype PureDisk -sts_user_id "user name"  -password "password"

the user name /passwd info are collect when you are create MSDP.

hope it's help.

[Juasiepo]

Hi,

This failing policy is the only one failing. And all policies are using the same storage server. So I don't think it is related to credentials. As If it were a credential problem, it would affect to more than one policy.

Thank for your time

Regards

BTW:  The workaround is working, so my server is being backuped up with the new policy, but I am still getting the Image Cleanup error. I opened a case with support and waiting their reply

[Mark_Solutions]

If just the image cleanup is now failing then we need to look at exactly which image it cannot cleanup as that is where the problem lies.

You have obviously identified where the actual image resides (./win_prod_PST/) but NetBackup is looking somewhere else for it - so obviously one of the other folders that is involved in this.

Two ways around this (being very careful as always!!)

1. Link the sub folders and not just the top level client folders

2. Copy those images files for the problem image into the other folders

As you have now changed the policy etc and that is working OK then you should not get the error in the future, so if you use the copy method it will at least allow NetBackup to successfully run the image cleanup to get rid of your error and after that some queue processing, garbage collection and rebasing should clean it all up

Once the files have dissapeared out of one of the folders (which will tell you where it has been looking all this time) then you should be able to remove them from the other folders too

Hope this helps

[Juasiepo]

Hi Mark,

I have been looking into the bptm logs, and I have found this:

21:36:35.562 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDVFS: _pdvfs_filldir_mb: pdvfs_cas_mb_get_first failed: unknown error (4)
21:36:35.562 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDVFS: _pdvfs_fill_dsid_subdir: failed scanning win_prod_PST
21:36:35.562 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDVFS: _pdvfs_find_entry: parent->get_info(win_prod_PST) failed: Permission denied (13)
21:36:35.562 [29755] <4> 312320:bptm:29755:ochlp-bak002: [INFO] PDVFS: find_entry_from_cache: exit can't find /ochlp-bak002#1/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info
21:36:35.562 [29755] <4> 312320:bptm:29755:ochlp-bak002: [INFO] PDVFS: PdvfsStat_mb: PdvfsStat_mb exit /ochlp-bak002#1/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info failed errno=13
21:36:35.562 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDSTS: impl_get_imh_image_prop: PdvfsStat(/ochlp-bak002#1/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info) failed (13:Permission denied)
21:36:35.562 [29755] <2> 312320:bptm:29755:ochlp-bak002: [DEBUG] PDSTS: impl_get_imh_image_prop: exit (2060029:authorization failure)
21:36:35.562 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDSTS: impl_image_handle: impl_get_imh_image_prop: unexpected error (2060029:authorization failure)
21:36:35.562 [29755] <2> 312320:bptm:29755:ochlp-bak002: [DEBUG] PDSTS: release_svh: svh:<0x2b0bae0>, nhandle:<2>
21:36:35.562 [29755] <2> 312320:bptm:29755:ochlp-bak002: [DEBUG] PDSTS: impl_image_handle: exit (2060029:authorization failure)
21:36:35.563 [29755] <16> 312320:bptm:29755:ochlp-bak002: [ERROR] PDSTS: impl_delete_image_legacy: could not remove svpfil05_1366133647_C1_F1 (2060029:authorization failure)

I cannot find in the directory tree the path /ochlp-bak002#1/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info The more similar path could be /deduplication/databases/catalog/2/svpfil05/win_prod_PST/ and it really does exists:

[root@ochlp-bak002 win_prod_PST]# ls -l /deduplication/databases/catalog/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info
-rw-r----- 1 root root 161 abr 16 21:42 /deduplication/databases/catalog/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info

So I don't know where the netbackup is looking for /ochlp-bak002#1/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info

Any other idea?

Thanks for your time.

Regards

[Mark_Solutions]

Can you show me an ls -lrt on that directory please.

Also, can you do a more on the .info file to see it contents? Wondering if it is actually corrupt.

Have you had a look in the spoold and storaged logs to see if they have any more clues?

[huanglao2002]

I'm sorry , my suggest don't help you.

If i encount this problem, i will call symc for support.  I think symc engineer know MSDP internal.

I only know how to install/use/uninstall MSDP.

[Juasiepo]

It has 3138 files:

[root@ochlp-bak002 win_prod_PST]# ls -ltr|wc -l
3138

So I have uploaded the ls -ltr output.
 

The svpfil05_1366133647_C1_F1.info file doesn't seem corrupted  to me:

[root@ochlp-bak002 win_prod_PST]# more /deduplication/databases/catalog/2/svpfil05/win_prod_PST/svpfil05_1366133647_C1_F1.info

0|||0|a68da3b2aaee8c4a88bdddaf89f7351f|01dff6331345c92c22ccaea91da20709|||0|N|0|0100600|0||260|1366140963|1366140963|1366140963|523||||0||PDVFS_2_F_0_ID_2_RT
_0|0

Nothing relevant found on spoold and storaged log files.

[Mark_Solutions]

OK, if you are sure there is nothing in the spoold and storaged logs then there does seem to be an issue with these files - as you do get the access denied error - so either corruption has crept in or the rights to those files (or at least the .info file) is not right

You will see that not all image sets have the .info files so at least this one has an issue and maybe when this is cleared others will then crop up too.

I think as we have nothing logged to help that you need to see what support comes up with

[Juasiepo · Accepted solution]

Hi,

After upgrading to 7.5.0.6, it seems that the error has dissapeared.

Regards