You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@jmeter.apache.org by Philippe Mouawad <p....@ubik-ingenierie.com> on 2017/07/26 19:40:08 UTC

Bug in log4j2

Hello,
Working on 61321 I face what seems to be a bug in log4j2:
2017-07-26 21:37:39,417 WARN o.a.j.p.h.s.HTTPSamplerBase: Execution issue
when fetching embedded resources
java.util.concurrent.ExecutionException:
java.util.ConcurrentModificationException
    at java.util.concurrent.FutureTask.report(FutureTask.java:122)
~[?:1.8.0_121]
    at java.util.concurrent.FutureTask.get(FutureTask.java:192)
~[?:1.8.0_121]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.downloadPageResources(HTTPSamplerBase.java:1349)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.resultProcessing(HTTPSamplerBase.java:1657)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPAbstractImpl.resultProcessing(HTTPAbstractImpl.java:519)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:534)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1189)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1178)
[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:500)
[ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425)
[ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
    at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254)
[ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
Caused by: java.util.ConcurrentModificationException
    at
org.apache.commons.collections.map.AbstractLinkedMap$LinkIterator.nextEntry(AbstractLinkedMap.java:560)
~[commons-collections-3.2.2.jar:3.2.2]
    at
org.apache.commons.collections.map.AbstractLinkedMap$EntrySetIterator.next(AbstractLinkedMap.java:428)
~[commons-collections-3.2.2.jar:3.2.2]
    at
org.apache.logging.log4j.message.ParameterFormatter.appendMap(ParameterFormatter.java:569)
~[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.message.ParameterFormatter.appendPotentiallyRecursiveValue(ParameterFormatter.java:505)
~[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:432)
~[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
~[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.message.ReusableParameterizedMessage.formatTo(ReusableParameterizedMessage.java:313)
~[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.core.impl.MutableLogEvent.setMessage(MutableLogEvent.java:214)
~[log4j-core-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.core.impl.ReusableLogEventFactory.createEvent(ReusableLogEventFactory.java:81)
~[log4j-core-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:401)
[log4j-core-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
[log4j-core-2.8.2.jar:2.8.2]
    at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
[log4j-core-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2005)
[log4j-api-2.8.2.jar:2.8.2]
    at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1876)
[log4j-api-2.8.2.jar:2.8.2]
    at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:124)
[log4j-slf4j-impl-2.8.2.jar:2.8.2]
    at
org.apache.jmeter.protocol.http.control.CacheManager.getEntry(CacheManager.java:501)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.control.CacheManager.inCache(CacheManager.java:431)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:443)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyncSample.call(HTTPSamplerBase.java:2031)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at
org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyncSample.call(HTTPSamplerBase.java:1)
~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
~[?:1.8.0_121]
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
~[?:1.8.0_121]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
~[?:1.8.0_121]
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
~[?:1.8.0_121]
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
~[?:1.8.0_121]
    ... 1 more



-- 
Cordialement.
Philippe Mouawad.
Ubik-Ingénierie

UBIK LOAD PACK Web Site <http://www.ubikloadpack.com/>

UBIK LOAD PACK on TWITTER <https://twitter.com/ubikloadpack>

Re: Bug in log4j2

Posted by Philippe Mouawad <ph...@gmail.com>.
For info:
https://issues.apache.org/jira/browse/LOG4J2-1990


On Wednesday, July 26, 2017, Philippe Mouawad <ph...@gmail.com>
wrote:

> Hi Felix,
> I'll leave work on 61321 for tonight. If you want to investigate , go
> ahead.
>
> Thanks
>
> On Wed, Jul 26, 2017 at 9:47 PM, Felix Schumacher <felix.schumacher@
> internetallee.de
> <javascript:_e(%7B%7D,'cvml','felix.schumacher@internetallee.de');>>
> wrote:
>
>> Am 26.07.2017 um 21:40 schrieb Philippe Mouawad:
>>
>>> Hello,
>>> Working on 61321 I face what seems to be a bug in log4j2:
>>>
>> If the debug line is
>>
>> log.debug("Cache: {}", getCache())
>>
>> then I think the problem could be, that the cache gets modified, while
>> log4j is trying to print it and thus might throw a modification exception.
>>
>> This log message is a small leftover from my tries and a) should be
>> guarded by a log.isDebugEnabled() call and b) should probably be removed.
>>
>> Felix
>>
>>
>> 2017-07-26 21:37:39,417 WARN o.a.j.p.h.s.HTTPSamplerBase: Execution issue
>>> when fetching embedded resources
>>> java.util.concurrent.ExecutionException:
>>> java.util.ConcurrentModificationException
>>>      at java.util.concurrent.FutureTask.report(FutureTask.java:122)
>>> ~[?:1.8.0_121]
>>>      at java.util.concurrent.FutureTask.get(FutureTask.java:192)
>>> ~[?:1.8.0_121]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.down
>>> loadPageResources(HTTPSamplerBase.java:1349)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.resu
>>> ltProcessing(HTTPSamplerBase.java:1657)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPAbstractImpl.res
>>> ultProcessing(HTTPAbstractImpl.java:519)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(H
>>> TTPHC4Impl.java:534)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sam
>>> ple(HTTPSamplerProxy.java:74)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.samp
>>> le(HTTPSamplerBase.java:1189)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.samp
>>> le(HTTPSamplerBase.java:1178)
>>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.threads.JMeterThread.executeSamplePackage(
>>> JMeterThread.java:500)
>>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.threads.JMeterThread.processSampler(JMeter
>>> Thread.java:425)
>>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>>      at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java
>>> :254)
>>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>>      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
>>> Caused by: java.util.ConcurrentModificationException
>>>      at
>>> org.apache.commons.collections.map.AbstractLinkedMap$LinkIte
>>> rator.nextEntry(AbstractLinkedMap.java:560)
>>> ~[commons-collections-3.2.2.jar:3.2.2]
>>>      at
>>> org.apache.commons.collections.map.AbstractLinkedMap$EntrySe
>>> tIterator.next(AbstractLinkedMap.java:428)
>>> ~[commons-collections-3.2.2.jar:3.2.2]
>>>      at
>>> org.apache.logging.log4j.message.ParameterFormatter.appendMa
>>> p(ParameterFormatter.java:569)
>>> ~[log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.message.ParameterFormatter.appendPo
>>> tentiallyRecursiveValue(ParameterFormatter.java:505)
>>> ~[log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.message.ParameterFormatter.recursiv
>>> eDeepToString(ParameterFormatter.java:432)
>>> ~[log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.message.ParameterFormatter.formatMe
>>> ssage2(ParameterFormatter.java:189)
>>> ~[log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.message.ReusableParameterizedMessag
>>> e.formatTo(ReusableParameterizedMessage.java:313)
>>> ~[log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.core.impl.MutableLogEvent.setMessag
>>> e(MutableLogEvent.java:214)
>>> ~[log4j-core-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.core.impl.ReusableLogEventFactory.c
>>> reateEvent(ReusableLogEventFactory.java:81)
>>> ~[log4j-core-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.core.config.LoggerConfig.log(Logger
>>> Config.java:401)
>>> [log4j-core-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.core.config.AwaitCompletionReliabil
>>> ityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
>>> [log4j-core-2.8.2.jar:2.8.2]
>>>      at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
>>> [log4j-core-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely
>>> (AbstractLogger.java:2091)
>>> [log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.spi.AbstractLogger.logMessage(Abstr
>>> actLogger.java:2005)
>>> [log4j-api-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(Abs
>>> tractLogger.java:1876)
>>> [log4j-api-2.8.2.jar:2.8.2]
>>>      at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:124)
>>> [log4j-slf4j-impl-2.8.2.jar:2.8.2]
>>>      at
>>> org.apache.jmeter.protocol.http.control.CacheManager.getEntr
>>> y(CacheManager.java:501)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.control.CacheManager.inCache
>>> (CacheManager.java:431)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(H
>>> TTPHC4Impl.java:443)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sam
>>> ple(HTTPSamplerProxy.java:74)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyn
>>> cSample.call(HTTPSamplerBase.java:2031)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at
>>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyn
>>> cSample.call(HTTPSamplerBase.java:1)
>>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>> ~[?:1.8.0_121]
>>>      at
>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>>> ~[?:1.8.0_121]
>>>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>> ~[?:1.8.0_121]
>>>      at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>> ~[?:1.8.0_121]
>>>      at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>> ~[?:1.8.0_121]
>>>      ... 1 more
>>>
>>>
>>>
>>>
>>
>
>
> --
> Cordialement.
> Philippe Mouawad.
>
>
>

-- 
Cordialement.
Philippe Mouawad.

Re: Bug in log4j2

Posted by Philippe Mouawad <ph...@gmail.com>.
Hi Felix,
I'll leave work on 61321 for tonight. If you want to investigate , go ahead.

Thanks

On Wed, Jul 26, 2017 at 9:47 PM, Felix Schumacher <
felix.schumacher@internetallee.de> wrote:

> Am 26.07.2017 um 21:40 schrieb Philippe Mouawad:
>
>> Hello,
>> Working on 61321 I face what seems to be a bug in log4j2:
>>
> If the debug line is
>
> log.debug("Cache: {}", getCache())
>
> then I think the problem could be, that the cache gets modified, while
> log4j is trying to print it and thus might throw a modification exception.
>
> This log message is a small leftover from my tries and a) should be
> guarded by a log.isDebugEnabled() call and b) should probably be removed.
>
> Felix
>
>
> 2017-07-26 21:37:39,417 WARN o.a.j.p.h.s.HTTPSamplerBase: Execution issue
>> when fetching embedded resources
>> java.util.concurrent.ExecutionException:
>> java.util.ConcurrentModificationException
>>      at java.util.concurrent.FutureTask.report(FutureTask.java:122)
>> ~[?:1.8.0_121]
>>      at java.util.concurrent.FutureTask.get(FutureTask.java:192)
>> ~[?:1.8.0_121]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.down
>> loadPageResources(HTTPSamplerBase.java:1349)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.resu
>> ltProcessing(HTTPSamplerBase.java:1657)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPAbstractImpl.res
>> ultProcessing(HTTPAbstractImpl.java:519)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(
>> HTTPHC4Impl.java:534)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sam
>> ple(HTTPSamplerProxy.java:74)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.samp
>> le(HTTPSamplerBase.java:1189)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.samp
>> le(HTTPSamplerBase.java:1178)
>> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.threads.JMeterThread.executeSamplePackage(
>> JMeterThread.java:500)
>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.threads.JMeterThread.processSampler(JMeter
>> Thread.java:425)
>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>      at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254)
>> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>>      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
>> Caused by: java.util.ConcurrentModificationException
>>      at
>> org.apache.commons.collections.map.AbstractLinkedMap$LinkIte
>> rator.nextEntry(AbstractLinkedMap.java:560)
>> ~[commons-collections-3.2.2.jar:3.2.2]
>>      at
>> org.apache.commons.collections.map.AbstractLinkedMap$EntrySe
>> tIterator.next(AbstractLinkedMap.java:428)
>> ~[commons-collections-3.2.2.jar:3.2.2]
>>      at
>> org.apache.logging.log4j.message.ParameterFormatter.appendMa
>> p(ParameterFormatter.java:569)
>> ~[log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.message.ParameterFormatter.appendPo
>> tentiallyRecursiveValue(ParameterFormatter.java:505)
>> ~[log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.message.ParameterFormatter.recursiv
>> eDeepToString(ParameterFormatter.java:432)
>> ~[log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.message.ParameterFormatter.formatMe
>> ssage2(ParameterFormatter.java:189)
>> ~[log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.message.ReusableParameterizedMessag
>> e.formatTo(ReusableParameterizedMessage.java:313)
>> ~[log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.core.impl.MutableLogEvent.setMessag
>> e(MutableLogEvent.java:214)
>> ~[log4j-core-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.core.impl.ReusableLogEventFactory.c
>> reateEvent(ReusableLogEventFactory.java:81)
>> ~[log4j-core-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.core.config.LoggerConfig.log(Logger
>> Config.java:401)
>> [log4j-core-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.core.config.AwaitCompletionReliabil
>> ityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
>> [log4j-core-2.8.2.jar:2.8.2]
>>      at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
>> [log4j-core-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely
>> (AbstractLogger.java:2091)
>> [log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.spi.AbstractLogger.logMessage(Abstr
>> actLogger.java:2005)
>> [log4j-api-2.8.2.jar:2.8.2]
>>      at
>> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(Abs
>> tractLogger.java:1876)
>> [log4j-api-2.8.2.jar:2.8.2]
>>      at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:124)
>> [log4j-slf4j-impl-2.8.2.jar:2.8.2]
>>      at
>> org.apache.jmeter.protocol.http.control.CacheManager.getEntr
>> y(CacheManager.java:501)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.control.CacheManager.inCache
>> (CacheManager.java:431)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(
>> HTTPHC4Impl.java:443)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sam
>> ple(HTTPSamplerProxy.java:74)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyn
>> cSample.call(HTTPSamplerBase.java:2031)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at
>> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyn
>> cSample.call(HTTPSamplerBase.java:1)
>> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>> ~[?:1.8.0_121]
>>      at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>> ~[?:1.8.0_121]
>>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>> ~[?:1.8.0_121]
>>      at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>> Executor.java:1142)
>> ~[?:1.8.0_121]
>>      at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>> lExecutor.java:617)
>> ~[?:1.8.0_121]
>>      ... 1 more
>>
>>
>>
>>
>


-- 
Cordialement.
Philippe Mouawad.

Re: Bug in log4j2

Posted by Felix Schumacher <fe...@internetallee.de>.
Am 26.07.2017 um 21:40 schrieb Philippe Mouawad:
> Hello,
> Working on 61321 I face what seems to be a bug in log4j2:
If the debug line is

log.debug("Cache: {}", getCache())

then I think the problem could be, that the cache gets modified, while 
log4j is trying to print it and thus might throw a modification exception.

This log message is a small leftover from my tries and a) should be 
guarded by a log.isDebugEnabled() call and b) should probably be removed.

Felix

> 2017-07-26 21:37:39,417 WARN o.a.j.p.h.s.HTTPSamplerBase: Execution issue
> when fetching embedded resources
> java.util.concurrent.ExecutionException:
> java.util.ConcurrentModificationException
>      at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> ~[?:1.8.0_121]
>      at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> ~[?:1.8.0_121]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.downloadPageResources(HTTPSamplerBase.java:1349)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.resultProcessing(HTTPSamplerBase.java:1657)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPAbstractImpl.resultProcessing(HTTPAbstractImpl.java:519)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:534)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1189)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1178)
> [ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:500)
> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425)
> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>      at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254)
> [ApacheJMeter_core.jar:3.3-SNAPSHOT.20170724]
>      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
> Caused by: java.util.ConcurrentModificationException
>      at
> org.apache.commons.collections.map.AbstractLinkedMap$LinkIterator.nextEntry(AbstractLinkedMap.java:560)
> ~[commons-collections-3.2.2.jar:3.2.2]
>      at
> org.apache.commons.collections.map.AbstractLinkedMap$EntrySetIterator.next(AbstractLinkedMap.java:428)
> ~[commons-collections-3.2.2.jar:3.2.2]
>      at
> org.apache.logging.log4j.message.ParameterFormatter.appendMap(ParameterFormatter.java:569)
> ~[log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.message.ParameterFormatter.appendPotentiallyRecursiveValue(ParameterFormatter.java:505)
> ~[log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:432)
> ~[log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
> ~[log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.message.ReusableParameterizedMessage.formatTo(ReusableParameterizedMessage.java:313)
> ~[log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.core.impl.MutableLogEvent.setMessage(MutableLogEvent.java:214)
> ~[log4j-core-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.core.impl.ReusableLogEventFactory.createEvent(ReusableLogEventFactory.java:81)
> ~[log4j-core-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:401)
> [log4j-core-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> [log4j-core-2.8.2.jar:2.8.2]
>      at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
> [log4j-core-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
> [log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2005)
> [log4j-api-2.8.2.jar:2.8.2]
>      at
> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1876)
> [log4j-api-2.8.2.jar:2.8.2]
>      at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:124)
> [log4j-slf4j-impl-2.8.2.jar:2.8.2]
>      at
> org.apache.jmeter.protocol.http.control.CacheManager.getEntry(CacheManager.java:501)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.control.CacheManager.inCache(CacheManager.java:431)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:443)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyncSample.call(HTTPSamplerBase.java:2031)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at
> org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase$ASyncSample.call(HTTPSamplerBase.java:1)
> ~[ApacheJMeter_http.jar:3.3-SNAPSHOT.20170724]
>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> ~[?:1.8.0_121]
>      at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> ~[?:1.8.0_121]
>      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> ~[?:1.8.0_121]
>      at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> ~[?:1.8.0_121]
>      at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> ~[?:1.8.0_121]
>      ... 1 more
>
>
>