Log file for bpbkar:
Server: REALM23;
12:50:56.141 AM: [5552.4680] <2> tar_backupt_tfi::create: TAR - Incremental backup using file dates since: 14/12/2009 6:25:57 PM
12:50:56.141 AM: [5552.4680] <2> tar_base::V_vTarMsgW: TRV - BACKUP 20/12/2009 12:50:56 AM realm23.toll.com.au VCB-ESXDov143 Diff-Inc INCR 14/12/2009 6:25:57 PM
12:50:56.141 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 106 of 106 bytes
12:50:56.141 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 14 of 14 bytes
12:50:56.141 AM: [5552.4680] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
12:50:56.141 AM: [5552.4680] <2> tar_backup_tfi::setupFileDirectives: TAR - Processing filename list
12:50:56.141 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 4 of 4 bytes
12:50:56.141 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 197 of 197 bytes
12:50:56.141 AM: [5552.4680] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = BACKUP
\\.\C:\ USING
\\?\Volume{77be05d5-c512-11de-b007-001185e748c6}\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_8084,FITYPE=MIRROR,MNTPOINT=\\.\C:\,FSTYPE=NTFS
12:50:56.141 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 4 of 4 bytes
12:50:56.141 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 197 of 197 bytes
12:50:56.157 AM: [5552.4680] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = BACKUP
\\.\D:\ USING
\\?\Volume{45da82c6-cdbc-11de-a00d-001185e748c6}\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_8084,FITYPE=MIRROR,MNTPOINT=\\.\D:\,FSTYPE=NTFS
12:50:56.157 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 4 of 4 bytes
12:50:56.157 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 197 of 197 bytes
12:50:56.157 AM: [5552.4680] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = BACKUP
\\.\E:\ USING
\\?\Volume{45da82ff-cdbc-11de-a00d-001185e748c6}\ OPTIONS:ALT_PATH_PREFIX=C:\Program Files\Veritas\NetBackup\temp\_vrts_frzn_img_8084,FITYPE=MIRROR,MNTPOINT=\\.\E:\,FSTYPE=NTFS
12:50:56.157 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 4 of 4 bytes
12:50:56.157 AM: [5552.4680] <2> dtcp_read: TCP - success: recv socket (676), 8 of 8 bytes
12:50:56.157 AM: [5552.4680] <4> tar_base::startKeepaliveThread: INF - keepalive thread started
12:50:56.157 AM: [5552.6836] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
12:50:56.157 AM: [5552.6836] <2> dtcp_read: TCP - success: recv socket (676), 4 of 4 bytes
12:50:56.157 AM: [5552.6836] <4> bpio::read_string: INF - read non-blocking message of length 1
12:50:56.157 AM: [5552.6836] <2> dtcp_read: TCP - success: recv socket (676), 1 of 1 bytes
12:50:56.157 AM: [5552.6836] <4> tar_backup::readServerMessage: INF - keepalive message received
12:50:56.157 AM: [5552.6836] <4> tar_base::keepaliveThread: INF - sending keepalive
12:50:56.157 AM: [5552.6836] <2> dtcp_write: TCP - success: send socket (1872), 1 of 1 bytes
12:50:57.219 AM: [5552.4680] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping:
\\?\Volume{023d5f60-7e83-11dd-ba49-806e6f6e6963}\ --> Volume{77be05d5-c512-11de-b007-001185e748c6}
12:50:57.219 AM: [5552.4680] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping:
\\?\Volume{7b17c9c1-7ee5-11dd-ad25-001185e748c6}\ --> Volume{45da82c6-cdbc-11de-a00d-001185e748c6}
12:50:57.219 AM: [5552.4680] <4> V_Snapshot::V_Snapshot_AddMappings: INF - Volume Snapshot Mapping:
\\?\Volume{023d5f59-7e83-11dd-ba49-806e6f6e6963}\ --> Volume{45da82ff-cdbc-11de-a00d-001185e748c6}
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileSystem: INF - Verifying:
\\.\C:\
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileSystem: INF - Verifying:
\\.\D:\
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileSystem: INF - Verifying:
\\.\E:\
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '\\.\C:\' --> 00000000
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '\\.\D:\' --> 00000000
12:50:57.219 AM: [5552.4680] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '\\.\E:\' --> 00000000
12:50:57.219 AM: [5552.4680] <2> ov_log::V_GlobalLog: INF - v_beds::V_FindFirst() ENTER Name:Shadow Copy Components Mode:0
12:50:57.219 AM: [5552.4680] <2> ov_log::V_GlobalLog: INF - bedsShadowCopyInit():ENTER (Reason:2048)
12:50:57.219 AM: [5552.4680] <2> ov_log::V_GlobalLog: INF - bedsShadowCopyInit():Found Resource DLE for 'Shadow?Copy?Components'
12:50:57.219 AM: [5552.4680] <2> ov_log::V_GlobalLog: DBG - v_beds::V_FindFirst() Device:Shadow Copy Components Obj: Pattern:(null)
12:50:57.391 AM: [5552.4680] <2> <FROM BEDS>: Status E_NOINTERFACE (0x80004002) returned creating IVssBackupComponentsEx2 interface when initializing shadow copy
12:50:57.719 AM: [5552.4680] <2> <FROM BEDS>: Calling IVssBackupComponents::GatherWriterMetadata...
12:50:58.891 AM: [5552.4680] <2> <FROM BEDS>: ...completed IVssBackupComponents::GatherWriterMetadata
12:50:58.891 AM: [5552.4680] <2> <FROM BEDS>: brUtil::brUtil( img ) Constructor
12:50:58.891 AM: [5552.4680] <2> ov_log::V_GlobalLog: INF - Successfully attached to Device 'Shadow?Copy?Components' BackupReason:0x800
12:50:59.094 AM: [5552.4680] <2> <FROM BEDS>: Informational status CODE (0x00000002) returned calling FindFirstFile for C:\WINDOWS\system32\perf?00?.bak when getting additional files
12:50:59.094 AM: [5552.4680] <2> <FROM BEDS>: Informational: Writer MSDEWriter contains no components in SHADOW::EnumSpecFiles
12:50:59.094 AM: [5552.4680] <2> <FROM BEDS>: Informational: Writer:SQL Server Logical Path:null Component:null exclusions not used
12:50:59.126 AM: [5552.4680] <2> ov_log::V_GlobalLog: INF - v_beds::V_FindFirst() EXIT Name:Shadow Copy Components: bRC:true LastError:0x0:
12:50:59.141 AM: [5552.4680] <4> TransporterLegacyLocal::winClientShm(): INF - Mapping for shared memory is (Global\NetBackup Media Manager SHM Info Path realm23.toll.com.au_1261230615) .
12:51:00.141 AM: [5552.4680] <4> TransporterLegacyLocal::winClientShm(): INF - Shared memory detail (media_shm_info = 30 262144 1423331265 5672 0 0 0 0 1).
12:51:00.141 AM: [5552.4680] <4> TransporterLegacyLocal::winClientShm(): INF - SHMID = 1423331265, BUF_PTR = 0x3720000, BUF_CONTROL = 0x3ea0000, readyptr = 0x3ea02d0.
12:51:00.141 AM: [5552.4680] <4> Packer::open(): INF - Started Backup...
12:51:00.141 AM: [5552.4680] <4> Transporter::setThrottlingParameters(): INF - Throttling parameters set in Transporter
12:51:00.141 AM: [5552.4680] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
12:51:00.141 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - Estimate:-1 -1
12:51:00.141 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 21 of 21 bytes
12:51:00.141 AM: [5552.4680] <4> dos_backup::tfs_startraw: INF - checking for: C:\
12:51:00.141 AM: [5552.4680] <4> V_DetermineMountInfo: INF - Checking Volume
\\?\Volume{023d5f60-7e83-11dd-ba49-806e6f6e6963}\ for '\'
12:51:00.141 AM: [5552.4680] <4> V_DetermineMountInfo: INF - Adding NTFS Volume
\\.\C: ==>
\\?\Volume{023d5f60-7e83-11dd-ba49-806e6f6e6963}\
12:51:00.141 AM: [5552.4680] <4> dos_backup::tfs_startraw: INF - RAW:
\\.\
12:51:00.157 AM: [5552.4680] <4> dos_backup::tfs_startraw: INF - RAW: C:
12:51:00.157 AM: [5552.4680] <2> tar_backup_tfi::flash_start_state: FlashBackup of Raw partition
\\.\C:\,
Frozen Device
\\?\Volume{77be05d5-c512-11de-b007-001185e748c6}\'
12:51:00.157 AM: [5552.4680] <4> tar_base::V_vTarMsgW: INF - tar message received from vxms_start
12:51:00.157 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - FIML startup time = 0
12:51:00.157 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 28 of 28 bytes
12:51:25.704 AM: [5552.4680] <4> tar_base::V_vTarMsgW: INF - tar message received from set_globals
12:51:25.704 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - arg list: rawdisk C:\ inctime 1260775557 Startblk 0
12:51:25.704 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 58 of 58 bytes
12:51:25.704 AM: [5552.4680] <4> tar_base::V_vTarMsgW: INF - tar message received from set_globals
12:51:25.704 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - clientname realm23.toll.com.au, buid realm23.toll.com.au_1261230615, filnum 0
12:51:25.704 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 86 of 86 bytes
12:51:25.719 AM: [5552.4680] <4> tar_base::V_vTarMsgW: INF - tar message received from vxms_error_handler
12:51:25.719 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - VxMS error - severity 1.
12:51:25.719 AM: [5552.4680] <2> dtcp_write: TCP - success: send socket (1872), 31 of 31 bytes
12:51:25.719 AM: [5552.4680] <4> tar_base::V_vTarMsgW: INF - tar message received from vxms_error_handler
12:51:25.735 AM: [5552.4680] <2> tar_base::V_vTarMsgW: INF - VxMS Error message 1 = pgnerr: plugin ntfs returned error 1024: Provider internal error