Forum Discussion
A bit more info pulled from the client side bpbkar log:
14:57:19.066 [7160.8920] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = X:\pagefile.sys
...
14:57:19.081 [7160.8920] <4> tar_backup_tfi::create: INF - after m_pBackupObject->V_Initialize(1)
14:57:19.081 [7160.8920] <4> tar_backup_tfi::create: INF - after m_pBackupObject->V_Initialize(1)
14:57:19.081 [7160.8920] <4> tar_backup_tfi::create: INF - after m_vxbsa_object->initialize
14:57:19.081 [7160.8920] <2> tar_backup_vxbsa::add: INF - called with 'X:\pagefile.sys'
14:57:19.081 [7160.8920] <2> _expand_root: INF - checking for root expansion:<X:\pagefile.sys>
14:57:19.081 [7160.8920] <2> _fix_registry: INF - checking for registry expansion:<X:\pagefile.sys>
14:57:19.081 [7160.8920] <4> dos_backup::V_VerifyFileSystem: INF - corrected name:<X:\pagefile.sys>
14:57:19.081 [7160.8920] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'X:\pagefile.sys' --> 10020002
14:57:19.097 [7160.8920] <2> VxCJUtilGetParams: INF - GetVolumePathName for <X:\pagefile.sys> returned <X:\>
14:57:19.097 [7160.8920] <2> VxCJUtilGetParams: INF - GetVolumeNameForVolumeMountPoint for <X:\> returned <\\?\Volume{8a554feb-9105-4aed-8342-d66aebc4b42e}\>
14:57:19.097 [7160.8920] <2> tar_base::V_vTarMsgW: JBD - not using change journal data for <X:\pagefile.sys>: not enabled
14:57:19.097 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 71 of 71 bytes
14:57:19.097 [7160.8920] <4> dos_backup::V_Initialize: INF - did not create change journal collection, not needed
.... we go off into the world of Shadow Copy Components, with no apparent errors, then move on to the actual processing
14:57:26.316 [7160.8920] <2> ov_log::V_GlobalLog: INF - v_beds::V_FindFirst() EXIT Name:Shadow Copy Components: bRC:true LastError:0x0:
14:57:26.316 [7160.8920] <2> TransporterLegacyLocal::winClientShm(): DBG - Mapping for shared memory is Global\NetBackup Media Manager SHM Info Path MEDIASERVER_1574193396 (../TransporterLegacyLocal.cpp:601)
14:57:27.332 [7160.8920] <2> TransporterLegacyLocal::winClientShm(): DBG - Multiplex tape backup is initiated. (../TransporterLegacyLocal.cpp:666)
14:57:27.332 [7160.8920] <2> TransporterLegacyLocal::winClientShm(): DBG - Shared memory detail media_shm_info = 1024 524288 967819078 12584 1 1 1 967819078 1 (../TransporterLegacyLocal.cpp:677)
14:57:27.332 [7160.8920] <2> TransporterLegacyLocal::winClientShm(): DBG - backup time in mpx headers is 1574193396 (../TransporterLegacyLocal.cpp:751)
14:57:27.332 [7160.8920] <2> TransporterLegacyLocal::winClientShm(): DBG - SHMID = 967819078, BUF_PTR = 0x000000009fff0000 , BUF_CONTROL = 0x0000000002556008 , readyptr = 0x000000000255c008 (../TransporterLegacyLocal.cpp:785)
14:57:27.519 [7160.8920] <2> Packer::open(): DBG - Started Backup... (../Packer.cpp:272)
14:57:27.519 [7160.8920] <4> backup_create: INF - after backup_class->create.
14:57:27.519 [7160.8920] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
14:57:27.519 [7160.8920] <4> backup_create: INF - before iINI->GetFileList(OV_EXCLUDE, &dwListCt)
14:57:27.519 [7160.8920] <4> backup_create: INF - after iINI->GetFileList(OV_EXCLUDE, &dwListCt)
14:57:27.519 [7160.8920] <4> backup_create: INF - before pOVMatchPList[i]->OVAdd loop dwListCt = 23
14:57:27.519 [7160.8920] <4> backup_create: INF - after pOVMatchPList[i]->OVAdd loop
14:57:27.519 [7160.8920] <4> backup_create: INF - after iINI->GetFileList
14:57:27.535 [7160.8920] <2> vnet_pcache_init_table: [vnet_private.c:214] starting cache size 200 0xc8
14:57:27.535 [7160.8920] <4> backup_create: INF - after backup_class->SetExcludeFileList
14:57:27.535 [7160.8920] <4> backup_create: INF - after iINI->GetFileList
14:57:27.535 [7160.8920] <4> tar_backup::SetIncludeFileList: INF - Starting VDS thread
14:57:27.535 [7160.8920] <4> tar_backup_tfi::UpdateExcludeListWithVHD: INF - UpdateExludeListWithVHD begin
14:57:27.535 [7160.8920] <4> backup_create: INF - after backup_class->SetIncludeFileList
14:57:27.535 [7160.8920] <2> tar_base::V_vTarMsgW: INF - Estimate:-1 -1
14:57:27.535 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 21 of 21 bytes
14:57:27.535 [7160.8920] <4> tar_backup_tfi::backup_arg_state: INF - V_MODE_BACKUP:Mark transition from estimation state
14:57:27.535 [7160.8920] <4> tar_backup_tfi::backup_arg_state: INF - remember start error count: 0
14:57:27.535 [7160.8920] <4> tar_backup_tfi::backup_arg_state: INF - remember start fatal count: 0
14:57:27.535 [7160.8920] <2> tar_backup_tfi::backup_arg_state: Is ALL_LOCAL_DRIVE Backup = 0
14:57:27.535 [7160.8920] <2> tar_backup_tfi::backup_arg_state: Backup selections for accurate licensing ---- backup_selections = X:\pagefile.sys, backup_size = 0
14:57:27.535 [7160.8920] <4> dos_backup::tfs_scanstart: INF - starting scan for file directive:<X:\pagefile.sys>
14:57:27.535 [7160.8920] <4> dos_backup::tfs_scanstart: INF - starting scan using name:<X:\pagefile.sys>
14:57:27.535 [7160.8920] <4> dos_backup::tfs_scanstart: INF - in 'backup' mode
14:57:27.550 [7160.8920] <4> dos_backup::tfs_startdir: INF - volume guid:<\\?\Volume{8a554feb-9105-4aed-8342-d66aebc4b42e}\>
14:57:27.550 [7160.8920] <4> dos_backup::tfs_startdir: INF - volume mount point:<X:\>
14:57:27.550 [7160.8920] <4> dos_backup::tfs_network_drive_check: DAT - GetDriveType(X:\) returned 3
14:57:27.550 [7160.8920] <4> tar_base::V_vTarMsgW: INF - tar message received from dos_backup::_check_filters
14:57:27.550 [7160.8920] <2> tar_base::V_vTarMsgW: INF - Filtered 'FilesNotToBackup' Object: X:\pagefile.sys
14:57:27.550 [7160.8920] <4> dos_backup::tfs_scannext: INF - no more path list entries
14:57:27.550 [7160.8920] <4> tar_backup::backup_endarg_state: INF - finish error count: 0
14:57:27.550 [7160.8920] <4> tar_backup::backup_endarg_state: INF - finish fatal count: 0
14:57:27.550 [7160.8920] <4> tar_backup_tfi::backup_arg_state: INF - V_MODE_BACKUP:No need to do the estimate. Just continue the backup with the next file
14:57:27.550 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 65 of 65 bytes
14:57:27.550 [7160.8920] <4> tar_backup::backup_add_last_entry_state: INF - catalog message: Dfi - 0 0 0 -1 23 292 user other 0 0 0 0 /VRTS_IMAGE_SIZE_RECORD
14:57:27.550 [7160.8920] <2> tar_base::backup_finish: TAR - backup: 0 files
14:57:27.550 [7160.8920] <2> tar_base::backup_finish: TAR - backup: file data: 0 bytes
14:57:27.550 [7160.8920] <2> tar_base::backup_finish: TAR - backup: image data: 0 bytes
14:57:27.550 [7160.8920] <2> tar_base::backup_finish: TAR - backup: elapsed time: 9 secs 0 bps
14:57:27.550 [7160.8920] <2> tar_base::V_vTarMsgW: INF - Total Size:0
14:57:27.550 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 19 of 19 bytes
14:57:27.550 [7160.8920] <4> tar_backup::backup_done_state: INF - V_MODE_BACKUP_POST:
14:57:27.550 [7160.8920] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0
14:57:27.550 [7160.8920] <4> tar_backup::backup_done_state: INF - number of file directives found: 1
14:57:27.550 [7160.8920] <2> tar_base::V_vTarMsgW: INF - Client completed sending data for backup
14:57:27.550 [7160.8920] <2> ov_log::V_GlobalLogEx: KeepAliveThread::stopKeepAlive Waiting for keepalive thread to finish
14:57:27.550 [7160.8920] <4> tar_base::stopKeepaliveThread: INF - keepalive thread stopped
14:57:27.550 [7160.8920] <8> tar_backup_tfi::cleanupTemp: WRN - will not cleanup 'temp' directory, debug level(s) are too high
14:57:27.582 [7160.8920] <4> send_msg_to_monitor: INF - in send_msg_to_monitor()...
14:57:27.582 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 63 of 63 bytes
14:57:27.582 [7160.8920] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 0: the requested operation was successfully completed
14:57:27.582 [7160.8920] <2> dtcp_write: TCP - success: send socket (516), 72 of 72 bytes
14:57:27.582 [7160.8920] <2> dtcp_shutdown: TCP - success: shutdown socket (1456)
14:57:27.582 [7160.8920] <2> dtcp_shutdown: TCP - success: shutdown socket (532)
Yet, this is the error in the Activity Monitor:
Nov 19, 2019 2:57:18 PM - Info bpbrm (pid=11088) start bpbkar32 on client
Nov 19, 2019 2:57:18 PM - connected; connect time: 0:00:00
Nov 19, 2019 2:57:19 PM - Info bpbkar32 (pid=7160) Backup started
Nov 19, 2019 2:57:19 PM - Info bpbrm (pid=11088) Sending the file list to the client
Nov 19, 2019 2:57:19 PM - Info bpbkar32 (pid=7160) change time comparison:<disabled>
Nov 19, 2019 2:57:19 PM - Info bpbkar32 (pid=7160) archive bit processing:<disabled>
Nov 19, 2019 2:57:19 PM - Info bpbkar32 (pid=7160) not using change journal data for <X:\pagefile.sys>: not enabled
Nov 19, 2019 2:57:27 PM - Info bpbkar32 (pid=7160) bpbkar waited 0 times for empty buffer, delayed 0 times.
Nov 19, 2019 2:58:21 PM - mounted H06228; mount time: 0:01:14
Nov 19, 2019 2:58:27 PM - positioning H06228 to file 1
Nov 19, 2019 2:58:41 PM - positioned H06228; position time: 0:00:14
Nov 19, 2019 2:58:41 PM - begin writing
Nov 19, 2019 2:58:54 PM - Info bpbrm (pid=11036) media manager for backup id MEDIASERVER_1574193396 exited with status 90: media manager received no data for backup image
Nov 19, 2019 2:58:57 PM - Info bpbrm (pid=11036) child done, status 90
Nov 19, 2019 2:58:57 PM - end writing; write time: 0:00:16
As I understand things, we should have looked at the file list, looked at the FilesNotToBackup + the exclude list, and gone "Ah ha! we don't need to backup X:\pagefile.sys", and simply stopped processing the job and shut it down cleanly, not mount a tape in a drive, then proceed to complain we got no data. This appears to work perfectly well for the Diff. Inc. schedule as there are never any SC 90's for this.
- DK125 years agoLevel 3
Seems I've hit on one that no one has any feedback on. I do seem to get those.
I'll be punting this to Veritas early next week - PTO starts in about an hour and a half, and I'd rather not be late for that!
I did do the same trace on the diff. backup and yup. it does not generate a SC 90 at any point. To be honest, It would be better if the job simply didn't fire up, but I do get how product works most of it's logic.
Related Content
- 9 years ago
- 3 years ago
- 2 months ago