06-07-2012 07:01 AM
Running NBU 7.0.1 on W2K3 Master server. Trying to do a restore to a CIFS share which fails. I saw a similar thread in April about this but there wasn't a resolution on it, so I thought I would re-open it. I am able to map a drive to the share using the same service account as the one I use for backups and successfully copy a file there, so I don't think it is a permissions issue. I do notice that the restore creates an empty file in the new directory with the correct name, but it has 0 bytes. Below is the output for my TAR for the restore:
7:17:47.812 AM: [4720.4888] <2> WinMain: DAT - _pgmptr = 'C:\Program Files\Veritas\NetBackup\bin\tar32.exe'
7:17:47.812 AM: [4720.4888] <2> WinMain: DAT - lpCmdLine = '-x -v -Y -p -P -I 1339075026 -U 13 -E /C/Programà€ Files/Veritas/NetBackup/logs/ALTPATH/ALTPATH.001 -k -J clnt_lc_messages=en -J clnt_lc_time=en -J clnt_lc_ctype=en -J clnt_lc_collate=en -J clnt_lc_numeric=en -J restoreid=2178160.001 -J job_total=1 -J client=srvycstorcava -J requesting_client=srvycstorcava -J browse_client=srvycstorcava -f - -J backup_time=1339004442 -L /C/Programà€ Files/Veritas/NetBackup/logs/user_ops/gronk/logs/NBWIN001 -J spsrestoreoptions=0 '
7:17:47.812 AM: [4720.4888] <2> date_debug: DAT - timezone: Mountain Standard Time, offset=25200, dst: Mountain Daylight Time
7:17:47.812 AM: [4720.4888] <2> date_debug: DAT - current time: 1339075067, 6/7/2012 7:17:47 AM
7:17:47.812 AM: [4720.4888] <2> date_debug: DAT - 01/01/94 UCT: 757382400, 12/31/1993 6:00:00 PM
7:17:47.812 AM: [4720.4888] <2> date_debug: DAT - 07/01/94 UCT: 773020800, 6/30/1994 6:00:00 PM
7:17:47.937 AM: [4720.4888] <2> WinMain: DAT - standard input handle = 484
7:17:47.937 AM: [4720.4888] <2> WinMain: DAT - standard output handle = 488
7:17:47.937 AM: [4720.4888] <2> WinMain: DAT - standard error handle = 492
7:17:49.078 AM: [4720.4888] <2> tar_process_restore_args: TRV - did not change name of file: /C/Programà€ Files/Veritas/NetBackup/logs/ALTPATH/ALTPATH.001
7:17:49.078 AM: [4720.4888] <4> backup_list: INF - creating restore object
7:17:49.078 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:17:49.078 AM: [4720.4888] <2> tar_process_restore_args: TRV - did not change name of file: /C/Programà€ Files/Veritas/NetBackup/logs/ALTPATH/ALTPATH.001
7:17:49.078 AM: [4720.4888] <4> tar_restore_tfi::create: INF - dwJobData: ffffffff
7:17:49.078 AM: [4720.4888] <4> tar_restore_tfi::create: INF - dwJob: ffffffff
7:17:49.078 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - restore privileges enabled, previous = 0
7:17:49.078 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - backup privileges enabled, previous = 0
7:17:49.078 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - security privileges enabled, previous = 0
7:17:49.078 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - create token privileges enabled, previous = 0
7:17:49.078 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - take ownership privileges enabled, previous = 0
7:17:49.500 AM: [4720.4888] <4> OVGetRestoreToken: INF - successfully wrote restore information to named pipe
7:17:49.500 AM: [4720.4888] <4> OVGetRestoreToken: INF - success obtaining access token
7:17:49.500 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - success obtaining access token: (000000000000022C)
7:17:49.500 AM: [4720.4888] <4> base_restore::tfs_enable_restore_privileges: INF - user has restore privileges
7:17:49.500 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:17:49.500 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:17:49.500 AM: [4720.3628] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 30 seconds
7:17:49.640 AM: [4720.2040] <2> ov_log::V_GlobalLog: WRN - ubsDetermineExchangeVersion(): RegOpenKeyEx() failed for HKLM\SOFTWARE\MICROSOFT\ExchangeServer\v14\Setup - 0x2.
7:17:49.640 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C:
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Shadow?Copy?Components
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State
7:17:49.687 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode
7:18:11.733 AM: [4720.4888] <2> tar_base::V_vTarMsgM: CKP - 2178160.001 1339075091 0 0 0 1 0 T 58 /\\YCVNX01CIFS01/CREATIVESERVICES/Sales Quote Printout.pdf
7:18:11.733 AM: [4720.4888] <2> tar_base::V_vTarMsgW: WRN - error writing file: \\YCVNX01CIFS01\CREATIVESERVICES\Restore4\Sales Quote Printout.pdf
7:18:11.733 AM: [4720.4888] <2> tar_base::V_vTarMsgW: WRN - disk full at byte: 0
7:18:11.733 AM: [4720.4888] <2> tar_base::V_vTarMsgW: WRN - wanted buffer size: 57476
7:18:11.733 AM: [4720.4888] <2> tar_base::backup_finish: TAR - restore: 1 files
7:18:11.733 AM: [4720.4888] <2> tar_base::backup_finish: TAR - restore: file data: 57476 bytes
7:18:11.733 AM: [4720.4888] <2> tar_base::backup_finish: TAR - restore: image data: 58880 bytes
7:18:11.733 AM: [4720.4888] <2> tar_base::backup_finish: TAR - restore: elapsed time: 21 secs 2803 bps
7:18:11.733 AM: [4720.4888] <8> tar_restore::processStateEOT: WRN - processStateEOT before keepalive
7:18:11.733 AM: [4720.3628] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)
7:18:11.733 AM: [4720.4888] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)
7:18:11.733 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:18:11.733 AM: [4720.4888] <2> tar_base::V_Close: closing...
7:18:11.733 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:18:11.749 AM: [4720.2040] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000001
7:18:11.749 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:18:11.749 AM: [4720.4888] <8> T_tar_rename::BMRApply: Cleaning up the BMR IDRInProgress and IDRSystemData config entries.
7:18:11.749 AM: [4720.4888] <4> OVStopCmd: INF - EXIT - status = 0
7:18:11.749 AM: [4720.4888] <4> OVShutdown: INF - Finished process
7:18:11.749 AM: [4720.4888] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\tar32.exe
7:18:13.749 AM: [4720.4888] <4> ov_log::OVClose: INF - Closing log file: C:\Program Files\Veritas\NetBackup\logs\TAR\060712.LOG
Any thoughts?
Dan
Solved! Go to Solution.
06-08-2012 08:13 AM
but all I see points to Windows permissions
06-07-2012 11:03 AM
try running 'As Administrator'
06-07-2012 11:26 AM
Nope, same error....
06-07-2012 06:17 PM
A few thoughts:
1) Diskspace should be sufficient as I can see you're restoring just a file.
2) Can you check this "Restore without access-control attributes (Windows clients only)" box when ask to do restore, see if it helps?
06-08-2012 06:10 AM
There is over a Terabyte of free space and this file is only 22 Mb.
If I check off the Restore without.... I get the following error.
07:08:00 6/8/2012: Restore Started
07:08:25 (2179354.001) Restoring from copy 1 of image created 6/6/2012 11:40:42 AM
07:08:42 (2179354.001) INF - TAR STARTED
07:09:02 (2179354.001) INF - Beginning restore from server srvhgnbs01 to client srvycstorcava.
07:09:09 (2179354.001) TAR - \\YCVNX01CIFS01\CREATIVESERVICES\Sales Quote Printout.pdf
07:09:09 (2179354.001) MNR - The file was renamed to the following:
07:09:09 (2179354.001) UTF - \\YCVNX01CIFS01\CREATIVESERVICES\Restore8\Sales Quote Printout.pdf
07:09:09 (2179354.001) ERR - unable to restore \\YCVNX01CIFS01\CREATIVESERVICES\Restore8\Sales Quote Printout.pdf (WIN32 1314: A required privilege is not held by the client. )
07:09:09 (2179354.001) INF - TAR EXITING WITH STATUS = 5
07:09:09 (2179354.001) INF - TAR RESTORED 0 OF 1 FILES SUCCESSFULLY
07:09:09 (2179354.001) INF - TAR KEPT 0 EXISTING FILES
07:09:09 (2179354.001) INF - TAR PARTIALLY RESTORED 0 FILES
07:09:18 (2179354.001) Status of restore from copy 1 of image created 6/6/2012 11:40:42 AM = tar did not find all the files to be restored
07:09:24 (2179354.xxx) INF - Status = the restore failed to recover the requested files.
06-08-2012 06:23 AM
This behavior can occur if the Administrators group has been removed from the "Backup Files and Directories" user right.
06-08-2012 06:26 AM
Either change the permissions of the enterprise log on account, or specify a different account to run the client service
06-08-2012 06:37 AM
We thought about that as well....I have tried restoring the file using an account that has Domain Admin priveledges with no luck. If it was permissions, then the file and directory wouldn't get created. They get created, but then NBU thinks there is no space to restore the file. That is where I am stumped.
06-08-2012 08:13 AM
but all I see points to Windows permissions
06-08-2012 09:14 AM
We figured it out.....you were right, it was a permissions problem. The CIFS server had been moved to a different OU by someone which stripped out some critical permissions. That person has now been soundly beaten.
Thanks for you help guys.