none
Assessment failing after inventory

    Question

  • Hello everybody!

    I'm using MapToolkit Build 9.2.292.00 to collect inventory data from our servers and, after a successful inventory has completed, the Assessment doesn't work!

    As a way to isolate the issue, I performed the inventory only in the VMWare infrastructure and, after that, it's clear: The problem with assessment task are the VMWare data. 

    I saw some threads about this error, but any helped me to solve my problem. I checked the data from "WMWare_Inventory" and "WMWare_Assessment" schemas and I'd not able to see anything wrong with them.

    Could you help me, please? Take a look at the log bellow.

    Thanks!

    Moises



       |Logging started at 03/31/2015 13:39:30
       |    Application:     MapToolkit.exe Build 9.2.292.00 retail
       |    Platform:        Win32NT 6.2.9200.0 
       |    UI Culture:      pt-BR
       |    Culture:         pt-BR
       |    Architecture:    64-bit
       |    OS Product Name: Microsoft Windows 8.1 Enterprise
       |    Machine Type:    Physical
       |    CPU:             Intel(R) Core(TM) i5-3317U CPU @ 1.70GHz
       |    #CPU:            1
       |    #Cores:          2
       |    #Logical:        4
       |    System Memory:   6036 MB
       |    Avail Memory:    2909 MB
       |    Free Disk:       136133 MB
       |
       |========================================
    <2015-03-31 13:39:33.34 TID-1@SqmSessionHelper,I> GetSession(): Started SQM session Main with AppId 101457979
    <2015-03-31 13:39:49.35 TID-5@InitializingPageViewModel,I> DoInitialization(): Checking for duplicate process.
    <2015-03-31 13:39:49.35 TID-5@InitializingPageViewModel,I> DoInitialization(): Loading extensions.
    <2015-03-31 13:39:51.34 TID-5@InitializingPageViewModel,I> DoInitialization(): Completing database management initialization.
    <2015-03-31 13:39:51.58 TID-5@InitializingPageViewModel,I> DoInitialization(): Loading metadata.
    <2015-03-31 13:39:55.98 TID-5@InitializingPageViewModel,I> DoInitialization(): Checking PowerShell version.
    <2015-03-31 13:39:56.22 TID-5@InitializingPageViewModel,I> DoInitialization(): Validating version values.
    <2015-03-31 13:39:56.31 TID-9@ServerConnectionManager,I> SQL Server connection name: (LocalDB)\MAPToolkit
    <2015-03-31 13:40:11.76 TID-5@DataAccessHelper,E> DataAccessHelper.OpenConnection: connection failed due to SqlException, Will be retried after 5000 milliseconds, Exception Number: -2 Exception Message: Tempo Limite de Conexão Expirado. O tempo limite decorrido durante a tentativa de consumo da confirmação de handshake pré-logon. Isso ocorre porque houve falha no handshake pré-logon ou o servidor não pôde responder a tempo.  A duração da tentativa de conexão com este servidor foi: [Pre-Login] initialization=14305; handshake=189;   retry Count: 1
    <2015-03-31 13:40:11.83 TID-9@DataAccessCore,W> OpenConnection() - Caught a SqlException trying to connect to the database.  Will retry connection 3 more time(s).  Retrying in 5000 milliseconds.
       |Exception message = Tempo Limite de Conexão Expirado. O tempo limite decorrido durante a tentativa de consumo da confirmação de handshake pré-logon. Isso ocorre porque houve falha no handshake pré-logon ou o servidor não pôde responder a tempo.  A duração da tentativa de conexão com este servidor foi: [Pre-Login] initialization=14412; handshake=175; 
    <2015-03-31 13:40:16.92 TID-9@ServerConnectionManager,I> SQL Server version info: Microsoft SQL Server 2012 - 11.0.2100.60 (X64) 
       | Feb 10 2012 19:39:15 
       | Copyright (c) Microsoft Corporation
       | Express Edition (64-bit) on Windows NT 6.2 <X64> (Build 9200: )
       |
    <2015-03-31 13:40:19.42 TID-5@InitializingPageViewModel,I> DoInitialization(): Preparing database.
    <2015-03-31 13:40:21.52 TID-5@InitializingPageViewModel,I> OpenPreviouslySelectedDatabase(): Opening previously selected database. DPESP
    <2015-03-31 13:40:23.13 TID-5@InitializingPageViewModel,I> DoInitialization(): Initialization complete.
    <2015-03-31 13:40:24.21 TID-10@ScuiFxTraceListener,W> <NavigationModelAdaptor.GetNode> Query for node 'msscnav://root/Windows' from provider 'msscnav://providers/definition' return no result.
    <2015-03-31 13:40:24.21 TID-10@ScuiFxTraceListener,W> <TasksPublisher.OnParentNavigationNodeAvailable|WARN> No node returned for query to location 'msscnav://root/Windows', no tasks will be displayed for this location.
    <2015-03-31 13:47:49.63 TID-12@ManageDbsDialogViewModel,I> ImportADatabase(RIACHUELO): Restoring database from 'C:\Users\moises.gabriel\Desktop\riachuelo.bak'
    <2015-03-31 13:48:13.78 TID-12@ManageDbsDialogViewModel,I> ImportADatabase(RIACHUELO): Completed import from file 'C:\Users\moises.gabriel\Desktop\riachuelo.bak'
    <2015-03-31 13:48:39.21 TID-7@SqmSessionHelper,I> GetSession(): Started SQM session Database with AppId 101457990
    <2015-03-31 13:48:39.21 TID-7@OpenCreateDbDialogViewModel,I> OpenAnExistingDatabase(RIACHUELO): Opening database. Version: 5765
    <2015-03-31 14:19:10.01 TID-1@MainMenuSupport,I> OnRefreshAssessmentCommand() - The user chose to refresh the inventory assessment.
    <2015-03-31 14:19:11.17 TID-13@TaskProcessor,I> Run: Processing task: 'Assess inventory'
    <2015-03-31 14:19:11.18 TID-13@TaskProcessor,I> StartWorkers: Starting worker thread: 'AssessInventoryWorker'
    <2015-03-31 14:19:11.18 AssessInventoryWorker@TaskProcessor,I> RunWorker: Running worker: 'AssessInventoryWorker'
    <2015-03-31 14:19:11.27 AssessInventoryWorker@AssessInventoryWorker,I> AssessmentStartedEventHandler: Assessment start event.
    <2015-03-31 14:19:13.80 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Core_Assessment].[RemoveInactiveIpAddresses]] : 2516 ms
    <2015-03-31 14:19:15.22 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Core_Assessment].[RemoveDuplicateDevices]] : 1422 ms
    <2015-03-31 14:19:15.90 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Core_Assessment].[PostInventorySetting]] : 687 ms
    <2015-03-31 14:19:15.90 AssessInventoryWorker@Analyzer,I> RunAssessments() - Elapsed time for assessment 'StoredProcAssessment': 4625 ms
    <2015-03-31 14:19:16.04 AssessInventoryWorker@Analyzer,I> RunAssessments() - Elapsed time for assessment 'SetAssessmentFlagsAssessment': 125 ms
    <2015-03-31 14:19:20.03 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[WindowsInstalledSoftwareAssessment]] : 3953 ms
    <2015-03-31 14:19:25.63 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[DeviceAssessmentProc]] : 5594 ms
    <2015-03-31 14:19:25.76 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[AllDevices_Assessment].[PrepareAssessment]] : 140 ms
    <2015-03-31 14:19:28.92 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[CategorizeInventoriedDevices]] : 3157 ms
    <2015-03-31 14:19:28.94 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Unix_Assessment].[CategorizeInventoriedDevices]] : 15 ms
    <2015-03-31 14:19:29.59 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[CategorizeDiscoveredDevices]] : 657 ms
    <2015-03-31 14:19:29.73 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Unix_Assessment].[CategorizeDiscoveredDevices]] : 125 ms
    <2015-03-31 14:19:29.97 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[CalculateHardwareInventoryCore]] : 250 ms
    <2015-03-31 14:19:30.04 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Unix_Assessment].[CalculateHardwareInventoryCore]] : 78 ms
    <2015-03-31 14:19:30.13 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[AllDevices_Assessment].[DiscoveryHardwareInventoryCore]] : 93 ms
    <2015-03-31 14:19:30.14 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[UT_FEP_Assessment].[AssessmentUsageTrackerForefrontEndpointProtection]] : 0 ms
    <2015-03-31 14:19:31.70 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Win_Assessment].[HardwareAssessmentProc]] : 1563 ms
    <2015-03-31 14:19:31.71 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[Unix_Assessment].[UnixDataConsistencyAssessment]] : 0 ms
    <2015-03-31 14:19:36.44 AssessInventoryWorker@StoredProcAssessment,I> RunAssessment() - [Perf] [[VMware_Assessment].[AssessmentVMwareData]] : 4734 ms
    <2015-03-31 14:19:38.01 AssessInventoryWorker@Analyzer,E> RunAssessments() - Assessment threw an exception:
       |Microsoft.AssessmentPlatform.MapException: Caught SqlException running the stored procedure [AllVirt_Assessment].[AssessmentHostGuestRelationships]. ---> System.Data.SqlClient.SqlException: String or binary data would be truncated.
       |The statement has been terminated.
       |   em System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
       |   em System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
       |   em System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
       |   em System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
       |   em System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds)
       |   em System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean asyncWrite)
       |   em System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite)
       |   em System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
       |   em Microsoft.AssessmentPlatform.DataAccess.DataAccessCore.ExecuteStoredProcHelper(String storedProcName, Object[] parameters)
       |   em Microsoft.AssessmentPlatform.DataAccess.DataAccessCore.DoWorkInTransaction[T](Nullable`1 isolationLevel, String onSqlExceptionMessage, TransactionWorkCallback`1 callback)
       |   --- Fim do rastreamento de pilha de exceções internas ---
       |   em Microsoft.AssessmentPlatform.DataAccess.DataAccessCore.DoWorkInTransaction[T](Nullable`1 isolationLevel, String onSqlExceptionMessage, TransactionWorkCallback`1 callback)
       |   em Microsoft.AssessmentPlatform.Analytics.Assessments.StoredProcAssessment.RunAssessment(ThreadSafeFlag continueProcessingFlag, SecureString connectionString)
       |   em Microsoft.AssessmentPlatform.Analytics.Analyzer.RunAssessments(IEnumerable`1 assessments)
    <2015-03-31 14:19:38.02 AssessInventoryWorker@AssessInventoryWorker,I> AssessmentCompletedEventHandler: Assessment completed event.
    <2015-03-31 14:19:38.03 AssessInventoryWorker@TaskProcessor,I> WorkerCompleted: Worker: 'AssessInventoryWorker'
    <2015-03-31 14:19:38.04 TID-13@TaskProcessor,I> Run: Completed. Status: Failed
    <2015-03-31 14:19:38.46 TID-13@ProgressPage,I> ProgressPage.TaskCompletedCallback: sender: Microsoft.AssessmentPlatform.UI.WpfConsole.Tasks.TaskProcessor
    <2015-03-31 14:20:04.57 TID-1@ProgressPage,I> FormClosingHandler: Closing reason: UserClosing
    <2015-03-31 15:21:22.50 TID-1@ScuiFxTraceListener,W> <WindowJobsService.Dispose|WARN> This instance of console jobs has already been disposed, returning.
       |
    <2015-03-31 15:21:23.16 TID-1@SqmSession,I> StartUploadingAllSqmData(): SqmApi.SqmStartUpload() queued 0 files.  GetLastError=0x00000000
    <2015-03-31 15:21:23.18 TID-1@SqmSessionHelper,I> Upload(): 0 files queued.  Skipping upload.

    Tuesday, March 31, 2015 7:21 PM

All replies

  • I have the same problem with my scanning.
    when scanning the VmWare environment, the assessment fails.

    Anyone foud a fix or workaround to this?
    Exept not to scan the VmWare environment of cource.

    /Roar

    Tuesday, May 26, 2015 3:06 PM
  • I just came across this myself.  The source of the failure is in the log you posted:

    Caught SqlException running the stored procedure [AllVirt_Assessment].[AssessmentHostGuestRelationships]

    I ran each block of code step-by-step in that proc and found that the issue is related to a column update where the source is larger than the destination.

    If you run this query, you will likely find at least one with a length > 128 (the size of the [Core_Inventory].[Devices].[OperatingSystem] column):

    select d.OperatingSystem, vg.[GuestGuestFullName]
    , COALESCE(d.[OperatingSystem], vg.[GuestGuestFullName]) as [coal]
    , len(COALESCE(d.[OperatingSystem], vg.[GuestGuestFullName])) as [coal_len]
    FROM [Core_Inventory].[Devices] d
    INNER JOIN [VMware_Assessment].[GuestUnique] vgu ON d.[DeviceNumber] = vgu.[GuestDeviceNumber]
    INNER JOIN [VMware_Inventory].[Guest] vg ON vg.[DeviceNumber] = vgu.[DeviceNumber] AND vg.[MobRef] = vgu.[MobRef]
    ORDER BY len(COALESCE(d.[OperatingSystem], vg.[GuestGuestFullName])) desc

    The fix is to search in the proc for vg.[GuestGuestFullName] (which may be line 204) and change the line from:

    COALESCE(d.[OperatingSystem], vg.[GuestGuestFullName])

    to:

    COALESCE(d.[OperatingSystem], LEFT(vg.[GuestGuestFullName],128))
    Hopefully this will be fixed in the next release.


    20150727 edit:  Use the code below to update the stored proc.  Just put in the name of the MAP database after it is created.
    USE [master]
    GO
    set nocount on;
    declare 
    	@mapdb sysname = 'MAPToolkit_20150701_v92';
    
    declare 
    	@sql nvarchar(max)
    	, @outersql nvarchar(max)
    	, @proc nvarchar(max);
    
    /* Create a copy of the broken stored proc */
    select @sql = 'use ' + quotename(@mapdb) + 
    	' select @procdef = replace(object_definition(object_id(''[AllVirt_Assessment].[AssessmentHostGuestRelationships]''))
    	, ''CREATE PROCEDURE [AllVirt_Assessment].[AssessmentHostGuestRelationships]''
    	, ''CREATE PROCEDURE [AllVirt_Assessment].[AssessmentHostGuestRelationships_orig]'')'
    exec sp_executesql @sql, N'@procdef nvarchar(max) OUTPUT', @procdef = @proc OUTPUT
    select @outersql = 'use ' + quotename(@mapdb) + char(13) + 'exec (''' + REPLACE(@proc,'''', '''''') + ''')'
    EXEC (@outersql)
    
    /* Modify the broken stored proc */
    select @sql = 'use ' + quotename(@mapdb) + 
    	' select @procdef = replace(
    		replace(object_definition(object_id(''[AllVirt_Assessment].[AssessmentHostGuestRelationships]''))
    			, ''COALESCE(d.[OperatingSystem], vg.[GuestGuestFullName])''
    			, ''COALESCE(d.[OperatingSystem], LEFT(vg.[GuestGuestFullName],128))'')
    	, ''CREATE PROCEDURE'', ''ALTER PROCEDURE'')
    	'
    exec sp_executesql @sql, N'@procdef nvarchar(max) OUTPUT', @procdef = @proc OUTPUT
    select @outersql = 'use ' + quotename(@mapdb) + char(13) + 'exec (''' + REPLACE(@proc,'''', '''''') + ''')'
    EXEC (@outersql)

    • Edited by Ron Klimaszewski Monday, July 27, 2015 6:18 PM Improvement
    • Proposed as answer by Ratbasket Thursday, September 7, 2017 4:06 PM
    Monday, June 1, 2015 1:30 PM
  • Thank you sir, followed your scripts and the assessment has completed successfully!
    Thursday, September 7, 2017 4:07 PM
  • We are using Version 9.7 and do have exactly the same issue on VM assessment. Is that fix still relevant for the so called latest version ?
    Tuesday, December 5, 2017 8:58 AM
  • Still running v9.6.  If it does not find the errant string, it won't make a change other than making a copy of the stored proc.
    Tuesday, December 5, 2017 12:35 PM
  • Yes, even for the by now released version 9.8

    Almost all my customers run MAP Toolkit and working around this error multiple times a month is somewhat frustrating.

    I wished Microsoft would fix this once and for all...

    Wednesday, April 11, 2018 11:35 AM
  • Can you please mark my response as the answer? Thank you.
    Wednesday, April 11, 2018 12:00 PM