Re: QA Test debugging

Tue, 26 Feb 2013 02:30:47 -0800 

Thanks Dan & Gregg,
I've treated Permission object's as immutable, but that's clearly a poor assumption, despite the Permission javadoc suggesting implementations should be immutable, just shows you can't be too careful with other people's code. 


To make an object effectively immutable (without final fields), it must 
be safely published after construction, which means writing to a 
concurrent collection, queue, final field, volatile field or a field 
protected by synchronization for the hand over from one thread to the 
next, it cannot be modified after publication either.



A truely immutable object has final fields, safe construction and can't 
be modified, it's safely published after the constructor returns, so is 
more robust as Gregg mentioned.



In this case, I've broken this rule, I've added SocketPermission to an 
unsynchronized collection (protected from external modification) and 
that collection is published to a final field in a constructor.



Now this is where things get a little uncertain, this final field only 
applies to the safe publication of the Collection, the Permission 
objects it contains are not referenced by final fields nor synchronized 
so they're not safely published, even though Permission objects are 
written to this collection prior to the final field being initialised.  
(At least that's what I gather from reading Concurrency in practise).


So I'm going to have to take a minor performance hit.

There are two solutions:

  1. Use a concurrent collection instead (ConcurrentSkipListSet, which
     is a ConcurrentSkipListMap discuised as a Set)
  2. Wrap each Permission in an Object and safely publish the
     Permission to a final field, then add the wrapper to the
     collection, the other thread then accesses the final field
     ensuring safe publication.  The collection is still an
     unsynchronized collection, but now contains immutable objects and
     hasn't been changed since it was published.


Option 2 requires the creation of more temporary objects, but should 
still avoid cache misses, while option 1 uses volatile variables to 
safely publish the Permission's.  Since this collection isn't modified 
after construction volatile reads will be almost as cheap as nonvolatile 
reads and I can use the existing PermissionComparator.  I think I'll go 
with option 1.



If you look at any security debugging output, remembering that many 
duplicate checks are eliminated by CombinerSecurityManager, the security 
architecture in a network environment gets absolutely hammered.



I'll modify org.apache.river.api.security.PermissionGrant accordingly, 
then commit.



We've already gone to significant trouble to avoid calling equals and 
hashcode on Permission objects.  SocketPermission has proven very 
challenging indeed.



The reason I suspect it's unsafe publication is the SocketPermission 
denied is 100% equal to that required.  PermissionComparator should pick 
that up, by comparing the class, name and actions of Permission objects 
(The comparator is used to avoid calling equals or implies unnecessarily).



CombinerSecurityManager has no such issue, it already uses a final field 
to store a permission, the problem appeared to be with the construction 
of PermissionGrant, which is where the handover between the policy 
parser thread and permission checking threads occur.


Cheers,

Peter.

On 26/02/2013 12:45 PM, Gregg Wonderly wrote:

Object construction is supposed to cause a "happens before" so that every single constructor doesn't have to 
have "synchronized" on it, to work in a concurrent environment.  Creating a thread, or otherwise leaking a 
"this" reference, calling a non-final method and other such "errors" in constructors are ways that 
you can end up without visibility of the completely constructed object.

Gregg Wonderly

On Feb 25, 2013, at 2:32 PM, Peter<[email protected]>  wrote:


Did you mean Sun bug number? 7123126

I'm wondering, the init method sets fields during construction of 
SocketPermission, are these fields guaranteed to be visible to all threads 
after construction?

Peter.

----- Original message -----

What is the issue number for you issue Peter?

Gregg

On Feb 25, 2013, at 7:33 AM, Dan Creswell<[email protected]>  wrote:


On 25 February 2013 12:40, Peter Firmstone<[email protected]>  wrote:

Bryan,

I'm interrogating the usual suspects first.

I've checked com.sun.jini.start.AggregatePolicyProvider and
MergedPolicyProvider but they look clean, java.security.Permissions is known
to have UnresolvablePermissions and not resolve them, however that
visibility issue is limited to UnresolvePermission's (I had to write an
entire replacement in org.apache.river.api.security.ConcurrentPermissions to
get around that issue, that's another story, I haven't raised a bug with
Oracle, I'll do that after they sort out the SocketPermission concurrency
bug I've raised, don't want to give them too much work all at once :).

 From java.security.Permission javadoc:


