JDK-6819298 : FX AU needs better error reporting in jusched.log
  • Type: Bug
  • Component: install
  • Sub-Component: install
  • Affected Version: 6u14
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: windows_vista,windows_7
  • CPU: x86
  • Submitted: 2009-03-19
  • Updated: 2010-08-06
  • Resolved: 2010-01-30
Related Reports
Duplicate :  
JDK-6839351 - FX AU is skipped on Windows 7 with Admin mode and UAC ON.
Duplicate :  
JDK-6819637 - FX Preload jar is failing on Windows 7 and Vista with UAC ON and ADMIN user
Relates :  
JDK-6787812 - Java FX AU is not working with Non Admin UAC ON with Vista
Description
Please make sure UAC is Enabled and User is Admin user on windows 7.
How to reproduce?

1.) Install the latest 6u14 b03 JRE
2.) Run the jusched.exe for 7-8 Mins, and kill jusched.exe.
3.) Clean the cache from JCP.
4.) Modify the system date accroding to the FX AU schedule.
5) Relaunch jesched.exe and here is the output of jusched.log.
Thu Mar 19 17:45:45 2009
:: JavaUpdate NextSchedTime=Sun Apr 05 14:13:00 2009
JavaFXUpdate NextSchedTime=Wed Mar 25 01:57:00 2009
JavaFX: lastSchedTime=Wed Mar 18 01:57:00 2009
JavaFX: nextSchedTime=Wed Mar 25 01:57:00 2009
JavaFX: sleeptime (sec=461475, hours=128)
actual sleep time=461503073 msecs (128:11:43) for JavaFX

Wed Mar 25 01:56:04 2009
:: **************** Running jusched ****************

Wed Mar 25 01:56:04 2009
:: GetRunNow: lastFinish=NULL

Wed Mar 25 01:56:04 2009
:: GetJavaFXUpdateTimeKey: returning FALSE

Wed Mar 25 01:56:04 2009
:: GetJavaFXUpdateTimeKey: returning FALSE

Wed Mar 25 01:56:04 2009
:: GetRunNow: lastFinish=NULL

Wed Mar 25 01:56:05 2009
:: JavaUpdate NextSchedTime=Sun Apr 05 14:29:00 2009
JavaFXUpdate NextSchedTime=Wed Mar 25 01:57:00 2009
JavaFX: lastSchedTime=Wed Mar 18 01:57:00 2009
JavaFX: nextSchedTime=Wed Mar 25 01:57:00 2009
JavaFX: sleeptime (sec=55, hours=0)
actual sleep time=57444 msecs (0:00:57) for JavaFX

Wed Mar 25 01:57:02 2009
:: Timeout occured.  Run JavaFX update now.

Wed Mar 25 01:57:02 2009
:: Started JavaFX Update process Command:C:\Program Files\Java\jre6\bin\javaws.e
xe  -silent -import -reverse -javafxau -J-Dkernel.download.dialog=false "http://
dl.javafx.com/javafx-cache.jnlp"
Return:1 Error:2

Wed Mar 25 01:57:02 2009
:: JavaUpdate NextSchedTime=Sun Apr 05 14:29:00 2009
JavaFXUpdate NextSchedTime=Wed Apr 01 01:57:00 2009
JavaFX: lastSchedTime=Wed Mar 25 01:57:00 2009
JavaFX: nextSchedTime=Wed Apr 01 01:57:00 2009
JavaFX: sleeptime (sec=604798, hours=167)
actual sleep time=604823070 msecs (168:00:23) for JavaFX
Comments
EVALUATION this is fixed already as part of 6869703: further enhancement to cached JAR pre-verification UpdateScheduler.cpp is updated to only output error log if CreateProcess fails.
30-01-2010
EVALUATION My previous evaluation is not correct. In UpdateScheduler.cpp (See the code below), dwExitCode is actually not the exit code of the process. http://msdn.microsoft.com/en-us/library/ms682425(VS.85).aspx For the CreateProcess function, if the function succeeds, the return value is nonzero. If the function fails, the return value is zero. So the GetLastError call here actually returns nothing meaningful, because we are calling it when the CreateProcess succeeded. GetLastError only works correctly when CreateProcess returns 0. That's why we always get these logged in the jusched.log: Wed Mar 25 01:57:02 2009 :: Started JavaFX Update process Command:C:\Program Files\Java\jre6\bin\javaws.e xe -silent -import -reverse -javafxau -J-Dkernel.download.dialog=false "http:// dl.javafx.com/javafx-cache.jnlp" Return:1 Error:2 This "Return: 1 Error:2" message is bogus. " if (dwExitCode != ERROR_SUCCESS) {" really means CreateProcess succeeded, that's all. (ERROR_SUCCESS is 0) And my evaluation in bug report is not correct on javaws import exit code. javaws -import actually exit with 0 instead of -1. But this is not relevant here anyway, because we are not looking at process exit code at all. We should update our error reporting to print out correct information here.
19-08-2009
EVALUATION Tried on winXP, win7 and vista, FX AU is working for admin user and UAC on. the real problem is "javaws -import -silent ..." will always exit with -1, and we write jusched.log as error: > :: Started JavaFX Update process Command:C:\Program Files\Java\jre6\bin\javaws.exe -silent -import -reverse -javafxau -J-Dkernel.download.dialog=false "http://dl.javafx.com/javafx-cache.jnlp" > Return:1 Error:2 when javaws.exe import exit, we call exit(-1). So in the java update code, we detected the process didn't finish with ERROR_SUCCESS, and hence we write the line "Return:1 Error:2 (or 0 on XP)". javaws -import is actually performed without problems. we should change javaws.exe to exit with a valid error code, so the jusched.log message will reflect actual status.
25-03-2009