Reconcile takes 7 to 13 hours to complete

[IronManMK10]

Good afternoon

I have a reconcile in FNMS takes around 7 to 13 hours to complete.

Is there any thing that we can check to improve reconcile time. The DB is optimised to the best that we have.

The below step takes over 5 hours to run.

2022-12-07 06:38:31,941 [INFO ] WriteFileEvidence - Match double ended wildcards
2022-12-07 06:38:31,941 [INFO ] Writer step 'WriteFileEvidence - Match double ended wildcards' with non-default execution path (Fallback) meets condition TestingOrFallback.
2022-12-07 12:29:55,700 [INFO ] Matched 1554186 records to existing File Evidence with start and end wildcards
2022-12-07 12:29:55,700 [INFO ] Successfully processed in 5 hours, 51 minutes, 21 seconds

I have attached the log accordingly.

[dbeckner]

Hi @IronManMK10 ,

I recommend opening a support case for this. I have seen issues with file evidence steps taking long periods of time and support has provided updated readers/writers that resolved the issue. I can't guarantee they have a fix for this specific step as they need to look at your specific environment and situation but it's worth bringing it to their attention.

- Dan

[IronManMK10]

Hi Dan

Thanks for the feedback. I have raised a case to support.

[mfeinman]

I have exactly the same issue.  In my case, it started recently with the rollout of the Inventory Agent to thousands of workstations.  (The rollout went fine.)  The agent version is 2021R1 but, for at least another month or two, my server is still at 2019R1.  What server version are you running?

--Mark

[IronManMK10]

Hi Mark

The same with us, it has started recently. Were are running 2021 R1 and Agent version is the same.

[mfeinman]

The fact that you are running a different release of the FNMS server than I am, and that my FNMS server has the same issue as you, tells me that this is likely the result of "some change".  I see further down that the current thought is Tibco wildcard entries in the ARL that are soon to be backed out.  Hopefully that is the source of the issue.

[jjoaquin]

Is this the one that run as part of the scheduled task? If it is then perhaps you can add ---nooptional at the end and that may help fasten the process.

[IronManMK10]

Hi 

Yes it is the Recon that is run as part of the Scheduled Task. Where do we add that option can you perhaps send a screenshot

[ChrisG]

The "WriteFileEvidence - Match double ended wildcards" writer step can be one that takes a long time. It is one of the more intensive steps of the inventory import process, especially in an environment where a lot of file evidence is being gathered. Seeing this step run for 6 hours sounds like it is on or above the upper end of normal: I've just looking over import details from a range of environments, and seen this step taking 1-2 hours, and up to 5 hours in one other instance. But "normal" would depend on the volume of inventory data being processed.

Unfortunately I am not aware of any easy way to speed this up - short of hard things like minimizing the amount of file evidence being gathered in inventory, ensuring the database server is provisioned with an appropriate amount of memory, etc.

I'm not sure how useful this may be for your troubleshooting, but if you look in the import procedures then you will find the following queries are involved. The final SELECT query in this batch is the one that is executed in the "WriteFileEvidence - Match double ended wildcards" writer. If you're comfortable with working with SQL, you might try looking at the query plan for the final SELECT query to see if there is anything obviously amiss (although be warned the plan is going to be a bit of spiderweb!).

------------------------------------------
-- "FileEvidenceSetup" step:

IF OBJECT_ID('tempdb..#FileEvidence') IS NOT NULL
	DROP TABLE #FileEvidence

CREATE TABLE #FileEvidence
(
	FileEvidenceID 	INT NOT NULL,
	FileName		NVARCHAR(256) COLLATE DATABASE_DEFAULT NOT NULL,
	FileSize		INT NULL,
	Company			NVARCHAR(200) COLLATE DATABASE_DEFAULT NOT NULL,
	FileVersion		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	Description		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	PRIMARY KEY (FileName, FileEvidenceID)
)

IF OBJECT_ID('tempdb..#FileEvidenceWild') IS NOT NULL
	DROP TABLE #FileEvidenceWild