Permission objects are similar to String objects in that they are
immutable once they have been created. Subclasses should not provide
methods that can change the state of a permission once it has been created.


SocketPermission, breaks this contract, it mutates internally after
construction, this might be affecting thread visibility.


Mmmm, I've just given that a light review and whilst it mutates it
looks like it's all simple assignments with no inter-dependencies and
the assignments are arguably deterministic (e.g. it's getting hold of
machine names or IP addresses which don't change much except via DHCP
games etc. So they *could* change but if they did it'd screw up many
things other than permissions).

Each of the fields is a primitive or a reference which are atomic
assignments (there are no longs for example).

Each thread will go through the same sequence of assignments and
initialisations so whilst there may be overlap, all threads will see
either an uninitialised or initialised value. In cases where the value
is uninitialised each thread will compute that itself and assign it
itself. There would be potential for duplicate work to be done in
initialisation but it's probably better than having locking and thread
contention in this case.

As I say, light review, so it could be the culprit but it doesn't feel
like a great candidate to me.


I noticed test failures aren't definite, the number of failed tests has been
reduced significantly by enabling security debugging, luckily we're still
seeing failures however.

Suggests a race condition for sure...


We're going to need to step through one of these tests and cofirm the policy
provider and check SocketPermission.implies().

I suspect we're having issues with SocketPermission's thread visibility.

