[
https://issues.apache.org/jira/browse/FLUME-2186?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13847249#comment-13847249
]
Ashish Paliwal commented on FLUME-2186:
---------------------------------------
It's not flaky, this is how it shall work.
We start the source after sending message 3, when msg 4 append is called, the
rpcClient is null, and we initiate reconnect() and return in next line. So when
next append comes, it will be logged. So in this case, msg initiated
reconnect() and message 5 got logged.
Didn't changed the code to keep it simple. Alternative was to check for
rpcClient to be in activeState() after activateOptions(). If true, don't return.
The result shall always be same. I didn't wanted to add to many checks.
> Log4jAppender throws a NPE when Flume is turned off
> ---------------------------------------------------
>
> Key: FLUME-2186
> URL: https://issues.apache.org/jira/browse/FLUME-2186
> Project: Flume
> Issue Type: Bug
> Components: Client SDK
> Affects Versions: v1.4.0
> Environment: Java 1.6.0_26
> Flume 1.4.0
> Reporter: X-Tough
> Assignee: Ashish Paliwal
> Attachments: FLUME-2186-0.patch, FLUME-2186-1.patch,
> FLUME-2186-2.patch, FLUME-2186-3.patch
>
>
> When Log4jAppender loses its connection to Flume, it will meet a NPE.
> My test Flume agent:
> {quote}
> a1.sources = r1
> a1.sinks = k1
> a1.channels = c1
> a1.sources.r1.type = avro
> a1.sources.r1.bind = 0.0.0.0
> a1.sources.r1.port = 4141
> a1.sinks.k1.type = null
> a1.channels.c1.type = memory
> a1.sources.r1.channels = c1
> a1.sinks.k1.channel = c1
> {quote}
> My Log4J property file for the Flume appender:
> {quote}
> log4j.appender.FLUME = org.apache.flume.clients.log4jappender.Log4jAppender
> log4j.appender.FLUME.Hostname = localhost
> log4j.appender.FLUME.Port = 4141
> log4j.appender.FLUME.UnsafeMode = true
> {quote}
> For the issue, I made a simple JUnit:
> {code}
> public class FlumeLog4jAppenderTest {
> private static final org.apache.log4j.Logger LOGGER =
> org.apache.log4j.Logger.getLogger(FlumeLog4jAppenderTest.class);
> @Test
> public void theMillionLog() {
> int MAX = 1000000;
> for (int i = 0; i < MAX; i++) {
> LOGGER.info(String.format("This is a dummy log, %1$d/%2$d", i, MAX));
> }
> }
> }
> {code}
> --
> Scenario:
> 1) Run Flume
> 2) Run the Java app
> 3) Turn Flume off
> The Java app will log:
> {code}
> ...
> [INFO] 13:22:18,246
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 301/1000000
> [INFO] 13:22:18,251
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 302/1000000
> [INFO] 13:22:18,254
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 303/1000000
> [INFO] 13:22:18,257
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 304/1000000
> [INFO] 13:22:18,261
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 305/1000000
> [INFO] 13:22:18,265
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 306/1000000
> [INFO] 13:22:18,269
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 307/1000000
> [INFO] 13:22:18,274
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 308/1000000
> [INFO] 13:22:18,281
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 309/1000000
> [INFO] 13:22:18,286
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 310/1000000
> log4j:ERROR Flume append() failed.
> [INFO] 13:22:18,291
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> This is a dummy log, 311/1000000
> log4j:ERROR RPC client creation failed! NettyAvroRpcClient { host: localhost,
> port: 4141 }: RPC connection error
> {code}
> ... and will stop.
> Here is the stacktrace (JUnit runned in Eclipse):
> {code}
> FlumeLog4jAppenderTest
> com.test.FlumeLog4jAppenderTest
> theMillionLog(com.test.FlumeLog4jAppenderTest)
> java.lang.NullPointerException
> at
> org.apache.flume.clients.log4jappender.Log4jAppender.append(Log4jAppender.java:163)
> at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
> at
> org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
> at org.apache.log4j.Category.callAppenders(Category.java:206)
> at org.apache.log4j.Category.forcedLog(Category.java:391)
> at org.apache.log4j.Category.info(Category.java:666)
> at
> com.test.FlumeLog4jAppenderTest.theMillionLog(FlumeLog4jAppenderTest.java:15)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
> at
> org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
> at
> org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
> at
> org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
> at
> org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
> at
> org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
> at
> org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
> {code}
> --
> Explanation:
> - Once Flume is turned off, Log4J fails to append:
> https://git-wip-us.apache.org/repos/asf?p=flume.git;a=blob;f=flume-ng-clients/flume-ng-log4jappender/src/main/java/org/apache/flume/clients/log4jappender/Log4jAppender.java;h=b07b189701d30e1789a8543b020b53aca1acee34;hb=756924e96ace470289472a3bdb4d87e273ca74ef#l163
> And logs the following error:
> bq. log4j:ERROR Flume append() failed.
> - At the next call of append, it tries to reconnect
> (https://git-wip-us.apache.org/repos/asf?p=flume.git;a=blob;f=flume-ng-clients/flume-ng-log4jappender/src/main/java/org/apache/flume/clients/log4jappender/Log4jAppender.java;h=b07b189701d30e1789a8543b020b53aca1acee34;hb=756924e96ace470289472a3bdb4d87e273ca74ef#l131)
> without success:
> bq. log4j:ERROR RPC client creation failed! NettyAvroRpcClient { host:
> localhost, port: 4141 }: RPC connection error
> (This logging error is done here:
> https://git-wip-us.apache.org/repos/asf?p=flume.git;a=blob;f=flume-ng-clients/flume-ng-log4jappender/src/main/java/org/apache/flume/clients/log4jappender/Log4jAppender.java;h=b07b189701d30e1789a8543b020b53aca1acee34;hb=756924e96ace470289472a3bdb4d87e273ca74ef#l313)
> Note: reconnect() is just calling close() (close rpcClient then set rpcClient
> to null) and activateOptions() (reconfigure the rpcClient)
> - BUT, since rpcClient has been set to null by the close() method, and
> activateOptions() failed, rpcClient remains null. Then
> rpcClient.append(event) will throw a NPE.
--
This message was sent by Atlassian JIRA
(v6.1.4#6159)
