river-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Dan Creswell <dan.cresw...@gmail.com>
Subject Re: QA Test debugging
Date Mon, 25 Feb 2013 13:33:10 GMT
On 25 February 2013 12:40, Peter Firmstone <jini@zeus.net.au> 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)
>
>
>

Mime
View raw message