You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@knox.apache.org by "ASF GitHub Bot (Jira)" <ji...@apache.org> on 2021/11/30 13:48:00 UTC
[jira] [Work logged] (KNOX-2694) StoreAndForwardAppenderTest.testAppender is intermittently failing with NPE
[ https://issues.apache.org/jira/browse/KNOX-2694?focusedWorklogId=688021&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-688021 ]
ASF GitHub Bot logged work on KNOX-2694:
----------------------------------------
Author: ASF GitHub Bot
Created on: 30/Nov/21 13:47
Start Date: 30/Nov/21 13:47
Worklog Time Spent: 10m
Work Description: zeroflag opened a new pull request #521:
URL: https://github.com/apache/knox/pull/521
## What changes were proposed in this pull request?
The NPE likely happens because of parallel test execution. If the target/audit file is written at the same time it might become corrupt.
```[INFO] Running org.apache.knox.gateway.audit.JdbmQueueTest
58592021-11-30 07:48:55,775 main ERROR Unable to invoke factory method in class org.apache.knox.gateway.audit.log4j.appender.JdbmStoreAndForwardAppender for element JdbmStoreAndForwardAppender: java.lang.NullPointerException java.lang.reflect.InvocationTargetException
5860 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
5861 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
5862 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
5863 at java.lang.reflect.Method.invoke(Method.java:498)
5864 at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
5865 at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1002)
5866 at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:942)
5867 at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:934)
5868 at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:552)
5869 at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:241)
5870 at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:288)
5871 at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:622)
5872 at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:695)
5873 at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:712)
5874 at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:267)
5875 at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
5876 at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
5877 at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
5878 at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:138)
5879 at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:45)
5880 at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:48)
5881 at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:30)
5882 at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:363)
5883 at jdbm.recman.BaseRecordManager.<clinit>(BaseRecordManager.java:94)
5884 at jdbm.recman.Provider.createRecordManager(Provider.java:83)
5885 at jdbm.RecordManagerFactory.createRecordManager(RecordManagerFactory.java:113)
5886 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.<init>(JdbmQueue.java:41)
5887 at org.apache.knox.gateway.audit.JdbmQueueTest.setUp(JdbmQueueTest.java:45)
5888 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
5889 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
5890 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
5891 at java.lang.reflect.Method.invoke(Method.java:498)
5892 at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
5893 at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
5894 at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
5895 at org.junit.internal.runners.statements.RunBefores.invokeMethod(RunBefores.java:33)
5896 at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
5897 at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
5898 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
5899 at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
5900 at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
5901 at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
5902 at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
5903 at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
5904 at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
5905 at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
5906 at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
5907 at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
5908 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
5909 at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
5910 at org.junit.runners.Suite.runChild(Suite.java:128)
5911 at org.junit.runners.Suite.runChild(Suite.java:27)
5912 at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
5913 at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
5914 at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
5915 at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
5916 at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
5917 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
5918 at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
5919 at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
5920 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
5921 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
5922 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
5923 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
5924 at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
5925 at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:383)
5926 at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:344)
5927 at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125)
5928 at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:417)
5929Caused by: java.lang.NullPointerException
5930 at jdbm.recman.BaseRecordManager.insert(BaseRecordManager.java:310)
5931 at jdbm.recman.BaseRecordManager.insert(BaseRecordManager.java:286)
5932 at jdbm.recman.BaseRecordManager.getNameDirectory(BaseRecordManager.java:575)
5933 at jdbm.recman.BaseRecordManager.getNamedObject(BaseRecordManager.java:508)
5934 at jdbm.recman.CacheRecordManager.getNamedObject(CacheRecordManager.java:378)
5935 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.findStat(JdbmQueue.java:124)
5936 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.<init>(JdbmQueue.java:42)
5937 at org.apache.knox.gateway.audit.log4j.appender.JdbmStoreAndForwardAppender.<init>(JdbmStoreAndForwardAppender.java:48)
```
JdbmStoreAndForwardAppender is only used from log4j2-test.xml.
## How was this patch tested?
```
$ mvn test
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@knox.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Issue Time Tracking
-------------------
Worklog Id: (was: 688021)
Remaining Estimate: 0h
Time Spent: 10m
> StoreAndForwardAppenderTest.testAppender is intermittently failing with NPE
> ---------------------------------------------------------------------------
>
> Key: KNOX-2694
> URL: https://issues.apache.org/jira/browse/KNOX-2694
> Project: Apache Knox
> Issue Type: Task
> Reporter: Attila Magyar
> Assignee: Attila Magyar
> Priority: Major
> Time Spent: 10m
> Remaining Estimate: 0h
>
> {code:java}
> [INFO] Running org.apache.knox.gateway.audit.JdbmQueueTest
> 58592021-11-30 07:48:55,775 main ERROR Unable to invoke factory method in class org.apache.knox.gateway.audit.log4j.appender.JdbmStoreAndForwardAppender for element JdbmStoreAndForwardAppender: java.lang.NullPointerException java.lang.reflect.InvocationTargetException
> 5860 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 5861 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 5862 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 5863 at java.lang.reflect.Method.invoke(Method.java:498)
> 5864 at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
> 5865 at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1002)
> 5866 at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:942)
> 5867 at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:934)
> 5868 at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:552)
> 5869 at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:241)
> 5870 at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:288)
> 5871 at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:622)
> 5872 at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:695)
> 5873 at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:712)
> 5874 at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:267)
> 5875 at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
> 5876 at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
> 5877 at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
> 5878 at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:138)
> 5879 at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:45)
> 5880 at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:48)
> 5881 at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:30)
> 5882 at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:363)
> 5883 at jdbm.recman.BaseRecordManager.<clinit>(BaseRecordManager.java:94)
> 5884 at jdbm.recman.Provider.createRecordManager(Provider.java:83)
> 5885 at jdbm.RecordManagerFactory.createRecordManager(RecordManagerFactory.java:113)
> 5886 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.<init>(JdbmQueue.java:41)
> 5887 at org.apache.knox.gateway.audit.JdbmQueueTest.setUp(JdbmQueueTest.java:45)
> 5888 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 5889 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 5890 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 5891 at java.lang.reflect.Method.invoke(Method.java:498)
> 5892 at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
> 5893 at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> 5894 at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
> 5895 at org.junit.internal.runners.statements.RunBefores.invokeMethod(RunBefores.java:33)
> 5896 at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
> 5897 at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> 5898 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
> 5899 at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
> 5900 at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
> 5901 at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
> 5902 at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
> 5903 at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
> 5904 at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
> 5905 at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
> 5906 at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
> 5907 at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
> 5908 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
> 5909 at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
> 5910 at org.junit.runners.Suite.runChild(Suite.java:128)
> 5911 at org.junit.runners.Suite.runChild(Suite.java:27)
> 5912 at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
> 5913 at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
> 5914 at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
> 5915 at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
> 5916 at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
> 5917 at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
> 5918 at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
> 5919 at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
> 5920 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
> 5921 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
> 5922 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
> 5923 at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
> 5924 at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
> 5925 at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:383)
> 5926 at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:344)
> 5927 at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125)
> 5928 at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:417)
> 5929Caused by: java.lang.NullPointerException
> 5930 at jdbm.recman.BaseRecordManager.insert(BaseRecordManager.java:310)
> 5931 at jdbm.recman.BaseRecordManager.insert(BaseRecordManager.java:286)
> 5932 at jdbm.recman.BaseRecordManager.getNameDirectory(BaseRecordManager.java:575)
> 5933 at jdbm.recman.BaseRecordManager.getNamedObject(BaseRecordManager.java:508)
> 5934 at jdbm.recman.CacheRecordManager.getNamedObject(CacheRecordManager.java:378)
> 5935 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.findStat(JdbmQueue.java:124)
> 5936 at org.apache.knox.gateway.audit.log4j.appender.JdbmQueue.<init>(JdbmQueue.java:42)
> 5937 at org.apache.knox.gateway.audit.log4j.appender.JdbmStoreAndForwardAppender.<init>(JdbmStoreAndForwardAppender.java:48)
> 5938 at org.apache.knox.gateway.audit.log4j.appender.JdbmStoreAndForwardAppender.createAppender(JdbmStoreAndForwardAppender.java:64)
> 5939 ... 69 more
> 5940
> 59412021-11-30 07:48:55,783 main ERROR Null object returned for JdbmStoreAndForwardAppender in Appenders.
> 59422021-11-30 07:48:55,794 main ERROR Unable to locate appender "audit-store" for logger config "audit.store"
> 5943Running org.apache.knox.gateway.audit.JdbmQueueTest#testConcurrentConsumer
> 5944Running org.apache.knox.gateway.audit.JdbmQueueTest#testConcurrentProcessor
> 5945Running org.apache.knox.gateway.audit.JdbmQueueTest#testSimple
> 5946[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.534 s - in org.apache.knox.gateway.audit.JdbmQueueTest
> 5947[INFO] Running org.apache.knox.gateway.audit.AuditServiceTest
> 5948[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.084 s - in org.apache.knox.gateway.audit.AuditServiceTest
> 5949[INFO] Running org.apache.knox.gateway.audit.StoreAndForwardAppenderTest
> 5950Running org.apache.knox.gateway.audit.StoreAndForwardAppenderTest#testAppender
> 5951Error: Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 500.013 s <<< FAILURE! - in org.apache.knox.gateway.audit.StoreAndForwardAppenderTest
> 5952Error: testAppender(org.apache.knox.gateway.audit.StoreAndForwardAppenderTest) Time elapsed: 500.012 s <<< ERROR!
> 5953org.junit.runners.model.TestTimedOutException: test timed out after 500000 milliseconds
> 5954 at org.apache.knox.gateway.audit.StoreAndForwardAppenderTest.testAppender(StoreAndForwardAppenderTest.java: {code}
--
This message was sent by Atlassian Jira
(v8.20.1#820001)