{"action":"created","issue":{"url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/25","labels_url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/25/labels{/name}","comments_url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/25/comments","events_url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/25/events","html_url":"https://github.com/killbill/killbill-plugin-framework-ruby/issues/25","id":58564950,"number":25,"title":"logging throwables with JRuby stack-traces does not work","user":{"login":"kares","id":45967,"avatar_url":"https://avatars.githubusercontent.com/u/45967?v=3","gravatar_id":"","url":"https://api.github.com/users/kares","html_url":"https://github.com/kares","followers_url":"https://api.github.com/users/kares/followers","following_url":"https://api.github.com/users/kares/following{/other_user}","gists_url":"https://api.github.com/users/kares/gists{/gist_id}","starred_url":"https://api.github.com/users/kares/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kares/subscriptions","organizations_url":"https://api.github.com/users/kares/orgs","repos_url":"https://api.github.com/users/kares/repos","events_url":"https://api.github.com/users/kares/events{/privacy}","received_events_url":"https://api.github.com/users/kares/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":10,"created_at":"2015-02-23T10:00:19Z","updated_at":"2015-03-12T11:02:06Z","closed_at":null,"body":"related to \"occasional\" traces seen as : \r\n```\r\njava.lang.IllegalArgumentException: name\r\nat sun.misc.URLClassPath$Loader.getResource(URLClassPath.java:529)\r\nat sun.misc.URLClassPath.getResource(URLClassPath.java:199)\r\nat java.net.URLClassLoader$1.run(URLClassLoader.java:358)\r\nat java.net.URLClassLoader$1.run(URLClassLoader.java:355)\r\nat java.security.AccessController.doPrivileged(Native Method)\r\nat java.net.URLClassLoader.findClass(URLClassLoader.java:354)\r\nat org.apache.catalina.loader.WebappClassLoader.findClass(WebappClassLoader.java:1225)\r\nat org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1688)\r\nat org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1569)\r\nat org.apache.felix.framework.BundleWiringImpl.doImplicitBootDelegation(BundleWiringImpl.java:1763)\r\nat org.apache.felix.framework.BundleWiringImpl.searchDynamicImports(BundleWiringImpl.java:1698)\r\nat org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1534)\r\nat org.apache.felix.framework.BundleWiringImpl.access$400(BundleWiringImpl.java:77)\r\nat org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1993)\r\nat java.lang.ClassLoader.loadClass(ClassLoader.java:358)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:207)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:232)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:138)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.populateUncommonFrames(PackagingDataCalculator.java:113)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:105)\r\nat ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:57)\r\nat ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147)\r\nat ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:124)\r\nat ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)\r\nat ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)\r\nat ch.qos.logback.classic.Logger.warn(Logger.java:713) \r\n```\r\nsome full traces at https://gist.github.com/anonymous/aea6b5a96e05bd2531dc\r\n\r\nthis seems to be one of the factors for unpredictable behaviour as well as likely a major source of \"unreliability\" for doing any performance optimizations that involve integrating with JRuby ...\r\n\r\nwhenever a `Throwable` is processed by logback it will try to analyse classes involved in stack-trace elements thus trying to load each class based on it's name, whenever a JRuby internal JIT-ed class name is there it will lead to an exception such as above - under logback effectively loosing the original exception.\r\n\r\non logback this seems to end up in a considerable slow-down (that only gets triggered after JRuby warms-up) https://gist.github.com/kares/e914ce2afae287a6059d#file-logback_with_yjp_agent-out\r\n\r\nsimilar behaviour happens with log4j2 as it tries to analyze the stack-trace elements: https://gist.github.com/kares/e914ce2afae287a6059d#file-log4j2-log\r\n\r\n\r\n**WiP**  but in case you have any feedback please let me know as at this point my paranoia is still growing :)"},"comment":{"url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/comments/78459974","html_url":"https://github.com/killbill/killbill-plugin-framework-ruby/issues/25#issuecomment-78459974","issue_url":"https://api.github.com/repos/killbill/killbill-plugin-framework-ruby/issues/25","id":78459974,"user":{"login":"kares","id":45967,"avatar_url":"https://avatars.githubusercontent.com/u/45967?v=3","gravatar_id":"","url":"https://api.github.com/users/kares","html_url":"https://github.com/kares","followers_url":"https://api.github.com/users/kares/followers","following_url":"https://api.github.com/users/kares/following{/other_user}","gists_url":"https://api.github.com/users/kares/gists{/gist_id}","starred_url":"https://api.github.com/users/kares/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kares/subscriptions","organizations_url":"https://api.github.com/users/kares/orgs","repos_url":"https://api.github.com/users/kares/repos","events_url":"https://api.github.com/users/kares/events{/privacy}","received_events_url":"https://api.github.com/users/kares/received_events","type":"User","site_admin":false},"created_at":"2015-03-12T11:02:06Z","updated_at":"2015-03-12T11:02:06Z","body":"najs logback pimps, thanks @pierre ... but keep in mind async-appenders versus \"true\" async-loggers are quite different ... the later employed by log4j2 (as fas as I understand) gets out of the way as fast as possible thus even heavy logging has little impact on business logic flow. the drawback for KB might be that for audit purposes it's simply not a \"good\" choice due its async-queue nature (just a gut guess of mine)."}}