Anatomy of an Outlier Bug: The Issue of the Failed App-V Report Upload

When software malfunctions, product support teams attempt to narrow the issue down to user error, configuration, or code. If the software attempts to perform a function where a specific result is expected and the actual results are different, we classify that as a bug. Of course, there is great debate on what is perceived as a bug, or is simply “by design” meaning the software was doing exactly what it was programmed to do – it just may be completely different from what the end user expected.

Let’s assume we are not having the “by design” vs. “bug” debate. When a bug confirmed, the next common item that is measured is the impact of that bug – impact within the specific customer’s environment, the frequency and likelihood of the bug occurrence. Bugs that have only occurred one or two times where the impact is minimal is usually referred to as an “outlier bug.”

Outlier bugs can be tricky – especially if there is not a known workaround. Software vendors have to weigh the risk and cost of implementing bug fixes via current version patches (as opposed to correcting the code for the next release.)

A while back I encountered one of those outlier bugs in which this bug only affected one customer (at the time) and it only revolved around one specific App-V package. It involved the App-V Client Reporting Agent failing to upload reporting XML data. The following issue was occurring.

Client machines were failing to upload reporting data. Upon a manual test using the Send-AppVClientReport cmdlet, it would yield the following error:

 

PS C:Windowssystem32> Send-AppvClientReport

Send-AppvClientReport : No reporting data has been sent to the specified URL. Verify the URL and try again.

Operation attempted: Send reporting data to reporting server.

AppV Error Code: 1300000013.

Please consult AppV Client Event Log for more details.

At line:1 char:1

+ Send-AppvClientReport

+ ~~~~~~~~~~~~~~~~~~~~~

    + CategoryInfo          : InvalidResult: (:) [Send-AppvClientReport], ClientException

    + FullyQualifiedErrorId : SendReportError,Microsoft.AppV.AppvClientPowerShell.SendAppvClientReport

==============

This issue was NOT occurring on all of the clients, so the first major step was to find the common denominator. Eventually we found the common denominator was a specific package. In addition, we actually got quite lucky. In many cases, the machines getting this issue only had one specific package deployed to them.

So we grabbed the XML file (C:ProgramDataMicrosoftAppVClientReportingdd6c24e-be93-48f7-b531-4eaa007128ec.xml) to view the Reporting cache and eventually narrowed it down to only occurring when the specific application was published.

What makes this issue an outlier is that the element that was causing the issue involved a package where the primary application had a version field that was greater than 16 characters. On a lark, we started modifying the XML data manually and found that if the reporting XML file was manually edited, and enough digits were removed from the version field, the upload worked. For some reason, only 16 characters were allowed in the version field. All of the fields were supposed to allow for 32.

Once root cause was narrowed down, the time came to assess the impact of the bug. It was definitely viewed as an outlier bug due to the fact there was only one known occurrence (again – at the time.) The assessment of how likely this would reoccur soon became a moot point as the good news here as the issue was within the database itself. The App-V 5 reporting service is stateless and writes directly to the temporary tables in the AppVReporting database. So we were able to fix the issue for the customer without cracking open binaries for patching.

If you are interested in the database script, it was published out on the TechNet Gallery here:

https://gallery.technet.microsoft.com/App-V-5-Fix-for-App-V-f8c1ac29

This fix was included in the App-V 5.1 release.

 

 

 

 

 

App-V: Arithmetic Overflow Error (0000B065) when Running System Utilization Report

Administrators can use the System Utilization Report to graph the total daily system usage. You can use this report to determine the load on your App-V Server.

This report tracks the usage over time during the reporting period for the specified server or for the server group.

The System Utilization Report also graphs the following system usage:

• Usage by day of the week
• Usage by hour of the day

The System Utilization Report also includes a summary of the total system usage for specific users and total session counts.

There is an issue, however that you may run into when you try to run a System Utilization Report by session count where you may get the following error:

Error: 0000B065

The SFTMMC.LOG (Management Console log) will also show the following:

2011-10-14 04:35:31                  https://steveth-appv/
ManagementConsole.MCException: Arithmetic overflow error converting expression to data type int. —> SoftGrid.Management.GetReportDataFailedException: Arithmetic overflow error converting expression to data type int. —> System.Data.OleDb.OleDbException: Arithmetic overflow error converting expression to data type int.
   at System.Data.OleDb.OleDbDataReader.ProcessResults(OleDbHResult hr)
   at System.Data.OleDb.OleDbDataReader.NextResult()
   at SoftGrid.Management.DataAccess.ReportDataAccess.GetSystemUtilizationBySessionData(DateTime startTime, DateTime endTime, Int32 serverGroupID, Int32 serverID, RptSystemDailySessions[]& dailySessions, RptSystemDayOfWeekSessions[]& dayOfWeekSessions, RptSystemHourOfDaySessions[]& hourOfDaySessions, RptSystemSessionUsageSummary& usageSummary)
   at SoftGrid.Management.Reports.GetSystemUtilizationBySessionData(DateTime startTime, DateTime endTime, Int32 serverGroupID, Int32 serverID, RptSystemDailySessions[]& dailySessions, RptSystemDayOfWeekSessions[]& dayOfWeekSessions, RptSystemHourOfDaySessions[]& hourOfDaySessions, RptSystemSessionUsageSummary& usageSummary)
   — End of inner exception stack trace —

Server stack trace:
   at SoftGrid.Management.Reports.GetSystemUtilizationBySessionData(DateTime startTime, DateTime endTime, Int32 serverGroupID, Int32 serverID, RptSystemDailySessions[]& dailySessions, RptSystemDayOfWeekSessions[]& dayOfWeekSessions, RptSystemHourOfDaySessions[]& hourOfDaySessions, RptSystemSessionUsageSummary& usageSummary)
   at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
   at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
   at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg, Int32 methodPtr, Boolean fExecuteInContext)

Exception rethrown at [0]:
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at SoftGrid.Management.IReports.GetSystemUtilizationBySessionData(DateTime startTime, DateTime endTime, Int32 serverGroupID, Int32 serverID, RptSystemDailySessions[]& dailySessions, RptSystemDayOfWeekSessions[]& dayOfWeekSessions, RptSystemHourOfDaySessions[]& hourOfDaySessions, RptSystemSessionUsageSummary& usageSummary)
   at ManagementConsole.ManagementSession.GetSystemUtilizationBySessionData(DateTime startTime, DateTime endTime, Int32 serverGroupID, Int32 serverID, RptSystemDailySessions[]& dailySessions, RptSystemDayOfWeekSessions[]& dayOfWeekSessions, RptSystemHourOfDaySessions[]& hourOfDaySessions, RptSystemSessionUsageSummary& usageSummary)
   — End of inner exception stack trace —

This is caused by the system exceeding a limit of calculation. When running the system utilization report the system calculates the total session duration in seconds for all users for all of the applications that have been used during the specified time period. This total must not exceed the current limit of 2,147 million seconds.

Reduce the time period used to generate the system utilization report so it falls within the current allowed limit. 30 Days will usually be a safe maximum.

App-V 4.6: App-V 4.6 Reporting does not work when using 4.1 Server

When Softgrid evolved into App-V for version 4.5, the reporting model was changed to where reporting is cached by the client and uploaded to the server during DC Refresh rather than with each application launch.

While 4.5 and 4.6 clients can connect to and use a 4.1 Softgrid Virtual Application Server, reporting will be disabled due to the difference in models. The 4.5/4.6 clients will cache this information in an XML file labled by a <GUID.>

The location of this <GUID>.XML file is registered using the LastCacheFile registry value in the following registry path:

HKEY_LOCAL_MACHINE\Software\Microsoft\Softgrid\4.5\Client\Reporting

This LastCacheFile contains both the path and GUID file name.

Here is an example of the reporting cache file:

<REPORT_DATA_CACHE><APP_RECORDS><APP_RECORD Name=”Adobe Reader 9.0″ Ver=”1.0″ Server=”app-v-ms.steveth.local” User=”STEVETH\Gladiator” “Launched=”8/19/2010 8:55:52 PM” Shutdown=”8/19/2010 8:56:00 PM”/><APP_RECORD name=”Adobe Reader 9.0″ Ver=”1.0″  Server=”app-v-ms.STEVETH.local” User=”STEVETH\Gladiator” Launched=”8/19/2010 8:58:58 PM” Shutdown=”8/19/2010 9:00:19 PM”/></APP_RECORDS></REPORT_DATA_CACHE>

The server reporting tag is located in the following registry path:

HKEY_LOCAL_MACHINE\Software\Microsoft\Softgrid\4.5\Client\DC Server\<SERVER>

The DWORD value is 1 by default when using a 4.5 or later server. it can be set to 0 to disable reporting. However, if the server is 4.1 and the client is 4.5 or later, then this value will always be reset to 0.

This process happens upon detection of the App-V 4.5 or later server. An event in the client log is also logged when this happens.

[08/19/2010 14:55:18:179 MIME VRB] {tid=BA4:usr=steveth}
DC server does not want to receive v4.5+ reporting