[
https://issues.apache.org/jira/browse/IGNITE-20471?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Mirza Aliev updated IGNITE-20471:
---------------------------------
Description:
*Motivation*
The following code prints the different logs:
{code:java}
sql("CREATE TABLE TEST(ID INT PRIMARY KEY, VAL0 INT)");
IgniteSql sql = igniteSql();
Session ses = sql.sessionBuilder().build();
try {
ses.execute(null, "INSERT INTO TEST VALUES (?, ?)", 1, 1);
} catch (Exception e) {
log.error("EXCEPTION", e);
throw e;
}
{code}
This log is printed when we call {{log.error("EXCEPTION", e);}}
{noformat}
[2023-09-29T17:58:48,717][ERROR][main][ItSqlAsynchronousApiTest] EXCEPTION
org.apache.ignite.lang.IgniteException: null
at
java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710) ~[?:?]
at
org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
~[main/:?]
at
org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
~[main/:?]
at
org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
~[integrationTest/:?]
...
Caused by: java.util.concurrent.CompletionException:
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
~[main/:?]
...
Caused by: org.apache.ignite.lang.IgniteException
at
org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
~[main/:?]
at
java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
~[?:?]
at
java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907)
~[?:?]
...
Caused by: java.util.concurrent.TimeoutException
at
org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
~[main/:?]
...
{noformat}
This one is printed after we {{throw e}}
{noformat}
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
java.base/java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710)
at
org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
at
org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
at
org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
at
org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
...
Caused by: java.util.concurrent.CompletionException:
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
at
java.base/java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:986)
...
Caused by: org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
...
Caused by: java.util.concurrent.TimeoutException
at
org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
...
{noformat}
*Expected behaviour*
I would expect that we do not print
{noformat}
org.apache.ignite.lang.IgniteException: null
{noformat}
*Implementation notes*
The root cause is that when we call
{code:java}
default ResultSet<SqlRow> execute(@Nullable Transaction transaction, String
query, @Nullable Object... arguments) {
Objects.requireNonNull(query);
try {
return new SyncResultSetAdapter<>(executeAsync(transaction, query,
arguments).join());
} catch (CompletionException e) {
throw
ExceptionUtils.sneakyThrow(ExceptionUtils.copyExceptionWithCause(e));
}
}
{code}
Especially when we do {{ExceptionUtils.copyExceptionWithCause(e)}} {{e}} is a
{{CompleteionException}} with cause as {{TimeoutExcpetion}}, which message is
{{null}}, so we return {{TimeoutExcpetion}} with {{null}} message, that is why
we receive {{org.apache.ignite.lang.IgniteException: null}}
was:
*Motivation*
The following code prints the different logs:
{code:java}
sql("CREATE TABLE TEST(ID INT PRIMARY KEY, VAL0 INT)");
IgniteSql sql = igniteSql();
Session ses = sql.sessionBuilder().build();
try {
ses.execute(null, "INSERT INTO TEST VALUES (?, ?)", 1, 1);
} catch (Exception e) {
log.error("EXCEPTION", e);
throw e;
}
{code}
This log is printed when we call {{log.error("EXCEPTION", e);}}
{noformat}
[2023-09-29T17:58:48,717][ERROR][main][ItSqlAsynchronousApiTest] EXCEPTION
org.apache.ignite.lang.IgniteException: null
at
java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710) ~[?:?]
at
org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
~[main/:?]
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
~[main/:?]
at
org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
~[main/:?]
at
org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
~[integrationTest/:?]
...
Caused by: java.util.concurrent.CompletionException:
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
~[main/:?]
...
Caused by: org.apache.ignite.lang.IgniteException
at
org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
~[main/:?]
at
java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
~[?:?]
at
java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907)
~[?:?]
...
Caused by: java.util.concurrent.TimeoutException
at
org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
~[main/:?]
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
~[main/:?]
...
{noformat}
{noformat}
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
java.base/java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710)
at
org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
at
org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
at
org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
at
org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
at
org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
...
Caused by: java.util.concurrent.CompletionException:
org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
at
java.base/java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:986)
...
Caused by: org.apache.ignite.lang.IgniteException: IGN-CMN-65535
TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
at
org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
at
org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
...
Caused by: java.util.concurrent.TimeoutException
at
org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
at
org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
...
{noformat}
This one is printed after we {{throw e}}
*Expected behaviour*
I would expect that we do not print
{noformat}
org.apache.ignite.lang.IgniteException: null
{noformat}
*Implementation notes*
The root cause is that when we call
{code:java}
default ResultSet<SqlRow> execute(@Nullable Transaction transaction, String
query, @Nullable Object... arguments) {
Objects.requireNonNull(query);
try {
return new SyncResultSetAdapter<>(executeAsync(transaction, query,
arguments).join());
} catch (CompletionException e) {
throw
ExceptionUtils.sneakyThrow(ExceptionUtils.copyExceptionWithCause(e));
}
}
{code}
Especially when we do {{ExceptionUtils.copyExceptionWithCause(e)}} {{e}} is a
{{CompleteionException}} with cause as {{TimeoutExcpetion}}, which message is
{{null}}, so we return {{TimeoutExcpetion}} with {{null}} message, that is why
we receive {{org.apache.ignite.lang.IgniteException: null}}
> Timeout exception from org.apache.ignite.sql.Session#execute() could be
> printed to log ambiguously
> --------------------------------------------------------------------------------------------------
>
> Key: IGNITE-20471
> URL: https://issues.apache.org/jira/browse/IGNITE-20471
> Project: Ignite
> Issue Type: Bug
> Reporter: Mirza Aliev
> Priority: Major
> Labels: ignite-3
>
> *Motivation*
> The following code prints the different logs:
> {code:java}
> sql("CREATE TABLE TEST(ID INT PRIMARY KEY, VAL0 INT)");
> IgniteSql sql = igniteSql();
> Session ses = sql.sessionBuilder().build();
> try {
> ses.execute(null, "INSERT INTO TEST VALUES (?, ?)", 1, 1);
> } catch (Exception e) {
> log.error("EXCEPTION", e);
> throw e;
> }
> {code}
> This log is printed when we call {{log.error("EXCEPTION", e);}}
> {noformat}
> [2023-09-29T17:58:48,717][ERROR][main][ItSqlAsynchronousApiTest] EXCEPTION
> org.apache.ignite.lang.IgniteException: null
> at
> java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710)
> ~[?:?]
> at
> org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
> ~[main/:?]
> at
> org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
> ~[main/:?]
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
> ~[main/:?]
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
> ~[main/:?]
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
> ~[integrationTest/:?]
> ...
> Caused by: java.util.concurrent.CompletionException:
> org.apache.ignite.lang.IgniteException: IGN-CMN-65535
> TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
> at
> org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
> ~[main/:?]
> ...
> Caused by: org.apache.ignite.lang.IgniteException
> at
> org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
> ~[main/:?]
> at
> java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
> ~[?:?]
> at
> java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907)
> ~[?:?]
> ...
> Caused by: java.util.concurrent.TimeoutException
> at
> org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
> ~[main/:?]
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
> ~[main/:?]
> ...
> {noformat}
> This one is printed after we {{throw e}}
> {noformat}
> org.apache.ignite.lang.IgniteException: IGN-CMN-65535
> TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
> at
> java.base/java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:710)
> at
> org.apache.ignite.internal.util.ExceptionUtils$1.copy(ExceptionUtils.java:772)
> at
> org.apache.ignite.internal.util.ExceptionUtils$ExceptionFactory.createCopy(ExceptionUtils.java:706)
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:543)
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCauseInternal(ExceptionUtils.java:641)
> at
> org.apache.ignite.internal.util.ExceptionUtils.copyExceptionWithCause(ExceptionUtils.java:494)
> at
> org.apache.ignite.internal.sql.AbstractSession.execute(AbstractSession.java:63)
> at
> org.apache.ignite.internal.sql.api.ItSqlAsynchronousApiTest.select(ItSqlAsynchronousApiTest.java:458)
> ...
> Caused by: java.util.concurrent.CompletionException:
> org.apache.ignite.lang.IgniteException: IGN-CMN-65535
> TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
> at
> org.apache.ignite.internal.sql.api.SessionImpl.lambda$executeAsync$3(SessionImpl.java:208)
> at
> java.base/java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:986)
> ...
> Caused by: org.apache.ignite.lang.IgniteException: IGN-CMN-65535
> TraceId:54d81fd9-6453-4adb-863d-6e82b9c0cb08
> at
> org.apache.ignite.internal.lang.IgniteExceptionMapperUtil.mapToPublicException(IgniteExceptionMapperUtil.java:110)
> at
> org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.wrapIfNecessary(AsyncSqlCursorImpl.java:100)
> at
> org.apache.ignite.internal.sql.engine.AsyncSqlCursorImpl.lambda$requestNextAsync$0(AsyncSqlCursorImpl.java:76)
> ...
> Caused by: java.util.concurrent.TimeoutException
> at
> org.apache.ignite.internal.sql.engine.exec.ResolvedDependencies.fetchColocationGroup(ResolvedDependencies.java:60)
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.fetchColocationGroups(ExecutionServiceImpl.java:982)
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.mapFragments(ExecutionServiceImpl.java:850)
> at
> org.apache.ignite.internal.sql.engine.exec.ExecutionServiceImpl$DistributedQueryManager.lambda$execute$11(ExecutionServiceImpl.java:654)
> ...
> {noformat}
> *Expected behaviour*
> I would expect that we do not print
> {noformat}
> org.apache.ignite.lang.IgniteException: null
> {noformat}
> *Implementation notes*
> The root cause is that when we call
> {code:java}
> default ResultSet<SqlRow> execute(@Nullable Transaction transaction,
> String query, @Nullable Object... arguments) {
> Objects.requireNonNull(query);
> try {
> return new SyncResultSetAdapter<>(executeAsync(transaction,
> query, arguments).join());
> } catch (CompletionException e) {
> throw
> ExceptionUtils.sneakyThrow(ExceptionUtils.copyExceptionWithCause(e));
> }
> }
> {code}
> Especially when we do {{ExceptionUtils.copyExceptionWithCause(e)}} {{e}} is a
> {{CompleteionException}} with cause as {{TimeoutExcpetion}}, which message is
> {{null}}, so we return {{TimeoutExcpetion}} with {{null}} message, that is
> why we receive {{org.apache.ignite.lang.IgniteException: null}}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
