I'd definitely like to see more automated checking of error and log messages,
although I was envisioning doing that at the source code or class file level.
I'm a bit worried that, even if we clean up all the known problems, there's
enough uncertainty in the behavior of quicklook that we'll expose a lot of
errors that aren't caused by what any person is changing.
Here's what I think we should do...
We should clean up all the errors currently found by this test.
We should set up a couple of Hudson jobs that run quicklook on different
platforms and *fail* if this test finds any errors. (Maybe an environment
variable could control whether these errors cause failure or not?) Let's run
those jobs for a few weeks and see what
kind of failures we see. If we only ever see real failures, we should make this
be the default behavior.
Does that seem reasonable?
Koper, Dies wrote on 04/25/2011 08:39 PM:
>
> Hi Byron, Bill,
>
> I’ve created GLASSFISH-16450 for the issue with the first message.
>
> ØIs there a point to doing this in the Quick Look Tests? I never see it
> change. It seems to be ignored. Or am I missing something? E.g. does it
> send badgering emails to the authors of code that have logging problems?
>
> It seems you are right.
>
> As it checks messages in server.log, it needs to be run after GF has been used
> at runtime.
>
> Running it in a svn commit hook is not an option.
>
> So I thought it would be good to have it run automatically at the end of the
> Quicklook tests and cause it to fail the tests, thereby failing the build,
> which in turn would cause authors who introduced the issues to be badgered by
> hudson e-mails.
>
> I was hoping once we had that in place, we could have something similar done
> for CTS, as that would catch many more broken messages.
>
> Unfortunately Naman and I couldn’t get Ming’s permission to include the change
> to make it fail the QL tests.
>
> Clearly, without having a way of enforcement new broken messages will be
> introduced.
>
> Bill, just like raising the bar on Findbugs, can’t we raise the bar on messages?
>
> All we need is someone who can convince Ming, or come up with another solution.
>
> FYI, this is how I envisioned the target would work:
>
> 1.Before introducing the change to fail the QL, we’ll need to address the
> current issues.
>
> 2.As soon as we have 0 message issues, make the change to let it fail the QL
> tests.
>
> 3.Next time a committer makes a change that causes the task to fail due to:
>
> a.a message with logging problems
>
> b.a message that is excluded from the requirement to have a message ID
>
> c.logging a stacktrace
>
> d.adding a new VM option or other string mistaken to be a message
>
> this person would have to fix it by e.g.:
>
> a.fixing the message or stacktrace
>
> b.adding the string to the exclude list
>
> Depending on how it goes we could reconsider for a next release to reduce the
> types of messages that do not get assigned message IDs.
>
> Regards,
>
> Dies
>
> *From:*Byron Nevins [mailto:byron.nevins_at_oracle.com]
> *Sent:* Tuesday, 26 April 2011 04:48
> *To:* Naman Mehta; admin_at_glassfish.java.net
> *Subject:* QL logging errors
>
> Is there a point to doing this in the Quick Look Tests? I never see it
> change. It seems to be ignored. Or am I missing something? E.g. does it
> send badgering emails to the authors of code that have logging problems?
>
> check-logged-messages:
> [echo] Checking messages in:
> [echo] c:\Hudson\BUILD_AREA\workspace\gf-trunk-build-windows\gfv3-gp\glassfish3\glassfish\domains\domain1\logs\server.log
> [echo]
> [copy] Copying 1 file to C:\Hudson\BUILD_AREA\workspace\gf-trunk-build-windows\v3\tests\test-output
> [echo]
> [echo] * Message keys logged instead of message:
> [echo] (none)
> [echo]
> [echo] * Parameter marker not substituted with value:
> [echo] [#|2011-04-25T12:51:19.015-0500|INFO|glassfish3.2|javax.enterprise.resource.jms.com.sun.enterprise.connectors.jms.system|_ThreadID=48;_ThreadName=Thread-1;|end point determine destionation name, Res name: javax.jms.Queue, JNDI name: MessageBean descriptor name : {3}|#]
> [echo]
> [echo]
> [echo] * Bundle not found:
> [echo] (none)
> [echo]
> [echo] * Messages not found in message bundle:
> [echo] (none)
> [echo]
> [echo] * No message:
> [echo] (none)
> [echo]
> [echo] * Messages with common typo's ('occured' with one 'r', 'dont' missing apostrophe, etc.):
> [echo] (none)
> [echo]
> [echo] * Messages with double apostrophes:
> [echo] (none)
> [echo]
> [echo] * Messages with no proper message Id:
> [echo] -Dgosh.args=--nointeractive
> [echo] -Dorg.glassfish.additionalOSGiBundlesToStart=org.apache.felix.shell,org.apache.felix.gogo.runtime,org.apache.felix.gogo.shell,org.apache.felix.gogo.command,org.apache.felix.shell.remote,org.apache.felix.fileinstall
> [echo] [#|2011-04-25T12:40:07.359-0500|INFO|glassfish3.2|javax.enterprise.system.core.com.sun.enterprise.v3.admin.adapter|_ThreadID=20;_ThreadName=Thread-1;|The Admin Console is starting. Please wait.|#]
> [echo] -Dgosh.args=--nointeractive
> [echo] -Dorg.glassfish.additionalOSGiBundlesToStart=org.apache.felix.shell,org.apache.felix.gogo.runtime,org.apache.felix.gogo.shell,org.apache.felix.gogo.command,org.apache.felix.shell.remote,org.apache.felix.fileinstall
> [echo] -Djava.security.manager
> [echo] Apr 25, 2011 12:40:21 PM null
> [echo] -Dgosh.args=--nointeractive
> [echo] -Dorg.glassfish.additionalOSGiBundlesToStart=org.apache.felix.shell,org.apache.felix.gogo.runtime,org.apache.felix.gogo.shell,org.apache.felix.gogo.command,org.apache.felix.shell.remote,org.apache.felix.fileinstall
> [echo] -Djava.security.manager
> [echo] Apr 25, 2011 12:40:53 PM null
> [echo] [#|2011-04-25T12:43:49.687-0500|WARNING|glassfish3.2|org.jboss.interceptor.reader.InterceptorMetadataUtils|_ThreadID=21;_ThreadName=Thread-1;|Method init defined on class numberguess.InterceptorB will not be used for interception, since it is not defined according to the specification. It is annotated with @javax.annotation.PostConstruct, but is defined on the target class and does not have 0 arguments|#]
> [echo] [#|2011-04-25T12:43:49.687-0500|WARNING|glassfish3.2|org.jboss.interceptor.reader.InterceptorMetadataUtils|_ThreadID=21;_ThreadName=Thread-1;|Method destroy defined on class numberguess.InterceptorB will not be used for interception, since it is not defined according to the specification. It is annotated with @javax.annotation.PreDestroy, but is defined on the target class and does not have 0 arguments|#]
> [echo] [#|2011-04-25T12:45:27.484-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=17;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(null)- permission((java.lang.RuntimePermission createClassLoader))|#]
> [echo] [#|2011-04-25T12:46:55.968-0500|INFO|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=22;_ThreadName=Thread-1;|Initialized AMXStartupServiceNew in 12 ms, registered as amx-support:type=amx-loader,name=startup|#]
> [echo] [#|2011-04-25T12:46:56.062-0500|INFO|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=23;_ThreadName=Thread-1;|In AMXConfigLoader : loader == null|#]
> [echo] [#|2011-04-25T12:46:56.546-0500|INFO|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=23;_ThreadName=Thread-1;|AMX config read, domain config registered as amx:pp=/,type=domain|#]
> [echo] [#|2011-04-25T12:46:57.000-0500|INFO|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=24;_ThreadName=Thread-1;|J2EEDomain registered at amx:pp=/,type=J2EEDomain,j2eeType=J2EEDomain,name=amx|#]
> [echo] [#|2011-04-25T12:46:57.000-0500|INFO|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=22;_ThreadName=Thread-1;|AMXStartupServiceNew: AMX ready for use, DomainRoot = amx:pp=,type=domain-root|#]
> [echo] [#|2011-04-25T12:47:16.500-0500|WARNING|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=26;_ThreadName=Thread-1;|Non-singleton ConfigBean com.sun.enterprise.config.serverbeans.Config has empty key value (name), supplying MISSING_NAME-1|#]
> [echo] [#|2011-04-25T12:48:11.515-0500|WARNING|glassfish3.2|null|_ThreadID=19;_ThreadName=Thread-1;|config.getHttpService() null for config 'AMXConfigProxyTests.TEST'|#]
> [echo] [#|2011-04-25T12:48:11.640-0500|INFO|glassfish3.2|javax.enterprise.system.core.com.sun.enterprise.v3.admin.adapter|_ThreadID=32;_ThreadName=Thread-1;|The Admin Console is starting. Please wait.|#]
> [echo] [#|2011-04-25T12:50:04.765-0500|INFO|glassfish3.2|org.glassfish.admingui|_ThreadID=21;_ThreadName=Thread-1;|Admin Console: Initializing Session Attributes...|#]
> [echo] [#|2011-04-25T12:50:32.000-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=34;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(jdbcusertx/jdbcusertx)- permission((java.lang.RuntimePermission getenv.AS_DEBUG))|#]
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 104 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 106 more
> [echo] [#|2011-04-25T12:50:33.296-0500|SEVERE|glassfish3.2|javax.enterprise.system.tools.monitor.org.glassfish.admin.monitor|_ThreadID=37;_ThreadName=Thread-1;|MNTG0205:Gmbal registration failed
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 104 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 106 more
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 128 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 130 more
> [echo] [#|2011-04-25T12:50:33.890-0500|SEVERE|glassfish3.2|javax.enterprise.system.tools.monitor.org.glassfish.admin.monitor|_ThreadID=35;_ThreadName=Thread-1;|MNTG0205:Gmbal registration failed
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 128 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 130 more
> [echo] [#|2011-04-25T12:50:36.046-0500|WARNING|glassfish3.2|javax.enterprise.system.container.web.com.sun.web.security|_ThreadID=38;_ThreadName=Thread-1;|Exception
> [echo] com.sun.enterprise.security.auth.login.common.LoginException: Login failed: Failed file login for j2ee.
> [echo] Caused by: javax.security.auth.login.LoginException: Failed file login for j2ee.
> [echo] ... 29 more
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 110 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 112 more
> [echo] [#|2011-04-25T12:50:42.578-0500|SEVERE|glassfish3.2|javax.enterprise.system.tools.monitor.org.glassfish.admin.monitor|_ThreadID=35;_ThreadName=Thread-1;|MNTG0205:Gmbal registration failed
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 110 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 112 more
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 92 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 94 more
> [echo] [#|2011-04-25T12:50:43.625-0500|SEVERE|glassfish3.2|javax.enterprise.system.tools.monitor.org.glassfish.admin.monitor|_ThreadID=37;_ThreadName=Thread-1;|MNTG0205:Gmbal registration failed
> [echo] Caused by: java.lang.RuntimeException: Can't add NotificationListener
> [echo] ... 92 more
> [echo] Caused by: java.security.AccessControlException: access denied (javax.management.MBeanPermission javax.management.MBeanServerDelegate#-[JMImplementation:type=MBeanServerDelegate] addNotificationListener)
> [echo] ... 94 more
> [echo] [#|2011-04-25T12:50:43.734-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=37;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(RosterApp/RosterAppEJB_jar)- permission((org.osgi.framework.AdminPermission (id=154) resolve,resource))|#]
> [echo] [#|2011-04-25T12:50:44.171-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=37;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(RosterApp/RosterAppEJB_jar)- permission((org.osgi.framework.AdminPermission (id=154) resolve,resource))|#]
> [echo] [#|2011-04-25T12:50:44.750-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=37;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(RosterApp/RosterAppEJB_jar)- permission((org.osgi.framework.AdminPermission (id=154) resolve,resource))|#]
> [echo] [#|2011-04-25T12:50:49.156-0500|INFO|glassfish3.2|javax.enterprise.resource.jms.com.sun.enterprise.connectors.jms.system|_ThreadID=47;_ThreadName=Thread-1;|ADDRESSLIST in setJmsServiceProvider: mq://localhost:7676/|#]
> [echo] [#|2011-04-25T12:51:19.015-0500|INFO|glassfish3.2|javax.enterprise.resource.jms.com.sun.enterprise.connectors.jms.system|_ThreadID=48;_ThreadName=Thread-1;|end point determine destionation name, Res name: javax.jms.Queue, JNDI name: MessageBean descriptor name : {3}|#]
> [echo] [#|2011-04-25T12:51:48.078-0500|WARNING|glassfish3.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=46;_ThreadName=Thread-1;|
> [echo] [#|2011-04-25T12:51:48.093-0500|WARNING|glassfish3.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=49;_ThreadName=Thread-1;|
> [echo] [#|2011-04-25T12:51:49.062-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=49;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(ejb-ejb30-hello-mdbApp/ejb-ejb30-hello-mdb-ejb_jar)- permission((java.lang.RuntimePermission getenv.AS_DEBUG))|#]
> [echo] [#|2011-04-25T12:51:55.953-0500|WARNING|glassfish3.2|javax.faces|_ThreadID=36;_ThreadName=Thread-1;|Multiple JSF Applications found on same ClassLoader. Unable to safely determine which FactoryManager instance to use. Defaulting to first match.|#]
> [echo] [#|2011-04-25T12:51:55.953-0500|WARNING|glassfish3.2|javax.faces|_ThreadID=36;_ThreadName=Thread-1;|Multiple JSF Applications found on same ClassLoader. Unable to safely determine which FactoryManager instance to use. Defaulting to first match.|#]
> [echo] [#|2011-04-25T12:52:04.484-0500|INFO|glassfish3.2|javax.enterprise.system.core.security|_ThreadID=34;_ThreadName=Thread-1;|JACC Policy Provider: Failed Permission Check, context(jaxbosgi/jaxbosgi)- permission((org.osgi.framework.AdminPermission (id=154) resolve,resource))|#]
> [echo] FAILURE_DETECT_TCP_RETRANSMIT_TIMEOUT(ms):10000
> [echo] START_TIMEOUT(ms):15000 WRITE_TIMEOUT(ms):10000
> [echo] /0.0.0.0;
> [echo] multicast address:/228.9.28.49 timeToLive=4|#]
> [echo] [#|2011-04-25T12:54:10.453-0500|WARNING|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=66;_ThreadName=Thread-1;|Can't unregister MBean: amx:pp=/domain/clusters/cluster[eec1],type=application-ref,name=helloworld
> [echo] javax.management.InstanceNotFoundException: amx:pp=/J2EEDomain/J2EEServer[eein1-with-a-very-very-very-long-name],type=WebModule,name=helloworld,j2eeType=WebModule,J2EEServer=eein1-with-a-very-very-very-long-name,J2EEApplication=null
> [echo] [#|2011-04-25T12:54:10.453-0500|WARNING|glassfish3.2|javax.enterprise.system.tools.admin.org.glassfish.admin.amx.impl.util|_ThreadID=66;_ThreadName=Thread-1;|Can't unregister MBean: amx:pp=/domain/clusters/cluster[eec1],type=application-ref,name=helloworld
> [echo] javax.management.InstanceNotFoundException: amx:pp=/J2EEDomain/J2EEServer[eein2],type=WebModule,name=helloworld,j2eeType=WebModule,J2EEServer=eein2,J2EEApplication=null
> [echo] [#|2011-04-25T12:54:22.906-0500|SEVERE|glassfish3.2|null|_ThreadID=70;_ThreadName=Thread-1;|Config Listener notification got interrupted
> [echo] java.util.concurrent.ExecutionException: java.lang.NullPointerException
> [echo] Caused by: java.lang.NullPointerException
> [echo] ... 5 more
> [echo] [#|2011-04-25T12:54:31.984-0500|SEVERE|glassfish3.2|null|_ThreadID=66;_ThreadName=Thread-1;|Config Listener notification got interrupted
> [echo] java.util.concurrent.ExecutionException: java.lang.NullPointerException
> [echo] Caused by: java.lang.NullPointerException
> [echo] ... 5 more
> [echo] [#|2011-04-25T12:54:50.640-0500|WARNING|glassfish3.2|javax.management.remote.misc|_ThreadID=78;_ThreadName=Thread-1;|Failed to restart: java.io.IOException: Failed to get a RMI stub: javax.naming.ServiceUnavailableException [Root exception is java.rmi.ConnectException: Connection refused to host: localhost; nested exception is:
> [echo] java.net.ConnectException: Connection refused: connect]|#]
> [echo] [#|2011-04-25T12:54:51.625-0500|WARNING|glassfish3.2|javax.management.remote.rmi|_ThreadID=78;_ThreadName=Thread-1;|Failed to call the method close():java.rmi.ConnectException: Connection refused to host: 10.232.128.191; nested exception is:
> [echo] java.net.ConnectException: Connection refused: connect|#]
> [echo] [#|2011-04-25T12:54:51.625-0500|WARNING|glassfish3.2|javax.management.remote.misc|_ThreadID=78;_ThreadName=Thread-1;|Failed to check connection: java.net.ConnectException: Connection refused: connect|#]
> [echo] [#|2011-04-25T12:54:51.625-0500|WARNING|glassfish3.2|javax.management.remote.misc|_ThreadID=78;_ThreadName=Thread-1;|stopping|#]
> [echo]
> [echo]
>
> pass:
>
> fail:
> [echo] ======================================================================
> [echo] FAILED: check-logged-messages
> [echo] Issues found in one or more messages (see results above).
> [echo] Please address them, or if the message should be left as-is,
> [echo] add it to the exclusion list with details why it should be excluded:
> [echo] C:\Hudson\BUILD_AREA\workspace\gf-trunk-build-windows\v3\tests\quicklook\gfproject\log_msg_excl.txt
> [echo] ======================================================================
>
>
> --
> Oracle <http://www.oracle.com/>
> Byron Nevins | Principal MTS
> Phone: +1 6503958992 <tel:+1%206503958992>
>
> Green Oracle <http://www.oracle.com/commitment>Oracle is committed to
> developing practices and products that help protect the environment
>