Error on call of coverage stop in java

[ksawerykarwacki]

I'm trying to introduce code coverage in my integration tests. Unfortunately every time I try to call ut_runner.coverage_stop() for the first time I get error listed below and no coverage is present on report generation if that was the only call. Of course starting coverage at later stage breaks some unique constraint on duplicating run id.

It is enough to wrap call in try/catch block and rerun it in catch to get everything back to normal but nevertheless it seems strange.

My DB is Oracle 12c Standard Edition docker image build using official scripts. Schema and utplsql are installed on the PDB.

`PreparedStatementCallback; uncategorized SQLException for SQL [call ut_runner.coverage_stop()]; SQL state [99999]; error code [8402]; ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278
; nested exception is java.sql.SQLException: ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278

org.springframework.jdbc.UncategorizedSQLException: PreparedStatementCallback; uncategorized SQLException for SQL [call ut_runner.coverage_stop()]; SQL state [99999]; error code [8402]; ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278
; nested exception is java.sql.SQLException: ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278

at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:89)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1443)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:633)
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:862)
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:883)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.update(NamedParameterJdbcTemplate.java:321)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.update(NamedParameterJdbcTemplate.java:326)
at com.aptitudesoftware.taf.revstream.config.SessionManager.stopCoverage(SessionManager.java:197)
at com.aptitudesoftware.taf.revstream.api.EngineService.stopCoverage(EngineService.java:61)
at com.aptitudesoftware.taf.revstream.api.RevStream.stopCoverage(RevStream.java:37)
at com.aptitudesoftware.taf.revstream.base.BaseTest.afterSuite(BaseTest.java:100)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
at org.testng.internal.MethodInvocationHelper.invokeMethodConsideringTimeout(MethodInvocationHelper.java:59)
at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:458)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:222)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:142)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:425)
at org.testng.SuiteRunner.run(SuiteRunner.java:364)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:84)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1208)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1137)
at org.testng.TestNG.runSuites(TestNG.java:1049)
at org.testng.TestNG.run(TestNG.java:1017)
at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.runTests(TestNGTestClassProcessor.java:141)
at org.gradle.api.internal.tasks.testing.testng.TestNGTestClassProcessor.stop(TestNGTestClassProcessor.java:90)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
at com.sun.proxy.$Proxy2.stop(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:133)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)
at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)
at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:414)
at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
at java.lang.Thread.run(Thread.java:748)

Caused by: java.sql.SQLException: ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278

at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494)
at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446)
at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:226)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:59)
at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:910)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3780)
at oracle.jdbc.driver.T4CPreparedStatement.executeInternal(T4CPreparedStatement.java:1343)
at oracle.jdbc.driver.OraclePreparedStatement.executeLargeUpdate(OraclePreparedStatement.java:3865)
at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3845)
at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeUpdate(OraclePreparedStatementWrapper.java:1061)
at org.springframework.jdbc.core.JdbcTemplate.lambda$update$0(JdbcTemplate.java:867)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:617)
... 53 more

Caused by: Error : 8402, Position : 5, Sql = call ut_runner.coverage_stop(), OriginalSql = call ut_runner.coverage_stop(), Error Msg = ORA-08402: error executing PL/SQL code coverage
ORA-06512: at "SYS.DBMS_PLSQL_CODE_COVERAGE", line 148
ORA-06512: at "UT3.UT_COVERAGE_HELPER_BLOCK", line 38
ORA-06512: at "UT3.UT_COVERAGE", line 203
ORA-06512: at "UT3.UT_RUNNER", line 278

at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498)
... 69 more`

[pesse]

Hey @ksawerykarwacki - which client do you use? Have you tried utPLSQL-cli?

[ksawerykarwacki]

I'm running call ut_runner.coverage_stop() using update method on jdbctemplate in my java code.

[pesse]

As far as I know, this is not part of the official documentation and not meant to be used in that way.
Is there a reason why you don't use the existing tools like utPLSQL-cli or running the coverage reporters?

Maybe @PhilippSalvisberg or @jgebal can give some insights

[ksawerykarwacki]

@pesse please check #1025 for reasons why I call it that way. Also I see that 3.1.11 is still not officially released so this issue is pretty much for prerelease code.

[pesse]

Ah, okay, I see - this context is important - good we have a reference now :)
I'll label this issue with "discussion", because it's not really an issue of utPLSQL but rather experimental :)

[jgebal]

I have noticed there is an issue in Oracle package SYS.DBMS_PLSQL_CODE_COVERAGE.
It fails to execute the coverage_stop in some cases.
One case that I'm 100% sure of is situation when the code under test invokes DBMS_STATS package (to gather table statistics).

So this fails:

• start coverage
• dbms_stats.gather_table_stats
• stop_coverage

I'm pretty sure that there will be no block-coverage reported after second call to stop_coverage.
So there are two things that can be done:

• Report the issue to Oracle and wait for it to be fixed (might take long time)
• Wrap the call to coverage_stop int a begin/exception/end block and trap exception on coverage stop. We would ignore those exceptions but then we loose information on why there is no block/statement level coverage reported.

It is a shitty situation but since we have no control over Oracle proprietary code behavior we can only react and workaround the issues we find.

@ksawerykarwacki - can you review and see if the code under test actually calls DBMS_STATS or other SYS-owned packages while coverage is gathered?

[jgebal]

Similar to #1097