Unexplained Temp Table Errors

This is a reposting of an article Allan Cahill originally wrote on my Developing for Dynamics GP blog.

Hi, my name is Allan Cahill (pronounced “Carl”) and I work with David Musgrave in the Asia Pacific support team and I wanted to share the experiences I had working on a recent incident.

The Problem

Over a number of months, the Customer was receiving random errors when doing various tasks in Microsoft Dynamics GP (GP).  This was predominately when posting Receiving’s Transaction Batches using Project Accounting data yet reportedly was occurring randomly throughout other GP specific tasks.  Examples of errors reported by Customer:

• An open operation on table ‘PA_POP_POLine_Temp’ has an incorrect record length
• An open operation on table ‘PA_POP_poplandedcost_Temp’ failed because the path does not exist
• An open operation on table ‘PA_POP_poplandedcost_Temp’ has caused an unknown error (407)
• Error Registering table ‘PA_Billing_DTL_Work’
• FP: Couldn’t Close Table

Receivables Batch Posting:

• An open operation on table ‘RM_Keys_MSTR_TRX’ has an incorrect record length

This had been occurring for a year before being reported to Microsoft Support.  We initially undertook all the general steps in relation to rebuilding forms & reports dictionaries etc. yet the problem would continue to randomly occur weekly for all users on each of the user’s workstations.

We conducted a screen sharing session and focused on the TNT*.idx, TNT*.dat and TNT*.tmp files found in the user’s profile temp directory (as defined by the %temp% environmental variable) and found that some of the TNT files were dating to more than a year old on the workstation.

The TNT files are temporary files that are created as local ctree tables in the user’s temp folder rather than SQL tables in tempdb.  This is defined by the developer when the table definition is created in Dexterity.  Normally, these files should be deleted when the temporary file is no longer required such as when the posting process is finished.

In our troubleshooting, we would delete as many of the TNT*.idx, TNT*.dat and TNT*.tmp files that were not in use (on the specific workstation being worked on) and during our testing we were unable to replicate the above errors after deleting these files.  This made us believe the files were somehow the cause of our errors.   Posting was conducted on the SQL Server by the Customer for larger batches and the errors were never experienced.

The Theory

When Dexterity needs a temporary file which will be created as a local ctree file in the user’s temp folder, it will generate a file name based on the format TNTXXX.tmp (where XXX is 3 hexadecimal digits).  If we have 3 Hexadecimal digits (that is 000 to FFF, which gives 4096 possible values), then this helps explain that we have that many possible file names.

Dexterity then checks if this TNT*.tmp (working as a placeholder file) already exists.  If it does, it will generate a new hexadecimal value and try again.  Once Dexterity has a file name that does not exist, it will create it to flag that this file name is now being used.   Dexterity will now attempt to use the TNT*.dat and TNT*.idx files using the same hexadecimal value.  When a temp table is first accessed, if the TNT*.dat and TNT*.idx files do no already exist they will be created.  Dexterity expects that the corresponding TNT*.dat and TNT*.idx files do not exist initially.

Remember that in our case we had TNT*.dat and TNT*.idx files that had not been deleted for some reason.  When the file names are used again, Dexterity tries to re-use the existing TNT*.dat and TNT*.idx files which were most likely created for a different table definition, hence the errors are generated.

Thanks to David and his help in explaining this.

The Cause

Now we know what the cause was, we needed to focus on why the TNT*.dat and TNT*.idx files were not being deleted in this particular circumstance.   Because there were hundreds of TNT*.* files in the user’s temp directory that were not being deleted, we had in mind that the files were being locked thus not being deleted and the scenario that generally would cause this as we know is a virus or malware protection program.  We decided to use Windows Sysinternals Process Monitor to monitor what files and registry items were being accessed.  Process Monitor can be downloaded from:

• http://technet.microsoft.com/en-au/sysinternals/bb896645.aspx

We found that Trend Micro virus software (PC-Cillin) was running on the workstation and that it was locking the *.dat files as they were scanned.  The Process Name (service) found in the process monitor log and logged under path was:

“C:Program FilesTrend MicroBMTMBMSRV.exe” /service

This service was doing a Query_Open operation on the dat file eg:

3:04:12.3076110 PM   TMBMSRV.exe  928    FASTIO_NETWORK_QUERY_OPEN C:Documents and SettingsJDoeLocal SettingsTempTNT98B.dat  SUCCESS                     

And at the same time the dynamics.exe was trying to delete the file yet was not able to because the virus service was querying the file and had it locked eg:

3:04:14.3076111 PM Dynamics.exe 5364 SetDispositionInformationFile C:Documents and SettingsJDoeLocal SettingsTempTNT98B.dat CANNOT DELETE Delete: True

The Solution

We suggested to the Customer that they change PC-Cillin to exclude scanning the TNT*.idx, TNT*.dat and TNT*.tmp files; i.e. add these files as exclusions.

After adding these files as exclusions, the Customer has now monitored the situation for the past 8 weeks and there has not been any recurrence of the errors and the TNT*.idx, TNT*.dat and TNT*.tmp files are now being cleared automatically from the user’s temp folder (%temp%).

Summary

In summary, TNT*.dat files were being locked by PC-Cillin (virus/malware protection program) and subsequently, Dexterity was unable to delete the files when the temporary files were no longer needed.  As a consequence, the TNT*.dat file was not deleted and when it was used again by a new temporary file, it contained an incorrect table definition and did not match the new process thus causing the errors.

Cheers….

Allan

21-Apr-2010: Also look at the An open operation on table ‘[TEMP Table]’ errors post on this blog.

This article was originally posted on the Developing for Dynamics GP Blog and has been reposted on http://www.winthropdc.com/blog.