Timeout occurred (0x87D00213 or -2016411117)

Topics: Archive - General
Aug 6, 2014 at 6:03 PM
Edited Aug 6, 2014 at 6:04 PM
I'm getting an error on a bunch of clients in my initial stages of a Java upgrade:

Image

I believe what is happening is the UI pops up and asks the user to close stuff, but there is no-one there and eventually it times out.

Is there a way to assume that the user isn't coming back - close the apps anyhow and continue the upgrade?
Coordinator
Aug 6, 2014 at 9:49 PM
If you look at the config file for the toolkit you'll see the exit code for the timeout is 1618 - that's not what is showing in your console. The toolkit is set to automatically timeout after 1 hour 55 minutes if there is no response to UI prompts. This is to avoid SCCM from reporting errors. Can you get a hold of the log files from one of the machines?
Aug 7, 2014 at 12:20 AM
I think I didn't have the max runtime high enough - so I set it to two hours to allow for a proper exit.

Still - I wouldn't mind having an option to assume after two hours of no user input - just go ahead and run the upgrade anyhow (killing off all offending apps and running my various config scripts etc).
Coordinator
Aug 7, 2014 at 7:29 AM
I don't think that's your problem. The toolkit is set to timeout after 1 hr 55 by default so that we can control the exit code passed back to SCCM.

You really need to get hold of the log files from an affected machine to see what is happening with these deployments.

There is an option to use the CloseAppsCountdown to force close apps after elapsed period but this will only get around the timeout if you are not offering a deferral or if be deferrals have expired.
Aug 7, 2014 at 10:23 PM
Here is the log from a machine that "timed out" - nothing of note sadly :/. I checked the detected methods - msi guid and the java.exe being 6.0.81 and it looks like it got updated just fine.

Maybe its some crappy client health issue - as the next time we do application evals - which is 4pm every day - the machine is compliant.

[07-08-2014 01:00:52] [Initialization] Oracle_Java_6Update81_x86_EN_01 setup started.
[07-08-2014 01:00:52] [Initialization] Script [C:\Windows\ccmcache\68\AppDeployToolkit\AppDeployToolkitExtensions.ps1] dot-source invoked by [C:\Windows\ccmcache\68\AppDeployToolkit\AppDeployToolkitMain.ps1]
[07-08-2014 01:00:53] [Initialization] Oracle_Java_6Update81_x86_EN_01 script version is [1.0.0]
[07-08-2014 01:00:53] [Initialization] Deploy Application script version is [3.1.3]
[07-08-2014 01:00:53] [Initialization] The following non-default parameters were passed to [Deploy Application]: [-DeploymentType Install -DeployMode Silent]
[07-08-2014 01:00:53] [Initialization] App Deploy Toolkit Main script version is [3.1.5]
[07-08-2014 01:00:53] [Initialization] App Deploy Toolkit Extensions version is [1.0.0]
[07-08-2014 01:00:53] [Initialization] PowerShell version is [3.0 x64]
[07-08-2014 01:00:53] [Initialization] PowerShell host is [ConsoleHost version 3.0]
[07-08-2014 01:00:53] [Initialization] OS version is [Microsoft Windows 7 Enterprise 64-bit 6.1.7601]
[07-08-2014 01:00:53] [Initialization] Hardware platform is [Physical]
[07-08-2014 01:00:53] [Initialization] Computer name is [ML115-RELEASE-3]
[07-08-2014 01:00:53] [Initialization] Current user is [PSU\ML115-RELEASE-3$]
[07-08-2014 01:00:54] [Initialization] Current Culture is [en-US] and UI language is [EN]
[07-08-2014 01:00:54] [Initialization] Deployment type is [Installation]
[07-08-2014 01:00:54] [Initialization] Script [C:\Windows\ccmcache\68\AppDeployToolkit\AppDeployToolkitMain.ps1] dot-source invoked by [C:\Windows\ccmcache\68\Deploy-Application.ps1]
[07-08-2014 01:00:54] [Initialization] The following users are logged on to the system: PSU\kioskuxx
[07-08-2014 01:00:54] [Initialization] Session 0 detected.
[07-08-2014 01:00:54] [Initialization] Installation is running in [NonInteractive] mode.
[07-08-2014 01:00:54] [Pre-Installation] Evaluating disk space requirements...
[07-08-2014 01:00:55] [Pre-Installation] Disk space requirements are met.
[07-08-2014 01:00:55] [Pre-Installation] Getting deferral history...
[07-08-2014 01:00:55] [Pre-Installation] Getting Registry key [Registry::\HKEY_LOCAL_MACHINE\SOFTWARE\PSAppDeployToolkit\DeferHistory\Oracle_Java_6Update81_x86_EN_01] ...
[07-08-2014 01:00:55] [Pre-Installation] Registry key does not exist: [Registry::\HKEY_LOCAL_MACHINE\SOFTWARE\PSAppDeployToolkit\DeferHistory\Oracle_Java_6Update81_x86_EN_01]
[07-08-2014 01:00:55] [Pre-Installation] User now has [2] deferrals remaining.
[07-08-2014 01:00:55] [Pre-Installation] Checking for running applications [java,javacpl,javaw,javaws,jucheck,obunity,iexplore,chrome,firefox]...
[07-08-2014 01:00:55] [Pre-Installation] Applications are not running.
[07-08-2014 01:00:55] [Pre-Installation] Finished checking running applications.
[07-08-2014 01:00:56] [Installation] Working Directory is [C:\Windows\ccmcache\68\Files]
[07-08-2014 01:00:56] [Installation] Executing [msiexec.exe /i "C:\Windows\ccmcache\68\Files\jre1.6.0_81.msi" TRANSFORMS="java.mst" /qn /L*v "C:\Windows\Logs\Software\jre1.6.0_81_Install.log"]...
[07-08-2014 01:02:39] [Installation] Execution completed successfully with exit code [0]
[07-08-2014 01:02:39] [Post-Installation] Oracle_Java_6Update81_x86_EN_01 Installation completed with exit code [0].
[07-08-2014 01:02:40] [Post-Installation] ----------------------------------------------------------------------------------------------------------
Coordinator
Aug 7, 2014 at 10:30 PM
Worth checking AppEnforce.log to see if that shows anything different.
Aug 7, 2014 at 10:41 PM
Yeah something is amiss. From AppDeployment.log:

<![LOG[+++ Starting Install enforcement for App DT "Install - Java 6 Update 81 - Unattended" ApplicationDeliveryType - ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, Revision - 5, ContentPath - C:\Windows\ccmcache\68, Execution Context - System]LOG]!><time="01:00:39.185+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appprovider.cpp:1702">
<![LOG[ A user is logged on to the system.]LOG]!><time="01:00:39.388+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appprovider.cpp:2083">
<![LOG[ Performing detection of app deployment type Install - Java 6 Update 81 - Unattended(ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, revision 5) for system.]LOG]!><time="01:00:39.388+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appprovider.cpp:2148">
<![LOG[+++ Application not discovered. [AppDT Id: ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, Revision: 5]]LOG]!><time="01:00:39.466+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="localapphandler.cpp:291">
<![LOG[ App enforcement environment:
Context: Machine
Command line: Deploy-Application.EXE -DeploymentType "Install" -DeployMode "Silent"
Allow user interaction: No
UI mode: 1
User token: null
Session Id: 4294967295
Content path: C:\Windows\ccmcache\68
Working directory: ]LOG]!><time="01:00:39.512+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appcontext.cpp:85">
Not discovered...

But from AppDiscovery:

<![LOG[Entering ExecQueryAsync for query "select * from CCM_AppDeliveryType where (AppDeliveryTypeId = "ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_955001fb-73e5-4751-8977-098b635f167d" AND Revision = 5)"]LOG]!><time="01:00:42.586+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="708" file="appprovider.cpp:406">
<![LOG[ Performing detection of app deployment type Install - Java 6 Update 81 - User attended(ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_955001fb-73e5-4751-8977-098b635f167d, revision 5) for system.]LOG]!><time="01:00:42.601+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="708" file="appprovider.cpp:2148">
<![LOG[+++ Application not discovered. [AppDT Id: ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_955001fb-73e5-4751-8977-098b635f167d, Revision: 5]]LOG]!><time="01:00:42.648+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="708" file="localapphandler.cpp:291">
<![LOG[+++ Did not detect app deployment type Install - Java 6 Update 81 - User attended(ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_955001fb-73e5-4751-8977-098b635f167d, revision 5) for system.]LOG]!><time="01:00:42.648+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="708" file="appprovider.cpp:540">

Then later on that night:

<![LOG[ Performing detection of app deployment type Install - Java 6 Update 81 - Unattended(ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, revision 6) for system.]LOG]!><time="11:18:44.318+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="2548" file="appprovider.cpp:2148">
<![LOG[+++ Discovered application [AppDT Id: ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, Revision: 6]]LOG]!><time="11:18:44.411+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="2548" file="localapphandler.cpp:287">
<![LOG[+++ Detected app deployment type Install - Java 6 Update 81 - Unattended(ScopeId_6481FEFB-78E2-49E0-BA0B-70A340F0B309/DeploymentType_6d1d6bf3-4810-4cff-aafb-a81be75c4930, revision 6) for system.]LOG]!><time="11:18:44.411+420" date="08-07-2014" component="AppDiscovery" context="" type="1" thread="2548" file="appprovider.cpp:524">
Coordinator
Aug 9, 2014 at 8:27 AM
I can't see the actual exit code from AppEnforce.log - would be good to see if that matches the toolkit log. Could it be something to do with the detection method?
Aug 11, 2014 at 7:24 PM
Edited Aug 11, 2014 at 7:28 PM
No there is - it lines up with the PSADT exit code too:

[07-08-2014 01:02:39] [Post-Installation] Oracle_Java_6Update81_x86_EN_01 Installation completed with exit code [0].

From App Enforce:

<![LOG[ Looking for exit code 0 in exit codes table...]LOG]!><time="01:02:41.443+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appexcnlib.cpp:505">
<![LOG[ Matched exit code 0 to a Success entry in exit codes table.]LOG]!><time="01:02:41.443+420" date="08-07-2014" component="AppEnforce" context="" type="1" thread="2928" file="appexcnlib.cpp:584">

The detection method is msi product code and java.exe must match version 6.0.810.32 - I've found in the past Java is pretty easy to munge so I require both be there to be considered a valid install.

Interestingly enough - this machine has gone into the "Already Compliant" bin with no changes all week on this rollout, and it didn't need to reinstall according to the PSADT log and its no longer in the error list. In fact all the machines that had the script timeout error have been cleared.

Maybe I'll just chalk this up to transient CM 2012 bug.