[
https://issues.apache.org/jira/browse/IGNITE-21090?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrey Khitrin updated IGNITE-21090:
------------------------------------
Description:
We have a simple automated test that creates 1000 tables of the same structure
and insert few rows into each one. Recently, it started to fail after creating
several tens of tables. An exception is always the same:
{code:java}
12:05:40.687 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
Update: create table test_table_49(id INTEGER not null, column_1 VARCHAR(50)
not null, column_2 VARCHAR(50) not null, column_3 VARCHAR(50) not null,
column_4 VARCHAR(50) not null, primary key (id))
Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
logInternal
INFO: Partition assignment change notification received
[remoteAddress=localhost:10800]
12:05:42.699 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
Creation of table: test_table_49 took 2012 ms
12:05:42.700 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Creation of 50 tables took 101686 ms
Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
logInternal
INFO: Partition assignment change notification received
[remoteAddress=localhost:10800]
12:05:45.539 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Table test_table_0 contains 1 rows
12:05:45.591 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Table test_table_1 contains 1 rows
Dec 15, 2023 12:05:45 PM org.apache.ignite.internal.logger.IgniteLogger error
SEVERE: Failed to deserialize server response [remoteAddress=localhost:10800]:
refCnt: 0
io.netty.util.IllegalReferenceCountException: refCnt: 0
at
io.netty.buffer.AbstractByteBuf.ensureAccessible(AbstractByteBuf.java:1454)
at
io.netty.buffer.AbstractByteBuf.checkReadableBytes0(AbstractByteBuf.java:1440)
at io.netty.buffer.AbstractByteBuf.readByte(AbstractByteBuf.java:730)
at
org.apache.ignite.internal.client.proto.ClientMessageUnpacker.unpackBoolean(ClientMessageUnpacker.java:209)
at
org.apache.ignite.internal.jdbc.proto.event.Response.readBinary(Response.java:81)
at
org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.lambda$closeAsync$3(JdbcClientQueryCursorHandler.java:65)
at
org.apache.ignite.internal.client.TcpClientChannel.lambda$receiveAsync$5(TcpClientChannel.java:368)
at
java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
at
java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
at
java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
at
org.apache.ignite.internal.client.TcpClientChannel.receiveAsync(TcpClientChannel.java:362)
at
org.apache.ignite.internal.client.TcpClientChannel.serviceAsync(TcpClientChannel.java:283)
at
org.apache.ignite.internal.client.ClientChannel.serviceAsync(ClientChannel.java:59)
at
org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.closeAsync(JdbcClientQueryCursorHandler.java:62)
at
org.apache.ignite.internal.jdbc.JdbcResultSet.close0(JdbcResultSet.java:287)
at
org.apache.ignite.internal.jdbc.JdbcResultSet.close(JdbcResultSet.java:268)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTableContains1RowAndColumnsValuesAreCorrect(TablesAmountCapacityTest.java:172)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTablesAreValid(TablesAmountCapacityTest.java:285)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.create1000EmptyTablesAmountOfColumnsEachAndMakeSimpleQueries(TablesAmountCapacityTest.java:102)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:728)
at
org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at
io.qameta.allure.junit5.AllureJunit5.interceptTestTemplateMethod(AllureJunit5.java:59)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
at
org.junit.jupiter.api.AssertTimeoutPreemptively.lambda$submitTask$3(AssertTimeoutPreemptively.java:95)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
{code}
-It seems that an issue was introduced somewhere between commits
0a2559d6658bdd7c946bc0794b844594f4f42ce5 (no issue yet) and
ba6cd4dfff0e4bc2eacb437a1331454e030bff84.-
was:
We have a simple automated test that creates 1000 tables of the same structure
and insert few rows into each one. Recently, it started to fail after creating
several tens of tables. An exception is always the same:
{code:java}
12:05:40.687 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
Update: create table test_table_49(id INTEGER not null, column_1 VARCHAR(50)
not null, column_2 VARCHAR(50) not null, column_3 VARCHAR(50) not null,
column_4 VARCHAR(50) not null, primary key (id))
Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
logInternal
INFO: Partition assignment change notification received
[remoteAddress=localhost:10800]
12:05:42.699 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
Creation of table: test_table_49 took 2012 ms
12:05:42.700 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Creation of 50 tables took 101686 ms
Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
logInternal
INFO: Partition assignment change notification received
[remoteAddress=localhost:10800]
12:05:45.539 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Table test_table_0 contains 1 rows
12:05:45.591 [junit-timeout-thread-1] INFO
o.g.a.tests.TablesAmountCapacityTest - Table test_table_1 contains 1 rows
Dec 15, 2023 12:05:45 PM org.apache.ignite.internal.logger.IgniteLogger error
SEVERE: Failed to deserialize server response [remoteAddress=localhost:10800]:
refCnt: 0
io.netty.util.IllegalReferenceCountException: refCnt: 0
at
io.netty.buffer.AbstractByteBuf.ensureAccessible(AbstractByteBuf.java:1454)
at
io.netty.buffer.AbstractByteBuf.checkReadableBytes0(AbstractByteBuf.java:1440)
at io.netty.buffer.AbstractByteBuf.readByte(AbstractByteBuf.java:730)
at
org.apache.ignite.internal.client.proto.ClientMessageUnpacker.unpackBoolean(ClientMessageUnpacker.java:209)
at
org.apache.ignite.internal.jdbc.proto.event.Response.readBinary(Response.java:81)
at
org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.lambda$closeAsync$3(JdbcClientQueryCursorHandler.java:65)
at
org.apache.ignite.internal.client.TcpClientChannel.lambda$receiveAsync$5(TcpClientChannel.java:368)
at
java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
at
java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
at
java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
at
org.apache.ignite.internal.client.TcpClientChannel.receiveAsync(TcpClientChannel.java:362)
at
org.apache.ignite.internal.client.TcpClientChannel.serviceAsync(TcpClientChannel.java:283)
at
org.apache.ignite.internal.client.ClientChannel.serviceAsync(ClientChannel.java:59)
at
org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.closeAsync(JdbcClientQueryCursorHandler.java:62)
at
org.apache.ignite.internal.jdbc.JdbcResultSet.close0(JdbcResultSet.java:287)
at
org.apache.ignite.internal.jdbc.JdbcResultSet.close(JdbcResultSet.java:268)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTableContains1RowAndColumnsValuesAreCorrect(TablesAmountCapacityTest.java:172)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTablesAreValid(TablesAmountCapacityTest.java:285)
at
org.gridgain.ai3tests.tests.TablesAmountCapacityTest.create1000EmptyTablesAmountOfColumnsEachAndMakeSimpleQueries(TablesAmountCapacityTest.java:102)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:728)
at
org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
at
io.qameta.allure.junit5.AllureJunit5.interceptTestTemplateMethod(AllureJunit5.java:59)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
at
org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
at
org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
at
org.junit.jupiter.api.AssertTimeoutPreemptively.lambda$submitTask$3(AssertTimeoutPreemptively.java:95)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
{code}
It seems that an issue was introduced somewhere between commits
0a2559d6658bdd7c946bc0794b844594f4f42ce5 (no issue yet) and
ba6cd4dfff0e4bc2eacb437a1331454e030bff84.
> "IllegalReferenceCountException: refCnt: 0" in SQL query
> --------------------------------------------------------
>
> Key: IGNITE-21090
> URL: https://issues.apache.org/jira/browse/IGNITE-21090
> Project: Ignite
> Issue Type: Bug
> Components: sql
> Affects Versions: 3.0.0-beta2
> Reporter: Andrey Khitrin
> Priority: Major
> Labels: client, ignite-3, sql
>
> We have a simple automated test that creates 1000 tables of the same
> structure and insert few rows into each one. Recently, it started to fail
> after creating several tens of tables. An exception is always the same:
> {code:java}
> 12:05:40.687 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
> Update: create table test_table_49(id INTEGER not null, column_1 VARCHAR(50)
> not null, column_2 VARCHAR(50) not null, column_3 VARCHAR(50) not null,
> column_4 VARCHAR(50) not null, primary key (id))
> Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
> logInternal
> INFO: Partition assignment change notification received
> [remoteAddress=localhost:10800]
> 12:05:42.699 [junit-timeout-thread-51] INFO o.g.q.s.g.TableGeneratorHelper -
> Creation of table: test_table_49 took 2012 ms
> 12:05:42.700 [junit-timeout-thread-1] INFO
> o.g.a.tests.TablesAmountCapacityTest - Creation of 50 tables took 101686 ms
> Dec 15, 2023 12:05:42 PM org.apache.ignite.internal.logger.IgniteLogger
> logInternal
> INFO: Partition assignment change notification received
> [remoteAddress=localhost:10800]
> 12:05:45.539 [junit-timeout-thread-1] INFO
> o.g.a.tests.TablesAmountCapacityTest - Table test_table_0 contains 1 rows
> 12:05:45.591 [junit-timeout-thread-1] INFO
> o.g.a.tests.TablesAmountCapacityTest - Table test_table_1 contains 1 rows
> Dec 15, 2023 12:05:45 PM org.apache.ignite.internal.logger.IgniteLogger error
> SEVERE: Failed to deserialize server response
> [remoteAddress=localhost:10800]: refCnt: 0
> io.netty.util.IllegalReferenceCountException: refCnt: 0
> at
> io.netty.buffer.AbstractByteBuf.ensureAccessible(AbstractByteBuf.java:1454)
> at
> io.netty.buffer.AbstractByteBuf.checkReadableBytes0(AbstractByteBuf.java:1440)
> at io.netty.buffer.AbstractByteBuf.readByte(AbstractByteBuf.java:730)
> at
> org.apache.ignite.internal.client.proto.ClientMessageUnpacker.unpackBoolean(ClientMessageUnpacker.java:209)
> at
> org.apache.ignite.internal.jdbc.proto.event.Response.readBinary(Response.java:81)
> at
> org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.lambda$closeAsync$3(JdbcClientQueryCursorHandler.java:65)
> at
> org.apache.ignite.internal.client.TcpClientChannel.lambda$receiveAsync$5(TcpClientChannel.java:368)
> at
> java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
> at
> java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
> at
> java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
> at
> org.apache.ignite.internal.client.TcpClientChannel.receiveAsync(TcpClientChannel.java:362)
> at
> org.apache.ignite.internal.client.TcpClientChannel.serviceAsync(TcpClientChannel.java:283)
> at
> org.apache.ignite.internal.client.ClientChannel.serviceAsync(ClientChannel.java:59)
> at
> org.apache.ignite.internal.jdbc.JdbcClientQueryCursorHandler.closeAsync(JdbcClientQueryCursorHandler.java:62)
> at
> org.apache.ignite.internal.jdbc.JdbcResultSet.close0(JdbcResultSet.java:287)
> at
> org.apache.ignite.internal.jdbc.JdbcResultSet.close(JdbcResultSet.java:268)
> at
> org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTableContains1RowAndColumnsValuesAreCorrect(TablesAmountCapacityTest.java:172)
> at
> org.gridgain.ai3tests.tests.TablesAmountCapacityTest.assertTablesAreValid(TablesAmountCapacityTest.java:285)
> at
> org.gridgain.ai3tests.tests.TablesAmountCapacityTest.create1000EmptyTablesAmountOfColumnsEachAndMakeSimpleQueries(TablesAmountCapacityTest.java:102)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at
> org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:728)
> at
> org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
> at
> org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
> at
> io.qameta.allure.junit5.AllureJunit5.interceptTestTemplateMethod(AllureJunit5.java:59)
> at
> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
> at
> org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
> at
> org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
> at
> org.junit.jupiter.api.AssertTimeoutPreemptively.lambda$submitTask$3(AssertTimeoutPreemptively.java:95)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base/java.lang.Thread.run(Thread.java:829)
> {code}
> -It seems that an issue was introduced somewhere between commits
> 0a2559d6658bdd7c946bc0794b844594f4f42ce5 (no issue yet) and
> ba6cd4dfff0e4bc2eacb437a1331454e030bff84.-
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