If that's the case, there are three options for a fix:

   1. Wait for Oracle to fix it (don't get your hopes up).
   2. Construct SocketPermission on demand and thread confine it.
   3. Create a replacement for SocketPermission and
         SocketPermissionCollection and substitute.

If the issue is SocketPermission, I'll probably go for option 2.

If it's something else, or the problem goes away during debugging, it could
require much head scratching to fix (brute force patch attempts).

The major problem is SocketPermission isn't being implied, the
ProtectionDomain clearly has the required Permission, see appended.

I'll get back to you with a patch to enable debugging and some instructions.

Thanks again for helping,

Peter.


ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:access: access denied
(java.net.SocketPermission bryan-thompson-macbook-Air.local
connect,accept,resolve)
           [java] ActSys-err: Feb 24, 2013 8:24:07
AM:Group-0:err:java.lang.Exception: Stack trace
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Thread.dumpStack(Thread.java:1273)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessControlContext.checkPermission(AccessControlContext.java:364)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessController.checkPermission(AccessController.java:549)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.SecurityManager.checkPermission(SecurityManager.java:532)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader$4.run(URLClassLoader.java:515)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessController.doPrivileged(Native Method)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader.getPermissions(URLClassLoader.java:513)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.loader.pref.PreferredClassLoader.getPermissions(PreferredClassLoader.java:1137)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.SecureClassLoader.getProtectionDomain(SecureClassLoader.java:235)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader.access$000(URLClassLoader.java:58)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader$1.run(URLClassLoader.java:197)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessController.doPrivileged(Native Method)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.net.URLClassLoader.findClass(URLClassLoader.java:190)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.ClassLoader.loadClass(ClassLoader.java:306)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.loader.pref.PreferredClassLoader.loadClass(PreferredClassLoader.java:965)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.ClassLoader.loadClass(ClassLoader.java:247)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Class.getDeclaredMethods0(Native Method)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Class.privateGetDeclaredMethods(Class.java:2436)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Class.privateGetPublicMethods(Class.java:2556)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Class.getMethods(Class.java:1412)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
sun.misc.ProxyGenerator.generateClassFile(ProxyGenerator.java:409)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
sun.misc.ProxyGenerator.generateProxyClass(ProxyGenerator.java:306)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.reflect.Proxy.getProxyClass0(Proxy.java:610)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.reflect.Proxy.getProxyClass(Proxy.java:394)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.loader.pref.PreferredClassProvider.loadProxyClass(PreferredClassProvider.java:1308)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.loader.pref.PreferredClassProvider.loadProxyClass(PreferredClassProvider.java:1186)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.rmi.server.RMIClassLoader.loadProxyClass(RMIClassLoader.java:294)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.loader.ClassLoading.loadProxyClass(ClassLoading.java:240)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.io.MarshalInputStream.resolveProxyClass(MarshalInputStream.java:373)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readProxyDesc(ObjectInputStream.java:1528)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1490)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1729)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1326)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1950)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1874)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1756)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1326)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.io.ObjectInputStream.readObject(ObjectInputStream.java:348)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Util.unmarshalValue(Util.java:221)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.jeri.BasicInvocationDispatcher.unmarshalArguments(BasicInvocationDispatcher.java:1057)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.jeri.BasicInvocationDispatcher.dispatch(BasicInvocationDispatcher.java:601)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target$2.run(Target.java:491)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.export.ServerContext.doWithServerContext(ServerContext.java:108)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target.dispatch(Target.java:488)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target.access$000(Target.java:57)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target$1.run(Target.java:464)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessController.doPrivileged(Native Method)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target.dispatch(Target.java:461)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.Target.dispatch(Target.java:426)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.runtime.DgcRequestDispatcher.dispatch(DgcRequestDispatcher.java:210)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
net.jini.jeri.connection.ServerConnectionManager$Dispatcher.dispatch(ServerConnectionManager.java:147)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.mux.MuxServer$1$1.run(MuxServer.java:244)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.security.AccessController.doPrivileged(Native Method)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.jeri.internal.mux.MuxServer$1.run(MuxServer.java:241)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.thread.ThreadPool$Task.run(ThreadPool.java:143)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
com.sun.jini.thread.ThreadPool$Worker.run(ThreadPool.java:177)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:    at
java.lang.Thread.run(Thread.java:680)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:access:
access allowed (java.security.SecurityPermission getPolicy)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:access:
domain that failed ProtectionDomain
(http://bryan-thompson-macbook-Air.local:9080/phoenix-dl.jar<no signer
certificates>)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err: null
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:<no
principals>
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
java.security.Permissions@ec0a9f9 (
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.io.FilePermission
/Users/bryan/Documents/workspace/river/trunk/qa/lib/- read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission apple.laf.* read,write)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vendor.url read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.name read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission com.apple.macos.useScreenMenuBar read,write)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission file.separator read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.specification.vendor read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission line.separator read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.specification.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission FILEPOLICY02 read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.specification.vendor read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.* read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission os.name read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.system.class.loader read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.vendor read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission path.separator read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.specification.name read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission os.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission
com.sun.jini.reggie.enableImplToStubReplacement read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission com.apple.hwaccel read,write)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission mrj.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission os.arch read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission apple.awt.* read,write)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.class.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vendor read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.vm.specification.name read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.util.PropertyPermission java.specification.version read)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err: (unresolved
com.sun.jini.phoenix.ExecPermission /bin/javax )
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err: (unresolved
com.sun.jini.phoenix.ExecPermission /bin/javax )
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err: (unresolved
com.sun.jini.phoenix.ExecOptionPermission * )
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err: (unresolved
com.sun.jini.phoenix.ExecOptionPermission * )
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.security.SecurityPermission getPolicy)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.lang.RuntimePermission createClassLoader)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.lang.RuntimePermission stopThread)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.net.SocketPermission bryan-thompson-macbook-Air.local
connect,accept,resolve)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.net.SocketPermission bryan-thompson-macbook-Air.local:9080
connect,resolve)
           [java] ActSys-err: Feb 24, 2013 8:24:07 AM:Group-0:err:
(java.net.SocketPermission localhost:1024- listen,resolve)



























					Reply via email to