IcedTea6-plugin PluginAppletSecurityContext NullPointers - this bug is reproducable with icedtea 1.4 on F10 i686 out of the box!

Mon Feb 16 15:55:38 PST 2009

Of pure luck i found a way to reproduce this nullpointer bug on my home 
machine running a newly installed F10 with icedtea 1.4 on my i686 box.
[xranby at pusspuss Skrivbord]$ java -version
java version "1.6.0_0"
IcedTea6 1.4 (fedora-9.b14.fc10-i386) Runtime Environment (build 
1.6.0_0-b14)
OpenJDK Server VM (build 14.0-b08, mixed mode)

the plugin used in firefox 3.0.6 are:
Filename: IcedTeaPlugin.so
The IcedTea Java Web Browser Plugin 1.4 (fedora-9.b14.fc10-i386) 
executes Java applets.

to reproduce:
1. make sure all certificates are removed from netx by running javaws 
-viewer and remove any trusted certificates for the test-applet
2. load firefox and load a page with a signed applet like : 
http://geomajas.org/users/oliverm/freerunner-gpsApplet/test-applet.html
3. wait more than 10 secods while the warning-security window is up 
(from netx)
4. now click on run applet without checking the checkbox that you trusts 
the provider.
5. push the get gps data and you will recive the null message in the 
message box

if you reload the browserwindow and klick on run applet within less 
than10seconds on the warning-security window then the get gps data 
button work.

you can the try reload the browser again and wait more than 10 sec 
during the security-window and then see the applet fail again.

on my machine firefox consumes about 40% cpu time while the plugin waits 
during the security-window, when the applet decides to stop waiting and 
applet initialization fails cpu usage goes down to 0.

basically what happens are that the applet initialization fails after 
about 10 seconds when waiting for the user to decide if it trusts a 
signed applet if the user have not responded within 10 seconds. So 
basically this bus manifested itself more often on ARM since it took too 
long for the user push the run button on ARM machines.
i have compare the java.stderr logs from a failed and successful run 
from the same machine with the same build of icedtea 1.4 and it is quite 
clear that the applet initialization fails when the plugin has to wait 
too long for the security warning window to close.
*snip*

--- firefox f10 bug/java.stderr    2009-02-16 23:46:11.000000000 +0100
+++ firefox f10 without bug/java.stderr    2009-02-17 00:02:12.000000000 
+0100
@@ -18,15 +18,15 @@
 REQUEST HANDLE NOT SET: 0. BYPASSING
 Consumption completed by consumer thread 0
 Waiting for data...
-  PIPE: appletviewer read: instance 1 handle 35654084
-Consumer received message instance 1 handle 35654084
-Message instance 1 handle 35654084 added to queue. Looking for free 
worker...
+  PIPE: appletviewer read: instance 1 handle 35652530
+Consumer received message instance 1 handle 35652530
+Message instance 1 handle 35652530 added to queue. Looking for free 
worker...
 Found free worker with id 0
 Consumer thread 0 woken...
-Consumer thread 0 consuming instance 1 handle 35654084
-Breakdown -- type: instance identifier: 1 reference: -1 src: null 
privileges: null rest: "handle 35654084"
-PAV handling: handle 35654084
-REQUEST HANDLE: 35654084
+Consumer thread 0 consuming instance 1 handle 35652530
+Breakdown -- type: instance identifier: 1 reference: -1 src: null 
privileges: null rest: "handle 35652530"
+PAV handling: handle 35652530
+REQUEST HANDLE: 35652530
 REQUEST HANDLE, PARSING Thread[Thread-1,5,main]
 PUT id = 'communicatorApplet'
 PUT code = 'org.geomajas.applet.FreerunnerCommunicator.class'
@@ -98,51 +98,6 @@
 Waiting for applet to initialize...
 Waiting for applet to initialize...
 Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-Waiting for applet to initialize...
-  PIPE: appletviewer wrote: instance 1 reference -1 fatalError 
Initialization failed
-REQUEST HANDLE, DONE PARSING Thread[Thread-1,5,main]
-Consumption completed by consumer thread 0
 WRITING 2: instance 1 status Appleten är inläst.
   PIPE: appletviewer wrote: instance 1 status Appleten är inläst.
 WRITING 2 DONE