-- FileName contains % or ?
CREATE TABLE #FileEvidenceWild
(
	FileEvidenceID 	INT NOT NULL,
	FileName		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	FileNameReverse		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	FileSize		INT NULL,
	Company			NVARCHAR(200) COLLATE DATABASE_DEFAULT NOT NULL,
	FileVersion		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	Description		NVARCHAR(400) COLLATE DATABASE_DEFAULT NOT NULL,
	PRIMARY KEY (FileName, FileEvidenceID)
)


------------------------------------------
-- "WriteFileEvidence - Load" step:

DECLARE @EscapeChar nchar(1)
SET @EscapeChar = '\'

INSERT INTO #FileEvidence
(
	FileEvidenceID,
	FileName,
	FileSize,
	Company,
	FileVersion,
	Description
)
SELECT
	FileEvidenceID,
	FileName,
	FileSize,
	Company = REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(ISNULL(Company, ''), @EscapeChar, @EscapeChar + @EscapeChar), '_', @EscapeChar + '_'), '[', @EscapeChar + '['), ']', @EscapeChar + ']'), '?', '_'),
	FileVersion = REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(FileVersion, ',', '.'), @EscapeChar, @EscapeChar + @EscapeChar), '_', @EscapeChar + '_'), '[', @EscapeChar + '['), ']', @EscapeChar + ']'), '?', '_'), '.', '[.,]'),
	Description = REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(Description, @EscapeChar, @EscapeChar + @EscapeChar), '_', @EscapeChar + '_'), '[', @EscapeChar + '['), ']', @EscapeChar + ']'), '?', '_')
FROM dbo.FileEvidence WITH (NOLOCK)
OPTION (MAXDOP 1)

PRINT N'Loaded ' + CAST(@@ROWCOUNT AS nvarchar(MAX)) + N' File Evidence records'


------------------------------------------
-- "WriteFileEvidence - Load wildcards" step:

INSERT INTO #FileEvidenceWild
(
	FileEvidenceID,
	FileName,
	FileNameReverse,
	FileSize,
	Company,
	FileVersion,
	Description
)
SELECT
	FileEvidenceID,
	FileName = REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(FileName, @EscapeChar, @EscapeChar + @EscapeChar), '_', @EscapeChar + '_'), '[', @EscapeChar + '['), ']', @EscapeChar + ']'), '?', '_'),
	FileNameReverse = REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REVERSE(FileName), @EscapeChar, @EscapeChar + @EscapeChar), '_', @EscapeChar + '_'), '[', @EscapeChar + '['), ']', @EscapeChar + ']'), '?', '_'),
	FileSize,
	Company,
	FileVersion,
	Description
FROM #FileEvidence
WHERE FileName LIKE '%[%?]%'

PRINT N'Found ' + CAST(@@ROWCOUNT AS nvarchar(MAX)) + N' File Evidence records with wildcards'


------------------------------------------
-- WriteFileEvidence - Match double ended wildcards step:

--INSERT INTO dbo.ImportedFileEvidenceMapping (FileEvidenceID, ExternalFileID, ComplianceConnectionID)	
SELECT
	[File].FileEvidenceID,
	Imported.ExternalFileID,
	Imported.ComplianceConnectionID	
FROM dbo.ImportedFileEvidence AS Imported
INNER JOIN #FileEvidenceWild AS [File]
	ON Imported.FileName LIKE [File].FileName ESCAPE @EscapeChar
	AND (
		(Imported.Company IS NULL AND '' LIKE [File].Company ESCAPE @EscapeChar)
		OR (Imported.Company LIKE [File].Company ESCAPE @EscapeChar)
	)
	AND Imported.FileVersion LIKE [File].FileVersion ESCAPE @EscapeChar
	AND Imported.Description LIKE [File].Description ESCAPE @EscapeChar
	AND ([File].FileSize IS NULL OR [File].FileSize = Imported.FileSize)
	AND ([File].FileName LIKE '[%_]%[%_]')
	
PRINT N'Matched ' + CAST(@@ROWCOUNT AS nvarchar(MAX)) + N' records to existing File Evidence with start and end wildcards'

[nrousseau1]

Hello,

