[
https://issues.apache.org/jira/browse/MRESOLVER-189?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17378690#comment-17378690
]
Michael Osipov commented on MRESOLVER-189:
------------------------------------------
Went through the data and the data is partially unusable because the executor
service reuses threads and therefore the same thread appear more then once in
the log making analysis im possible. Please build Maven from branch
{{3.8.x/MNG-6471}}. I will likely backport this to 3.8.x.
Please retry with patch.
As far as I was able to analyze dumps and and logs, the hang is again in
Redisson code. You simply provide an overview over lock events:
{noformat}
for run in {1..4} ; do \
grep -e Acquiring -e Releasing -e "Failed to acquire" semaphore-$nameMapper$run
| sed -e 's# \[#;[#g' -e 's#\] #];#' | sed 's#\[TRACE\];##' > data.txt; \
cat etl.sql | sqlite3; mv data.db data$run.db; done
{noformat}
The have a look at the SQLite database in the {{lock_events}} table you'll see
when and what is happening. If you see no previous lock held (interleaving
locks) then this is a bug in Redisson.
Waiting for new data....
> Using semaphore-redisson followed by rwlock-redisson on many parallel build
> of the same project triggers redisson error
> -----------------------------------------------------------------------------------------------------------------------
>
> Key: MRESOLVER-189
> URL: https://issues.apache.org/jira/browse/MRESOLVER-189
> Project: Maven Resolver
> Issue Type: Bug
> Reporter: Jacques-Etienne Beaudet
> Assignee: Michael Osipov
> Priority: Major
>
> While testing performance for in
> [https://github.com/apache/maven-resolver/pull/68|https://github.com/apache/maven-resolver/pull/68,]
> , I ran into an error using rwlock-redisson. Here are the steps to reproduce
> (hopefully it's easily reproducible on your end) and the logs of the run
> (trace enabled on org.eclipse.aether) at the end :
> * `redis-cli flushall` to get a clean slate
> * Clone a repository with a fair size
> * Make 4 copy of this repository (I ran my test with 4 copies, but 2 might
> be enough?)
> * `mvn clean` on all repositories
> * run a parallel build with semaphore-redis (`mvn compile -T1C
> -Daether.syncContext.named.factory=semaphore-redisson`) on all repositories
> * `mvn clean` all repositories
> * run a parallel build with rwlock-redis (`mvn compile -T1C
> -Daether.syncContext.named.factory=rwlock-redisson`) on all repositories
> By doing this, I ran into this and the only way out was running a `redis-cli
> flushall`.
>
> The way I ran my parallel build was really dumb and simple, something like
> that :
>
> {code:java}
> cd repo1 ; mvn clean > /tmp/log1 2>&1 & cd ../repo2 ; mvn clean > /tmp/log2
> 2>&1 & cd ../repo3 ; mvn clean > /tmp/log3 2>&1 & cd ../repo4 ; mvn clean >
> /tmp/log4 2>&1 & cd .. ;
> {code}
>
>
> Let me know if you can't reproduce, I might be able to provide you with
> traces logs of the semaphore build as well.
> {code:java}
> [INFO] Redisson 3.15.6
> [INFO] 1 connections initialized for localhost/127.0.0.1:6379
> [INFO] 24 connections initialized for localhost/127.0.0.1:6379
> [TRACE] Created Redisson client with id '42934566-3759-4f73-9fbc-a2d0a8368e1f'
> [DEBUG] Using manager EnhancedLocalRepositoryManager with priority 10.0 for
> /root/.m2/repository
> [INFO] Scanning for projects...
> [TRACE] Need 1 write lock(s) for
> [artifact:com.coveo:coveo-cloud-base-service-pom:40.123.0]
> [TRACE] Acquiring write lock for
> 'artifact:com.coveo:coveo-cloud-base-service-pom:40.123.0'
> [ERROR] Internal error: org.redisson.client.RedisException: ERR Error running
> script (call to f_6306ba3bf1f563b284bed52d305fce615c6664d9): @user_script:1:
> WRONGTYPE Operation against a key holding the wrong kind of value. channel:
> [id: 0x69ea1187, L:/127.0.0.1:60800 - R:localhost/127.0.0.1:6379] command:
> (EVAL), params: [local mode = redis.call('hget', KEYS[1], 'mode'); if (mode
> == false) then redis.call('hset', KEYS[1]..., 1,
> maven:resolver:artifact:com.coveo:coveo-cloud-base-service-pom:40.123.0,
> 30000, 42934566-3759-4f73-9fbc-a2d0a8368e1f:1:write] -> [Help 1]
> org.apache.maven.InternalErrorException: Internal error:
> org.redisson.client.RedisException: ERR Error running script (call to
> f_6306ba3bf1f563b284bed52d305fce615c6664d9): @user_script:1: WRONGTYPE
> Operation against a key holding the wrong kind of value. channel: [id:
> 0x69ea1187, L:/127.0.0.1:60800 - R:localhost/127.0.0.1:6379] command: (EVAL),
> params: [local mode = redis.call('hget', KEYS[1], 'mode'); if (mode == false)
> then redis.call('hset', KEYS[1]..., 1,
> maven:resolver:artifact:com.coveo:coveo-cloud-base-service-pom:40.123.0,
> 30000, 42934566-3759-4f73-9fbc-a2d0a8368e1f:1:write]
> at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:120)
> at org.apache.maven.cli.MavenCli.execute (MavenCli.java:957)
> at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:289)
> at org.apache.maven.cli.MavenCli.main (MavenCli.java:193)
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke
> (NativeMethodAccessorImpl.java:62)
> at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke
> (DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke (Method.java:566)
> at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced
> (Launcher.java:282)
> at org.codehaus.plexus.classworlds.launcher.Launcher.launch
> (Launcher.java:225)
> at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode
> (Launcher.java:406)
> at org.codehaus.plexus.classworlds.launcher.Launcher.main
> (Launcher.java:347)
> Caused by: org.redisson.client.RedisException: ERR Error running script (call
> to f_6306ba3bf1f563b284bed52d305fce615c6664d9): @user_script:1: WRONGTYPE
> Operation against a key holding the wrong kind of value. channel: [id:
> 0x69ea1187, L:/127.0.0.1:60800 - R:localhost/127.0.0.1:6379] command: (EVAL),
> params: [local mode = redis.call('hget', KEYS[1], 'mode'); if (mode == false)
> then redis.call('hset', KEYS[1]..., 1,
> maven:resolver:artifact:com.coveo:coveo-cloud-base-service-pom:40.123.0,
> 30000, 42934566-3759-4f73-9fbc-a2d0a8368e1f:1:write]
> at org.redisson.client.handler.CommandDecoder.decode
> (CommandDecoder.java:345)
> at org.redisson.client.handler.CommandDecoder.decodeCommandBatch
> (CommandDecoder.java:246)
> at org.redisson.client.handler.CommandDecoder.decodeCommand
> (CommandDecoder.java:188)
> at org.redisson.client.handler.CommandDecoder.decode
> (CommandDecoder.java:116)
> at org.redisson.client.handler.CommandDecoder.decode
> (CommandDecoder.java:101)
> at
> io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection
> (ByteToMessageDecoder.java:507)
> at io.netty.handler.codec.ReplayingDecoder.callDecode
> (ReplayingDecoder.java:366)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead
> (ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead
> (AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead
> (AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead
> (AbstractChannelHandlerContext.java:357)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead
> (DefaultChannelPipeline.java:1410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead
> (AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead
> (AbstractChannelHandlerContext.java:365)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead
> (DefaultChannelPipeline.java:919)
> at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read
> (AbstractNioByteChannel.java:166)
> at io.netty.channel.nio.NioEventLoop.processSelectedKey
> (NioEventLoop.java:719)
> at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized
> (NioEventLoop.java:655)
> at io.netty.channel.nio.NioEventLoop.processSelectedKeys
> (NioEventLoop.java:581)
> at io.netty.channel.nio.NioEventLoop.run (NioEventLoop.java:493)
> at io.netty.util.concurrent.SingleThreadEventExecutor$4.run
> (SingleThreadEventExecutor.java:989)
> at io.netty.util.internal.ThreadExecutorMap$2.run
> (ThreadExecutorMap.java:74)
> at io.netty.util.concurrent.FastThreadLocalRunnable.run
> (FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run (Thread.java:829)
> [ERROR]
> [ERROR] To see the full stack trace of the errors, re-run Maven with the -e
> switch.
> [ERROR] Re-run Maven using the -X switch to enable full debug logging.
> [ERROR]
> [ERROR] For more information about the errors and possible solutions, please
> read the following articles:
> [ERROR] [Help 1]
> http://cwiki.apache.org/confluence/display/MAVEN/InternalErrorException
> [TRACE] Shutting down Redisson client with id
> '42934566-3759-4f73-9fbc-a2d0a8368e1f'
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
