Bug 745866 (EDG-45)

Summary: Possible netty logging config problem
Product: [JBoss] JBoss Data Grid 5 Reporter: Michal Linhard <mlinhard>
Component: InfinispanAssignee: Default User <jbpapp-maint>
Status: CLOSED NEXTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: high    
Version: EAP 5.1.0 EDG TPCC: galder.zamarreno, mlinhard, nobody
Target Milestone: ---   
Target Release: EAP 5.1.0 EDG TP   
Hardware: Unspecified   
OS: Unspecified   
URL: http://jira.jboss.org/jira/browse/EDG-45
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-03-28 08:25:42 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Michal Linhard 2011-03-16 13:59:34 UTC
project_key: EDG

infinispan 4.2.1.CR4
a netty logging problem occured in a client stress test:

{code}
[JBoss] 09:26:55,244 ERROR [STDERR] Exception in thread "pool-7-thread-1" 
[JBoss] 09:26:55,244 ERROR [STDERR] java.lang.InternalError
[JBoss] 09:26:55,244 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:755)
[JBoss] 09:26:55,244 ERROR [STDERR] 	at sun.misc.URLClassPath.getResource(URLClassPath.java:169)
[JBoss] 09:26:55,244 ERROR [STDERR] 	at java.net.URLClassLoader$1.run(URLClassLoader.java:194)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.security.AccessController.doPrivileged(Native Method)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at sun.misc.Launcher$ExtClassLoader.findClass(Launcher.java:229)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:296)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle$RBClassLoader.loadClass(ResourceBundle.java:435)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2289)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1364)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle.findBundle(ResourceBundle.java:1328)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle.findBundle(ResourceBundle.java:1282)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1224)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.ResourceBundle.getBundle(ResourceBundle.java:705)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.Level.getLocalizedName(Level.java:223)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.SimpleFormatter.format(SimpleFormatter.java:64)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.StreamHandler.publish(StreamHandler.java:179)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:88)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.Logger.log(Logger.java:481)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.Logger.doLog(Logger.java:503)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.logging.Logger.logp(Logger.java:703)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at org.jboss.netty.logging.JdkLogger.warn(JdkLogger.java:86)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at org.jboss.netty.logging.InternalLoggerFactory$1.warn(InternalLoggerFactory.java:133)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink$Boss.run(NioServerSocketPipelineSink.java:260)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[JBoss] 09:26:55,245 ERROR [STDERR] 	at java.lang.Thread.run(Thread.java:662)
[JBoss] 09:26:55,246 ERROR [STDERR] Caused by: java.util.zip.ZipException: error in opening zip file
[JBoss] 09:26:55,246 ERROR [STDERR] 	at java.util.zip.ZipFile.open(Native Method)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at java.util.zip.ZipFile.&lt;init>(ZipFile.java:127)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at java.util.jar.JarFile.&lt;init>(JarFile.java:135)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at java.util.jar.JarFile.&lt;init>(JarFile.java:72)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader.getJarFile(URLClassPath.java:646)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader.access$600(URLClassPath.java:540)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader$1.run(URLClassPath.java:607)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at java.security.AccessController.doPrivileged(Native Method)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader.ensureOpen(URLClassPath.java:599)
[JBoss] 09:26:55,246 ERROR [STDERR] 	at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:753)
[JBoss] 09:26:55,246 ERROR [STDERR] 	... 31 more
{code}

(whole log: http://hudson.qa.jboss.com/hudson/view/EDG/job/edg-51x-stress-client-size10-hotrod/3/console-perf18/consoleText)

Comment 1 Michal Linhard 2011-03-16 14:06:26 UTC
also here, same run different cluster node: http://hudson.qa.jboss.com/hudson/view/EDG/job/edg-51x-stress-client-size10-hotrod/3/console-perf19/consoleText

Comment 2 Galder ZamarreƱo 2011-03-22 10:02:26 UTC
Hmmmm, it appears that Netty needs to log an exception and so it's using its own logger which by default is using the JDK logger. It appears that Netty's logger can only be modified programmatically - http://docs.jboss.org/netty/3.1/api/org/jboss/netty/logging/InternalLoggerFactory.html - I can probably get a JIRA sorted so that if the server uses a Log4J logger, we force Netty to do the same, i.e. call

{code}InternalLoggerFactory.setDefaultFactory(new Log4JLoggerFactory());{code}

The error appears to come from the JDK simple formatter trying to find the "sun.util.logging.resources.logging" bundle. I've no idea where it's trying to locate it that it's causing it issues.

The underlying issue is that Netty server side failed to accept a connection. I don't know why though cos it fails to log.

Comment 3 Galder ZamarreƱo 2011-03-22 10:06:04 UTC
Link: Added: This issue depends ISPN-991