You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@nifi.apache.org by "Oleg Zhurakousky (JIRA)" <ji...@apache.org> on 2015/10/29 19:08:27 UTC
[jira] [Comment Edited] (NIFI-869) The logger used by processors,
controller services, etc. produces odd message when logging exception
[ https://issues.apache.org/jira/browse/NIFI-869?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14980932#comment-14980932 ]
Oleg Zhurakousky edited comment on NIFI-869 at 10/29/15 6:08 PM:
-----------------------------------------------------------------
This is actually an issue with how Logback formats messages
Here is the example of difference in behavior between Logback and Log4J:
{code}
LOG.error("Hello {} and {}", 3456, new RuntimeException("foo"));
{code}
Log4J will print:
{code}
Hello 3456 and java.lang.RuntimeException: foo
{code}
Logback will print:
{code}
Hello 3456 and {}
java.lang.RuntimeException: foo
at org.apache.nifi.controller.scheduling.StandardProcessScheduler$6.run(StandardProcessScheduler.java:659) [classes/:na]
. . .
{code}
So, the logback will print the stack trace but will not do ancor replace.
So unfortunately we just need to be aware of this and pass non-Throwable if we want ancor to be replaced by the value.
The fix is simple; In StandardProcessScheduler replace
{code}
componentLog.error("Failed to invoke @OnEnabled method due to {}", cause);
{code}
. . . with
{code}
componentLog.error("failed to invoke @OnEnabled method due to {}", new Object[]{cause.toString()});
{code}
Wil submit PR shortly
was (Author: ozhurakousky):
This is actually an issue with how Logback formats messages
Here is the example of difference in behavior between Logback and Log4J:
{code}
LOG.error("Hello {} and {}", 3456, new RuntimeException("foo"));
{code}
Log4J will print:
{code}
Hello 3456 and java.lang.RuntimeException: foo
{code}
Logback will print:
{code}
Hello 3456 and {}
java.lang.RuntimeException: foo
at org.apache.nifi.controller.scheduling.StandardProcessScheduler$6.run(StandardProcessScheduler.java:659) [classes/:na]
. . .
{code}
So, the logback will print the stack trace but will not do ancor replace.
So unfortunately we just need to be aware of this and pass non-Throwable if we want ancor to be replaced by the value.
The fix is simple; In StandardProcessScheduler replace
{code}
componentLog.error("Failed to invoke @OnEnabled method due to {}", cause);
{code}
. . . with
{code}
componentLog.error("failed to invoke @OnEnabled method due to {}", new Object[]{cause.toString()});
{code}
> The logger used by processors, controller services, etc. produces odd message when logging exception
> ----------------------------------------------------------------------------------------------------
>
> Key: NIFI-869
> URL: https://issues.apache.org/jira/browse/NIFI-869
> Project: Apache NiFi
> Issue Type: Bug
> Reporter: Mark Payne
> Assignee: Oleg Zhurakousky
> Priority: Minor
> Fix For: 0.4.0
>
>
> An easy way to reproduce this is to add a DBCPConnectionPool controller service and use an invalid driver class name and attempt to enable the service. You'll see a log message that indicates "Failed to invoke @OnEnabled method due to {}" as seen below. The "due to {}" part is weird and should either log a toString of the Exception or should not include the {}
> 2015-08-18 23:01:57,200 ERROR [pool-27-thread-1] o.a.n.c.s.StandardControllerServiceNode [DBCPConnectionPool[id=a2639013-c688-4080-8bbc-3a604122ae15]] Failed to invoke @OnEnabled method due to {}
> org.apache.nifi.reporting.InitializationException: org.apache.commons.dbcp.SQLNestedException: Cannot load JDBC driver class 'com.bogusville.net'
> at org.apache.nifi.dbcp.DBCPConnectionPool.onConfigured(DBCPConnectionPool.java:175) ~[nifi-dbcp-service-0.3.0-SNAPSHOT.jar:0.3.0-SNAPSHOT]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_45]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_45]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
> at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:102) ~[na:na]
> at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotation(ReflectionUtils.java:47) ~[na:na]
> at org.apache.nifi.controller.scheduling.StandardProcessScheduler$6.run(StandardProcessScheduler.java:644) ~[na:na]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_45]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_45]
> at java.lang.Thread.run(Thread.java:745) [na:1.8.0_45]
> Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot load JDBC driver class 'com.bogusville.net'
> at org.apache.commons.dbcp.BasicDataSource.createConnectionFactory(BasicDataSource.java:1429) ~[commons-dbcp-1.4.jar:1.4]
> at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1371) ~[commons-dbcp-1.4.jar:1.4]
> at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044) ~[commons-dbcp-1.4.jar:1.4]
> at org.apache.nifi.dbcp.DBCPConnectionPool.onConfigured(DBCPConnectionPool.java:169) ~[nifi-dbcp-service-0.3.0-SNAPSHOT.jar:0.3.0-SNAPSHOT]
> ... 10 common frames omitted
> Caused by: java.lang.ClassNotFoundException: com.bogusville.net
> at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[na:1.8.0_45]
> at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[na:1.8.0_45]
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)