@@ -152,6 +107,14 @@
 WRITING 2: instance 1 status Appleten har startat.
   PIPE: appletviewer wrote: instance 1 status Appleten har startat.
 WRITING 2 DONE
+Waiting for applet to initialize...
+Applet initialized
+Associating net.sourceforge.jnlp.runtime.JNLPClassLoader at 1c8f59c with 
http://geomajas.org
+WRITING 2: instance 1 initialized
+  PIPE: appletviewer wrote: instance 1 initialized
+WRITING 2 DONE
+REQUEST HANDLE, DONE PARSING Thread[Thread-1,5,main]
+Consumption completed by consumer thread 0
*snap*

Cheers and have a great day!
Xerxes

Deepak Bhole skrev:
> * Oliver May <oliver.may at dfc.be> [2009-02-13 04:35]:
>   
>> Seems my message got hold back by the mailing list because the large 
>> attachment, I uploaded the file to the website too:
>> http://geomajas.org/users/oliverm/freerunner-gpsApplet/applet-test.tgz
>>
>> Hi Deepak!
>>
>>  >>
>>  >> What website do you see this error on?
>>  >>
>>  >> As for PluginDebug.debug() ... its messages go to STDERR. However,
>>  >> debug() prints only if you have set ICEDTEAPLUGIN_DEBUG=true, and in
>>  >> that case, all OUT/ERR is redirected to /tmp/java.stdout and
>>  >> /tmp/java.stderr
>>  >>
>>  >> Cheers,
>>  >> Deepak
>>  >>
>>  >
>>  > Whoops.. should have checked the ML first.
>>  >
>>  > Okay, can you start the browser with the env variable
>>  > ICEDTEAPLUGIN_DEBUG=true , and then send the resulting log
>>  > and /tmp/java.std* files?
>>  >
>>  > Deepak
>>  >
>>
>> I did some more testing, and put the applet I am using online with some
>> simple javascript <> java interaction, including the source files.
>>
>> http://geomajas.org/users/oliverm/freerunner-gpsApplet/test-applet.html
>>
>>     
>
> What version of IcedTea are you trying this with again? I think I have
> seen this sort of error once before, but I was never able to reproduce
> it. After that though, I changed one of the structures in
> PluginAppletSecurityContext (where the NPE is happening) to be a
> Hashtable instead of HashMap. So in theory, any NPE should get thrown
> when the table is updated, rather than when the value is read. From the
> logs, it appears that the latter is the case.
>
> Can you try running it with IcedTea 1.4 or later and attach those logs
> please?
>
> Thanks,
> Deepak
>
>   
>> The applet expects a gpsd running on localhost, but it wont crash
>> without it. You may forward local port 2947 to gpsd.mainframe.cx:2947
>> for some real data (real, but static, mainframe.cx is not moving :)).
>>
>> Using this site I just did a test with debugging output:
>>
>> debian-gta02:/tmp# ICEDTEAPLUGIN_DEBUG=true
>> debian-gta02:/tmp# export ICEDTEAPLUGIN_DEBUG
>> debian-gta02:/tmp# (iceweasel > /tmp/iceweasel.out) >& /tmp/iceweasel.err
>>
>> so i have also gathered the iceweasel process out and err streams.
>>
>> What I did is:
>> +Started iceweasel and opened http://geomajas.org....
>> +Waited until the applet was completely loaded (cpu idle)
>> +Clicked on "Start gps" and waited like 10 minutes until cpu idle
>> +Clicked on "Get gps data", this returned null in the textbox after half
>> a second.
>> +Clicked on "Stop gps"
>> +Clicked on "Get gps data" again, wich actet the same way as before
>> +Closed iceweasel
>>
>> Btw, there seem to be some real performance issues too, the first call
>> from javascript to java takes ages, esp. with debugging turned on. But
>> that could even well be the rather slow cpu (200 bogoMIPS, 400MHz arm).
>>
>> Greetings!
>>
>> -- 
>> Oliver May
>>
>> DFC Software Engineering
>> GeoMajas partner www.geomajas.org
>>
>> Brugsesteenweg 587
>> B-9030 Gent
>> Belgium
>> T: +32 9 236 61 96
>> F: +32 9 236 54 12
>> E: oliver.may at dfc.be
>> W: www.dfc.be
>>
>>     


