river-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gregg Wonderly <gregg...@gmail.com>
Subject Re: QA Test debugging
Date Mon, 25 Feb 2013 14:38:38 GMT
What is the issue number for you issue Peter?

Gregg

On Feb 25, 2013, at 7:33 AM, Dan Creswell <dan.creswell@gmail.com> wrote:

> 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