Reporter initialization fails with error ORA-01013: user requested cancel of current operation
Describe the bug Randomly we have reporter initialization that fails with error : ORA-01013: user requested cancel of current operation Our tests are launched using jenkins in "Execute Windows batch command" build steps with following syntax:
According this other bug (fixed): https://github.com/utPLSQL/utPLSQL-cli/issues/191 I added parameter --ora-stuck-timeout=0 in command line but that did not fix my problem
set PAK_NAME=%JOB_NAME:tpkg_=pkg_%
%utPLSQL_JCLI%\utplsql run ut_test/ut_test_psw@%Database% -d --failure-exit-code=0 --ora-stuck-timeout=0 ^
-f=ut_xunit_reporter -o=%JOB_NAME%_result.xml ^
-f=ut_coverage_cobertura_reporter -o=%JOB_NAME%_coverage.xml ^
-f=ut_coverage_html_reporter -o=%JOB_NAME%_coverage.html -p=ut_test.%JOB_NAME% -include=vbo.%PAK_NAME%
Error stack is :
D:\JenkinsData\Workspaces\tpkg_var_pnl_vectors>V:\Tools\UnitTests\Jenkins\utPLSQL-cli\bin\utplsql run ut_test/ut_test_psw@VISDAY_GVA -d --failure-exit-code=0 --ora-stuck-timeout=0 -f=ut_xunit_reporter -o=tpkg_var_pnl_vectors_result.xml -f=ut_coverage_cobertura_reporter -o=tpkg_var_pnl_vectors_coverage.xml -f=ut_coverage_html_reporter -o=tpkg_var_pnl_vectors_coverage.html -p=ut_test.tpkg_var_pnl_vectors -include=vbo.pkg_var_pnl_vectors
09:59:24.725 [main] DEBUG org.utplsql.cli.Cli - Args: run, ut_test/ut_test_psw@VISDAY_GVA, -d, --failure-exit-code=0, --ora-stuck-timeout=0, -f=ut_xunit_reporter, -o=tpkg_var_pnl_vectors_result.xml, -f=ut_coverage_cobertura_reporter, -o=tpkg_var_pnl_vectors_coverage.xml, -f=ut_coverage_html_reporter, -o=tpkg_var_pnl_vectors_coverage.html, -p=ut_test.tpkg_var_pnl_vectors, -include=vbo.pkg_var_pnl_vectors
2025-02-06 09:59:24 [main] DEBUG org.utplsql.cli.RunAction - Java Locale not changed from LC_ALL or LANG environment variable
2025-02-06 09:59:24 [main] INFO org.utplsql.cli.RunAction - #################### utPLSQL cli ####################
# #
# utPLSQL-cli 3.1.9.local #
# utPLSQL-java-api 3.1.9.local #
# Java-Version: 17 #
# ORACLE_HOME: null #
# NLS_LANG: ENGLISH_UNITED KINGDOM.WE8MSWIN1252 #
# #
# Thanks for testing! #
# #
#####################################################
2025-02-06 09:59:24 [main] INFO org.utplsql.cli.RunAction -
2025-02-06 09:59:25 [main] DEBUG o.u.c.d.TestedDataSourceProvider - NLS settings: BEGIN
EXECUTE IMMEDIATE q'[ALTER SESSION SET NLS_LANGUAGE='ENGLISH']';
EXECUTE IMMEDIATE q'[ALTER SESSION SET NLS_TERRITORY='UNITED KINGDOM']';
END;
2025-02-06 09:59:25 [main] DEBUG o.u.c.d.TestedDataSourceProvider - Try connecting jdbc:oracle:oci8:****/****@VISDAY_GVA
2025-02-06 09:59:25 [main] DEBUG o.u.c.d.TestedDataSourceProvider - Try connecting jdbc:oracle:thin:****/****@VISDAY_GVA
2025-02-06 09:59:27 [main] INFO o.u.c.d.TestedDataSourceProvider - Use connection string jdbc:oracle:thin:****/****@VISDAY_GVA
2025-02-06 09:59:28 [main] INFO org.utplsql.cli.RunAction - Successfully connected to database. UtPLSQL core: v3.1.12.3589
2025-02-06 09:59:28 [main] INFO org.utplsql.cli.RunAction - Oracle-Version: 19.0.0.0.0
2025-02-06 09:59:34 [main] DEBUG org.utplsql.api.reporter.Reporter - Database-reporter initialized, Type: UT_XUNIT_REPORTER, ID: 2D7675E51EF190DCE0640010E0E38394
java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation
at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:509)
at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:461)
at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1104)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:550)
Provide version info Information about utPLSQL and Database version,
UT_VERSION
------------------------------------------------------------
v3.1.12.3589
BANNER BANNER_FULL BANNER_LEGACY CON_ID
-------------------------------------------------------------------------------- -------------------------------------------------------------------------------- -------------------------------------------------------------------------------- ----------
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production 0
Version 19.18.0.0.0
PARAMETER VALUE
------------------------------ ----------------------------------------------------------------
NLS_LANGUAGE AMERICAN
NLS_TERRITORY AMERICA
NLS_CURRENCY $
NLS_ISO_CURRENCY AMERICA
NLS_NUMERIC_CHARACTERS .,
NLS_CALENDAR GREGORIAN
NLS_DATE_FORMAT DD-MON-RR
NLS_DATE_LANGUAGE AMERICAN
NLS_SORT BINARY
NLS_TIME_FORMAT HH.MI.SSXFF AM
NLS_TIMESTAMP_FORMAT DD-MON-RR HH.MI.SSXFF AM
NLS_TIME_TZ_FORMAT HH.MI.SSXFF AM TZR
NLS_TIMESTAMP_TZ_FORMAT DD-MON-RR HH.MI.SSXFF AM TZR
NLS_DUAL_CURRENCY $
NLS_COMP BINARY
NLS_LENGTH_SEMANTICS BYTE
NLS_NCHAR_CONV_EXCP FALSE
17 rows selected
PORT_STRING
------------------------------------------------------------
SVR4-be-64bit-8.1.0
Information about client software Jenkins build step using utplsql-cli version 3.1.9
Expected behavior Initialization of reporter should not failed
Additional case Can fail on any reporter during init: Below another case where HTML reporter failed.
2025-02-06 09:46:26 [main] INFO org.utplsql.cli.RunAction - Oracle-Version: 19.0.0.0.0
2025-02-06 09:46:27 [main] DEBUG org.utplsql.api.reporter.Reporter - Database-reporter initialized, Type: UT_XUNIT_REPORTER, ID: 2D764712AC258155E0640010E0E38394
2025-02-06 09:46:27 [main] DEBUG org.utplsql.api.reporter.Reporter - Database-reporter initialized, Type: UT_COVERAGE_COBERTURA_REPORTER, ID: 2D764712AC298155E0640010E0E38394
2025-02-06 09:46:28 [main] DEBUG org.utplsql.api.reporter.Reporter - Database-reporter initialized, Type: UT_COVERAGE_HTML_REPORTER, ID: 2D764712AC2D8155E0640010E0E38394
java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation
at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:509)
at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:461)
Thanks in advance for your help.
- Please update to latest utPLSQL framework 3.1.14.
- Why do you set the parameter
ora-stuck-timeout=0? - Did you try other values to see if it fails or works?
- Do you face the same issue when running the cli against other DB
- Do you face the same issue when running the cli from localhost against the same server?
I think that ora-stuck-timeout=0 is the default value of the CLI. Can you try setting it to something like 5 (seconds) and see if it helps ? The documentation does not say what is the default but looking at pull request I see it is 0. Also documentation is confusing to me as no-timout could be interpreted az timeout immediately or wait forever. So a better description of parameter is needed. I assume that 0 - timeout immediately
I tried the parameter ora-stuck-timeout=0 because I found the explanation in previous bug (https://github.com/utPLSQL/utPLSQL-cli/issues/191)
I tried several values : 0, 2, 200 But issue occurs randomly.
Our unit tests runs on daily basis on different databases, I noticed the problem on several DB.
I tried to balance the workload on additional DBs and on a wider period of time but no effect.
I will see to run cli from another computer. In the meantime I asked to double the memory of my server.
After upgrading to the latest version of the API + increase of memory of server, I still have the issue. I have it less frequently but between 5 and 10 jobs are failing due to this error.
About the error
java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation
Do you see this error immediately after the job is started or is it that the job is hanging for some time and then it dies?
Did you check for any network issues or configuration that could cause it?
Error occurs immediately, no hanging.
I exclude network issue because we have all our unit tests running between 8am and 10am then we have up to 5 jenkins jobs running in parallel connected on same database and fortunately when error occurs that does not impact all the jobs that are running.
To be honest it's pretty hard to diagnose this if it only occurs sometimes and in specific env.
One think That I saw randomly occur on Jenkins some time ago was a connection lapse exception , but this was a different problem and a different behaviuor.
https://github.com/utPLSQL/utPLSQL-cli/issues/191#issuecomment-768409344