Backup stuck in scan phase.

Last post 04-11-2014, 3:21 AM by Jakes. 5 replies.
Sort Posts: Previous Next
  • Backup stuck in scan phase.
    Posted: 04-10-2014, 3:25 AM

    What can make the backup of a Windows 2012 R2 server not finish.

    This is a new active directory server with very little data.

    I know in linux this can happen when you have stale mount pathes.

  • Re: Backup stuck in scan phase.
    Posted: 04-10-2014, 4:54 AM

    Hi,

    Are you sure that the client is properly configure din CommVault ?

    Also can you give us the logs for that job ?

    Regards.


    I'm Certifiable, not only certified.
    It just means my answers are from experience, not from a book.
  • Re: Backup stuck in scan phase.
    Posted: 04-10-2014, 9:58 AM




    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
    Machine : umkn-bkp02pp
    File    : AppMgrService.log
    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

    4776  131c  04/10 09:31:26 19088 handleEnableServerCacheXMLMessage Sending response to the client with populated cache messages. Process time: 0.004 sec
    4776  131c  04/10 09:59:02 ##### AppTypeLsn::getProperties() - Error [Error for operation [Fetch] on table [APP_IDAName]. No rows were affected or no data was returned from the operation.] trying to getProperties of Apptype [33], clientId  [12]



    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
    Machine : umkn-bkp02pp
    File    : JobManager.log
    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

    4796  153c  04/10 09:31:23 19088 Servant    [---- IMMEDIATE BACKUP REQUEST ----], taskid [3737] Clnt[sflo-adc01pp] AppType[Windows File System][33] BkpSet[defaultBackupSet] SubClnt[default] BkpLevel[Full][1]
    4796  b90   04/10 09:31:25 19088 Scheduler  Phase [4-Scan] (0,0) started on [sflo-adc01pp.students.int.unisa.ac.za] - ifind.exe -j 19088 -a 2:444 -t 1 -d uflo-bkp01pp.int.unisa.ac.za*uflo-bkp01pp*8400*8402 -r 0 -ab 0 -i 1 -cs umkn-bkp02pp  -jt 19088:4:1  -systemFiles  -seb
    4796  10f8  04/10 09:31:26 19088 Servant    Reg [Control] received. Client [sflo-adc01pp] plattype = 4. Token [19088:4:1]



    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
    Machine : umkn-bkp02pp
    File    : Licensing.log
    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

    4796  153c  04/10 09:31:23 19088 Check license: appType [33] Name [Windows File System] on client/library [411]- Valid
    4796  153c  04/10 09:31:23 ##### License - Type [196] Name [NetApp Snap Management]: Free permanent license available.
    4796  153c  04/10 09:31:23 ##### License - Type [196] Name [NetApp Snap Management]: available [1000000] used [0]
    4796  153c  04/10 09:31:23 ##### [1000000] perm license [NetApp Snap Management (196)] are issued



    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
    Machine : sflo-adc01pp
    File    : FileScan.log
    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

    6604  1084  04/10 09:31:25 19088 wmain(77) - Logging configured, DebugMask=0x0000FFFF, DebugLvl=1
    6604  1084  04/10 09:31:25 19088 wmain(81) -
    6604  1084  04/10 09:31:25 19088 wmain(82) -
    6604  1084  04/10 09:31:25 19088 wmain(83) -
    6604  1084  04/10 09:31:25 19088 wmain(84) - ======================
    6604  1084  04/10 09:31:25 19088 wmain(85) - IFIND PROCESS STARTING
    6604  1084  04/10 09:31:25 19088 wmain(86) - ----------------------
    6604  1084  04/10 09:31:25 19088 wmain(87) -
    6604  1084  04/10 09:31:25 19088 wmain(88) -
    6604  1084  04/10 09:31:25 19088 wmain(89) -
    6604  1084  04/10 09:31:25 19088 CJobManagerRegistrationPrivate::Register(56) - +++
    6604  1084  04/10 09:31:25 19088 CJobManagerRegistrationPrivate::Register(77) - CommServe=umkn-bkp02pp.int.unisa.ac.za, JobId=19088, JobManagerToken=19088:4:1, PlatformType=4
    6604  1084  04/10 09:31:25 19088 JM Client  CVBkpJobClient::init(): Initializing job object with token [19088:4:1].
    6604  1084  04/10 09:31:25 19088 Init() - Initializing job control [token=19088:4:1,cn=sflo-adc01pp], serverName [umkn-bkp02pp.int.unisa.ac.za], ControlFlag [1], Job Id [19088]
    6604  1084  04/10 09:31:26 19088 Cvcl::init() - CVCL: Running in FIPS Mode
    6604  1084  04/10 09:31:26 19088 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\6.604]
    6604  1084  04/10 09:31:26 19088 CJobManagerRegistrationPrivate::Register(56) - --- 0:01.052691
    6604  1084  04/10 09:31:27 19088 wmain(122) - ScanJobType=FILE_SYSTEM (3)
    6604  1084  04/10 09:31:27 19088 Find::Run(560) - +++
    6604  1084  04/10 09:31:27 19088 Find::Initialize(848) - +++
    6604  1084  04/10 09:31:27 19088 Find::InitializeJobControl(879) - +++
    6604  1084  04/10 09:31:27 19088 Find::InitializeJobControl(904) - Job Control object initialized
    6604  1084  04/10 09:31:27 19088 Find::InitializeJobControl(879) - --- 0:00.008909
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(936) - +++
    6604  1084  04/10 09:31:27 19088 Find::CreateImpersonationToken(8079) - +++
    6604  1084  04/10 09:31:27 19088 Find::CreateImpersonationToken(8110) - No subclient credentials found, trying job results impersonation
    6604  1084  04/10 09:31:27 19088 Find::CreateImpersonationToken(8118) - No job results credentials found, no impersonation configured
    6604  1084  04/10 09:31:27 19088 Find::CreateImpersonationToken(8079) - --- 0:00.013532
    6604  1084  04/10 09:31:27 19088 JOBRESCACHEDIR: job 19088 creating 'D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\19088'
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1015) - AppNumber=2:444, AppTypeId=33, ReferenceTime=1601/01/01 02:00:00.000000, ReferenceTimeUtc=1601/01/01 00:00:00.000000Z, BackupType=1 (Full)
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1016) - SubclientDir=D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\FileSystemAgent\2\444, CollectFile=D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\FileSystemAgent\2\444\CollectTot.cvf, FilterFile=D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\FileSystemAgent\2\444\FilterTot.cvf
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1017) - DirChangeTmp=D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\FileSystemAgent\2\444\DCTmp.cvf
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1018) - MediaAgentName=uflo-bkp01pp.int.unisa.ac.za*uflo-bkp01pp*8400*8402, BackupSetName=defaultBackupSet, SubclientName=default
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1019) - JobId=19088, CommCellId=2
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1020) - UseArchiveBit=0
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(1021) - CommServeName=umkn-bkp02pp
    6604  1084  04/10 09:31:27 19088 Find::InitializeEnvironment(936) - --- 0:00.088701
    6604  1084  04/10 09:31:27 19088 Find::InitializeScanJob(1029) - +++
    6604  1084  04/10 09:31:27 19088 JM Client  CVJobClient::processXmlReq(), got response.
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::SetOptions(140) - SubclientName=default, JobStartTime=2014/04/10 07:31:24.000000Z
    6604  1084  04/10 09:31:27 19088 Find::InitializeScanJob(1029) - --- 0:00.366370
    6604  1084  04/10 09:31:27 19088 Find::CleanupOldCollectsAndDirChange(2879) - +++
    6604  1084  04/10 09:31:27 19088 Find::CleanupOldCollectsAndDirChange(2879) - --- 0:00.007786
    6604  1084  04/10 09:31:27 19088 Find::Initialize(848) - --- 0:00.494442
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1152) - +++
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1193) - UseIncrementalImageMode=0
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1233) - UseNewContentList=1
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1318) - UseChangeJournal=0
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1335) - UseDataClassifier=1
    6604  1084  04/10 09:31:27 19088 GXDCDB::SetDataClassificationEvent(103) - Global\GXDC_ThreadEvent_001 set
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1369) - OnDemandBackupset=0
    6604  1084  04/10 09:31:27 19088 Find::ConfigureScanMethod(1152) - --- 0:00.038599
    6604  1084  04/10 09:31:27 19088 Find::ConfigureStreams(1466) - +++
    6604  1084  04/10 09:31:27 19088 Find::ConfigureStreamsFinalize(1492) - The number of subclient streams to use is [2]
    6604  1084  04/10 09:31:27 19088 Find::ConfigureStreamsFinalize(1512) - User selected option to do multiple reads on the disk, collect files will be divided to perform simultaneous reads on a single drive, AvoidStarvationFactor=2
    6604  1084  04/10 09:31:27 19088 Find::ConfigureStreams(1466) - --- 0:00.013079
    6604  1084  04/10 09:31:27 19088 Find::ConfigureShadowUsage(1525) - +++
    6604  1084  04/10 09:31:27 19088 Find::ConfigureShadowUsage(1527) - Checking for VSS/QSnap selection
    6604  1084  04/10 09:31:27 19088 Find::ConfigureShadowUsage(1563) - Subclient info suggests no VSS/QSnap selection
    6604  1084  04/10 09:31:27 19088 Find::ConfigureShadowUsage(1525) - --- 0:00.012901
    6604  1084  04/10 09:31:27 19088 Find::InitializeProxyHost(1609) - +++
    6604  1084  04/10 09:31:27 19088 Find::InitializeProxyHost(1618) - Proxy host mapper not initialized, AppId=2:444
    6604  1084  04/10 09:31:27 19088 Find::InitializeProxyHost(1609) - --- 0:00.008421
    6604  1084  04/10 09:31:27 19088 Find::PrepareCommitAndPreviousDirChange(1754) - +++
    6604  1084  04/10 09:31:27 19088 Find::PrepareCommitAndPreviousDirChange(1766) - Cleaning any previous committed files
    6604  1084  04/10 09:31:27 19088 CPathCacheFlatFileIndexPrivate::LoadFromCurrentBackingFile(94) - +++
    6604  1084  04/10 09:31:27 19088 CPathCacheFlatFileIndexPrivate::LoadFromCurrentBackingFile(108) - CurrentBackingFile=D:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\FileSystemAgent\2\444\DCTmp.cvf
    6604  1084  04/10 09:31:27 19088 CPathCacheFlatFileIndexPrivate::LoadFromCurrentBackingFile(94) - --- 0:00.008656
    6604  1084  04/10 09:31:27 19088 Find::PrepareCommitAndPreviousDirChange(1754) - --- 0:00.021925
    6604  1084  04/10 09:31:27 19088 Find::InitializeFiles(1641) - +++
    6604  1084  04/10 09:31:27 19088 Find::InitializeFiles(1688) - m_vecLastScanFailures size 0
    6604  1084  04/10 09:31:27 19088 Find::InitializeFiles(1641) - --- 0:00.008935
    6604  1084  04/10 09:31:27 19088 Find::GatherContent(1909) - +++
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::LoadContent(211) - +++
    6604  1084  04/10 09:31:27 19088 FSSubclientConf::load(854) - +++
    6604  1084  04/10 09:31:27 19088 FSSubclientConf::load(854) - --- 0:00.155992
    6604  1084  04/10 09:31:27 19088 FSSubclientConf::setIfindMode(4912) - ifind mode is enabled
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::GetSubclientContent(322) - +++
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::GetSubclientContent(322) - --- 0:00.004483
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::GetSubclientContentExceptions(377) - +++
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::GetSubclientContentExceptions(377) - --- 0:00.004327
    6604  1084  04/10 09:31:27 19088 CScanContentConfiguration::GetNewContentSinceLastBackup(462) - +++
    6604  1084  04/10 09:31:27 19088 CMonikerResolverPrivate::EnumUserProfilePathsRegistry(891) - LookupAccountSidW unsuccessful for SID [S-1-5-21-1466292615-3783471166-4240737546-500], error=0x80070534:{MonikerResolverPrivate.cpp[CMonikerResolverPrivate::EnumUserProfilePathsRegistry(891)]/W32.1332.(No mapping between account names and security IDs was done.)}
    6604  1084  04/10 09:31:27 19088 CMonikerResolverPrivate::EnumUserProfilePathsRegistry(891) - LookupAccountSidW unsuccessful for SID [S-1-5-21-972081050-4039856273-241938932-500], error=0x80070534:{MonikerResolverPrivate.cpp[CMonikerResolverPrivate::EnumUserProfilePathsRegistry(891)]/W32.1332.(No mapping between account names and security IDs was done.)}
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::GetNewContentSinceLastBackup(462) - --- 0:00.188249
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::GetSubclientSyncContent(412) - +++
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::GetSubclientSyncContent(423) - AppId=444, Result=0, SyncFolders=0
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::GetSubclientSyncContent(412) - --- 0:00.023559
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::LoadContent(211) - --- 0:00.414701
    6604  1084  04/10 09:31:28 19088 Find::GatherContent(1909) - --- 0:00.423164
    6604  1084  04/10 09:31:28 19088 Find::GatherFilters(2578) - +++
    6604  1084  04/10 09:31:28 19088 CScanContentConfiguration::GetSubclientNoNames(599) - +++
    6604  1084  04/10 09:36:06 19088 Find::ExpandContent5(2372) - Converted, JunctionPoint=C:\Documents and Settings\All Users\Application Data\Microsoft\Microsoft Antimalware\Scans, TargetPath=C:\ProgramData\Microsoft\Microsoft Antimalware\Scans
    6604  1084  04/10 09:37:38 19088 Find::ExpandContent5(2372) - Converted, JunctionPoint=C:\Documents and Settings\All Users\Application Data\Microsoft\Microsoft Forefront\Client Security, TargetPath=C:\ProgramData\Microsoft\Microsoft Forefront\Client Security
    6604  1084  04/10 09:38:25 19088 CScanContentConfiguration::GetSubclientNoNames(599) - --- 6:56.938395
    6604  1084  04/10 09:38:25 19088 CScanContentConfiguration::GetSubclientYesNames(515) - +++
    6604  1084  04/10 09:38:25 19088 CScanContentConfiguration::GetSubclientYesNames(515) - --- 0:00.003921
    6604  1084  04/10 09:38:25 19088 Find::LoadSystemProtectedFiles(2610) - +++
    6604  1084  04/10 09:38:25 19088 CSystemFilterEnumerator::Process(54) - +++
    6604  1084  04/10 09:38:25 19088 CSystemFilterEnumerator::LoadFilters(94) - +++
    6604  1084  04/10 09:38:25 19088 CNTFileReplicationService::EnumReplicatedPaths(333) - BackupContext=0x00000000010286C0
    6604  1084  04/10 09:38:25 19088 CVPI_PT_MA is an invalid platform for focus Instance001
    6604  1084  04/10 09:38:25 19088 CFilterSingleInstanceDatabaseFiles::Process(50) - Could not get SIDB folders; cannot exclude SIDB folders from this backup
    6604  1084  04/10 09:38:25 19088 CFilterSystemProtectedFiles::Process(173) - Adding VSS System writer skip files, result=0x0
    6604  1084  04/10 09:38:25 19088 CsSnapRequestor::RunCreateShadow() - Volume list empty, no volumes added to the shadow
    6604  1084  04/10 09:38:25 19088 CsSnapRequestor::Initialize() - Will gather the writer metadata
    6604  1084  04/10 09:38:25 19088 CsVssBackupComponents::SetBackupState() - Committing backup state: SelectComponents: [1], BootableSystemState: [0], BackupType: [1 - VSS_BT_FULL], PartialFileSuppport: [0]
    6604  1084  04/10 09:38:25 19088 CsVssAsync::WaitUntilDone() - Async status returned final code = 0x0004230a, Description = VSS_S_ASYNC_FINISHED.
    6604  1084  04/10 09:38:25 19088 CsVssBackupComponents::GatherWriterMetadata() - Writer Metadata gathered
    6604  1084  04/10 09:38:26 19088 CsVssBackupComponents::GatherWriterMetadata() - Gathered all writer metadata
    6604  1084  04/10 09:38:26 19088 CsSnapRequestor::Initialize() - Shadow Provider=b5946137-7b9f-4925-af80-51abd60b20d5
    6604  1084  04/10 09:38:26 19088 CWinWriterSkipJob::CheckAddWriterToSkipList(276) - Adding writer [e8132975-6f93-4464-a53e-1050253ae220] to writer skips list.
    6604  1084  04/10 09:38:26 19088 CDefaultWriterBackup::GetWriterFileList(1529) - System Files has 17669 files, 0 logs, and 0 databases
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1544) - No log files to backup for System Files
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1551) - No database files to backup for System Files
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1529) - Win32 Services Files has 7 files, 0 logs, and 0 databases
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1544) - No log files to backup for Win32 Services Files
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1551) - No database files to backup for Win32 Services Files
    6604  1084  04/10 09:38:30 19088 CDefaultWriterBackup::GetWriterFileList(1560) - Retrieved up [78526] files for the writer.
    6604  1084  04/10 09:38:30 19088 CWinWriterSkipJob::Run(438) - <--- Adding 17676 skips for System Protected Files --->
    6604  1084  04/10 09:38:31 19088 CWinWriterSkipJob::Run(535) - <--- Ending skips for System Protected Files --->
    6604  1084  04/10 09:38:31 19088 CsVssBackupComponents::FreeWriterMetadata() - Free'd all writer metadata
    6604  1084  04/10 09:38:31 19088 CSystemFilterEnumerator::LoadFilters(94) - --- 0:06.771728
    6604  1084  04/10 09:38:31 19088 CSystemFilterEnumerator::Process(76) - 17764 filters, 0 filter exceptions
    6604  1084  04/10 09:38:31 19088 CSystemFilterEnumerator::Process(54) - --- 0:06.776819
    6604  1084  04/10 09:40:01 19088 Find::ExpandContent5(2372) - Converted, JunctionPoint=C:\Documents and Settings\All Users\Application Data\Microsoft\Crypto\RSA\MachineKeys, TargetPath=C:\ProgramData\Microsoft\Crypto\RSA\MachineKeys

  • Re: Backup stuck in scan phase.
    Posted: 04-10-2014, 10:10 AM
    • Ali is not online. Last active: 02-22-2019, 10:44 AM Ali
    • Top 10 Contributor
    • Joined on 08-05-2010

    Hi Jakes,

    What version and Service Pack of Simpana are you using?  Also could you attach the full FileScan.log and clBackup.log from the client machine?

  • Re: Backup stuck in scan phase.
    Posted: 04-10-2014, 11:32 AM

    I would try just backing up a directory or two on the C: drive first.  If that finishes then you know the Windows File System iData agent is working ok.

     

    Then try the entire C: drive.

     

    Then try one of the other types of backups if you have any on this client (AD?).

     

     

    Thanks

  • Re: Backup stuck in scan phase.
    Posted: 04-11-2014, 3:21 AM

    I'm still not sure what the problem is, the servers can ping each other but after I put there IP's

    into the Hosts file the backup ran fine.

    Ther seems to be and intermittent Dns/connectivity problem.

The content of the forums, threads and posts reflects the thoughts and opinions of each author, and does not represent the thoughts, opinions, plans or strategies of Commvault Systems, Inc. ("Commvault") and Commvault undertakes no obligation to update, correct or modify any statements made in this forum. Any and all third party links, statements, comments, or feedback posted to, or otherwise provided by this forum, thread or post are not affiliated with, nor endorsed by, Commvault.
Commvault, Commvault and logo, the “CV” logo, Commvault Systems, Solving Forward, SIM, Singular Information Management, Simpana, Commvault Galaxy, Unified Data Management, QiNetix, Quick Recovery, QR, CommNet, GridStor, Vault Tracker, InnerVault, QuickSnap, QSnap, Recovery Director, CommServe, CommCell, SnapProtect, ROMS, and CommValue, are trademarks or registered trademarks of Commvault Systems, Inc. All other third party brands, products, service names, trademarks, or registered service marks are the property of and used to identify the products or services of their respective owners. All specifications are subject to change without notice.
Close
Copyright © 2019 Commvault | All Rights Reserved. | Legal | Privacy Policy