We have added 55 Tibco Unix evidences last Friday that contain double wildcard... Let's see if this is not causing the performance issue. If more customers face the same issue at the same step, we may need to roll back or make this one a simple wildcard.

Nicolas Rousseau

Product Manager - ITAM

[IronManMK10]

Thanks @nrousseau1 - This issue actually started last week. What would the way forward be?

[nrousseau1]

Hello @IronManMK10  ,

When did you start seeing the issue? The ARL Update was Friday evening. If you are a cloud customer in US, there was a 2022R2 upgrade last week end of November 26th.

We are assessing if many customers are impacted and try to confirm is the cause is Tibco.

If the answer is yes for both, we may roll back the ARL change quickly... will need to enhance the double wild card recognition step (knowing the is a complex hard to optimize part) or make these evidences simple wildcard.

If no, there may be a need for checking specifically with customers (and you) what is going on.

A quick way to see if these ARL evidence files are guilty is to do a "mass ignore" from the file evidence screen with the filters displayed in the screenshot.

If next import is back to normal, that's interesting.

Thanks for sharing when this started and if you are Cloud.

[Nicolas Rousseau edit]: thinking again about it, ignoring the evidences will not help as they will still be involved in the matching process that takes so long.

[IronManMK10]

Hi @nrousseau1 

This issue started happening last week Sunday, after our ARL updates. We are an on-prem customer based in South Africa running 2021 R1.

[IronManMK10]

Hi @nrousseau1 @mschwach 

As a workaround for recons to finish on time, i can move my jobs up earlier and start the recon a 9pm on my side. The question that i have will the attached jobs be affected

[DiannaB]

@nrousseau1 we also have the same issue.  As of Saturday, Dec. 3, reconciliation is running much longer and the double ended wildcards step is taking 4-6 hours now.  We've tried updating DB stats and rebuilding indexes but that has not helped.  We would be interested to see the impact of rolling this back or making the Tibco evidence one simple wildcard.  Thanks!

[mschwach]

Hi DiannaB and all others,

a possible workaround helped us to overcome the issue.

you can increase the timeout-settings on BatchServer for the whole Reconciliation Process:
https://community.flexera.com/t5/FlexNet-Manager-Knowledge-Base/Inventory-import-and-license-reconcile-timeouts/ta-p/5661

In our Case (also on-prem hit by ARL update) it helped, even though the Reconciliation Process is now taking much longer then before.

[DiannaB]

@mschwach Thanks!  We had already increased our timeout so that's not an issue.  My clients expect to have current, reconciled data available each morning.  We have many integrations so we are managing a "delicate" job stream that cannot afford significant delays like this that cause cascading issues.  Looking forward to a better resolution from Flexera!

[mschwach]

Hi DiannaB,

you can adjust the execution of the Reconcile by considering to adjust the Task in Task Scheduler and adopt it to an earlier run, prior to the time your clients are expecting the reports?

[mschwach]

Hi,
we have had the same issue after ARL-update to Version: 2718 on 02.12.2022.

The step "WriteFileEvidence - Match double ended wildcards" run into timeout and reconcilation was broken.
Before the ARL-Update, this Step only tooks about 30 Min.
We've  adjusted registry on BatchServer to increase the timeout for the whole process and after this, the Step "...Match double ended wildcards" was processed in 2h 20min and Reconciliatioin was done successfully.

Also, before updating the ARL, the whole Reconciliation Process was done in 4,5h - after ARL update, it takes now almost 7,5h. 

Timeout-settings used:
https://community.flexera.com/t5/FlexNet-Manager-Knowledge-Base/Inventory-import-and-license-reconcile-timeouts/ta-p/5661


regards,
Matthias

[mschwach]

Hi,

after latest ARL release, I can also confirm the issue of long-term-running processes has been eliminated on our Env.

Speeking though, have you rolled back the "...match double ended wildcards..." (Tibco Unix evidences as mentioned by nrousseau1 above)?

Or how did you overcome this issue, Flexera? Just out of curiosity here.

regards,

Matthias

[ChrisG]

Yes, the Tibco Unix evidences that @nrousseau1 mentioned were removed in last week's ARL release.