GeezerVison is showing github.com — Wrong rollback warnings in utPLSQL Development Environment · Issue #982 · utPLSQL/utPLSQL
Wrong rollback warnings in utPLSQL Development Environment #982DescriptionDescribe the bug
When I refresh my utpPLSQL development environment I get the following test result:
Warnings:
1) utplsql.ut3_tester.core
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
2) utplsql
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
Finished in 84.704215 seconds
888 tests, 0 failed, 0 errored, 5 disabled, 2 warning(s)
But when I rerun the tests I do not get this warnings again.
What am I doing wrong?
Provide version info
Information about utPLSQL and Database version,
19.0.0.0.0
19.0.0
PL/SQL procedure successfully completed.
UT_VERSION
------------------------------------------------------------
v3.1.8.3169-develop
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.2.0.0.0
PARAMETER VALUE
------------------------------ ----------------------------------------------------------------
NLS_LANGUAGE ENGLISH
NLS_TERRITORY SWITZERLAND
NLS_CURRENCY SFr.
NLS_ISO_CURRENCY SWITZERLAND
NLS_NUMERIC_CHARACTERS .'
NLS_CALENDAR GREGORIAN
NLS_DATE_FORMAT DD.MM.YYYY HH24:MI:SS
NLS_DATE_LANGUAGE ENGLISH
NLS_SORT BINARY
NLS_TIME_FORMAT HH24:MI:SSXFF
NLS_TIMESTAMP_FORMAT DD.MM.RR HH24:MI:SSXFF
PARAMETER VALUE
------------------------------ ----------------------------------------------------------------
NLS_TIME_TZ_FORMAT HH24:MI:SSXFF TZR
NLS_TIMESTAMP_TZ_FORMAT DD.MM.RR HH24:MI:SSXFF TZR
NLS_DUAL_CURRENCY SF
NLS_COMP BINARY
NLS_LENGTH_SEMANTICS BYTE
NLS_NCHAR_CONV_EXCP FALSE
17 rows selected.
PORT_STRING
------------------------------------------------------------
x86_64/Linux 2.4.xx
Information about client software
UTPLSQL_CLI_VERSION="3.1.6" (as configured in the current develop branch)
To Reproduce
- Refresh develop branch via git
- Run the following (excerpt of a shell script)
# local cloned utPLSQL repository, is different in your environment
cd /Users/phs/github/utPLSQL
git fetch --all
chmod +x development/*.sh
chmod +x test/*.sh
chmod +x .travis/*.sh
# configuring connection for my database for utPLSQL development
echo "export CONNECTION_STR=127.0.0.1:1521/odb.docker" >> development/env.sh
. development/env.sh
development/cleanup.sh
development/refresh_ut3.sh
development/refresh_sources.sh
# copying JARs which must not be distributed from my local SQLcl installation
cp /usr/local/bin/sqlcl/lib/ojdbc8.jar utPLSQL-cli/lib
cp /usr/local/bin/sqlcl/lib/orai*.jar utPLSQL-cli/lib
development/install.sh
test/install_and_run_tests.sh
then the results contains unexpected warnings:
Warnings:
1) utplsql.ut3_tester.core
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
2) utplsql
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
Finished in 84.704215 seconds
888 tests, 0 failed, 0 errored, 5 disabled, 2 warning(s)
- Rerun the tests
cd test
time . ./${DIR}/run_tests.sh
then the result is as expected:
Finished in 62.915066 seconds
888 tests, 0 failed, 0 errored, 5 disabled, 0 warning(s)
Expected behavior
I expect the results of the subsequent runs also in the first run. Activityjgebal commented on Aug 4, 2019 This is something I've encountered several times when running self-tests with utPLSQL.
I didn't manage to get to the bottom of the problem though as it is not deterministic and only happens "sometimes".
I couldn't figure out what could be causing inconsistent transaction invalidation in the test-run. PhilippSalvisberg commented on Nov 6, 2019 Just a short note, that I can reproduce this error at will.
It always happens when install utPLSQL. I've just installed the current develop branch and got the following result:
Running tests finished.
Warnings:
1) utplsql.ut3_tester.core
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
2) utplsql
Unable to perform automatic rollback after test suite. An implicit or explicit commit/rollback occurred in procedures:
Use the "--%rollback(manual)" annotation or remove commit/rollback/ddl statements that are causing the issue.
Finished in 77.456744 seconds
903 tests, 0 failed, 0 errored, 5 disabled, 2 warning(s)
I run the following script:
START_TIME=${SECONDS}
cd /Users/phs/github/utPLSQL
git fetch --all
git pull
chmod +x development/*.sh
chmod +x test/*.sh
chmod +x .travis/*.sh
. development/env.sh
development/cleanup.sh
development/refresh_ut3.sh
development/refresh_sources.sh
development/install.sh
test/install_and_run_tests.sh
ELAPSED_TIME=$((${SECONDS}-${START_TIME}))
echo ut3 for dev installed in ${ELAPSED_TIME} seconds.
and my development/env.sh looks as follows:
#!/usr/bin/env bash
export SQLCLI=sql # For sqlcl client
export ORACLE_PWD=oracle # Adjust your local SYS password
export UTPLSQL_CLI_VERSION="3.1.8"
export SELFTESTING_BRANCH=develop
export UTPLSQL_DIR="utPLSQL_latest_release"
export UT3_OWNER=ut3
export UT3_OWNER_PASSWORD=ut3
export UT3_RELEASE_VERSION_SCHEMA=ut3_latest_release
export UT3_RELEASE_VERSION_SCHEMA_PASSWORD=ut3
export UT3_TESTER=ut3_tester
export UT3_TESTER_PASSWORD=ut3
export UT3_USER=ut3\$user#
export UT3_USER_PASSWORT=ut3
export UT3_TESTER_HELPER=ut3_tester_helper
export UT3_TESTER_HELPER_PASSWORD=ut3
export UT3_TABLESPACE=users
export UT3_USER="UT3\$USER#"
export UT3_USER_PASSWORD=ut3
export CONNECTION_STR=127.0.0.1:1521/odb.docker
PhilippSalvisberg commented on Nov 6, 2019 and after the failure, I can run
test/install_and_run_tests.sh
and then the result is
Running tests finished.
Finished in 66.452462 seconds
903 tests, 0 failed, 0 errored, 5 disabled, 0 warning(s)
Looks like the condition for the very first run is different and that is causing the error. jgebal commented on Nov 6, 2019 I am able to reproduce it locally too.
Though in my case I didn't use your approach.
Install on clean FB caused the same issue.
When I re-install isdue no longer appears.
I will do some debugging to chase it down.
It's not critical but annnoing. PhilippSalvisberg commented on Nov 6, 2019 I agree, this is low priority.
Since I updated my local installation and got this warnings again, I checked the status of this issue. And then I saw your comment about this not being "deterministic" (somehow I missed that previously). Hence, I thought it is important to point out, that it is reproducible. It has to be a bug. Either in the framework or its test suites. added a commit that references this issue on Nov 30, 2019This issue will close once commit 39d144a is merged into the 'develop' branch.39d144a jgebal commented on Nov 30, 2019 After some debugging I've found the problem, though it seems like Oracle issue.
We currently use a database sequence ut_savepoint_seq to get a savepoint name.
The sequence works fine and the savepoints get established at right moments.
Seems that for some reason, with a newly created sequence the savepoints get "damaged" and transaction cannot rollback.
The issue we both saw was occuring for the very first two savepoints in the run (SEQ_NO=1 and SEQNO = 1).
See attached file: test_results-problem.log
A change from sequence to a timestamp made it go away and I can no longer reproduce the issue
I'm not sure if there is an Oracle bug for it.
If you want @PhilippSalvisberg you can dig a bit deeper to see if it can be distilled into reproducible test-case for Oracle to investigate.
For now I'll change from sequence to timestamp by replacing line
from:
return 's'||trim(to_char(ut_savepoint_seq.nextval,'0000000000000000000000000000'));
to:
return 's'||to_char(systimestamp,'yyyymmddhh24missff9'); Reacted by Philipp Salvisberg PhilippSalvisberg commented on Nov 30, 2019 I had a deeper look while reviewing #1027 .
It is not an Oracle bug. It's a bug of the utPLSQL test setup. It's a namespace clash between the ut3 and the ut3_latest_release schema. Both schemas own a sequence named ut_savepoint_seq. During test execution both sequences are used to generate savepoint names within the very same Oracle session. This leads to these warnings... after the initial run difference in the sequence numbers is large enough to not cause this warnings on subsequent runs.
I can reproduce it by running this with this script:
connect ut3_latest_release/XNtxj8eEgA6X6b6f@odb190
alter sequence ut_savepoint_seq restart;
connect ut3/ut3@odb190
alter sequence ut_savepoint_seq restart;
connect ut3_tester_helper/ut3@odb190
set serveroutput on size unlimited
begin
ut.run('ut3_tester');
end;
/
A simple fix is to use the owner of the PL/SQL package in the name of the savepoint. Changing the package function ut_utils.gen_savepoint_name to something like this:
function gen_savepoint_name return varchar2 is
begin
return 's' || $$plsql_unit_owner || trim(to_char(ut_savepoint_seq.nextval));
end;
After that change I do not get these warnings anymore. jgebal commented on Nov 30, 2019 Thanks for digging @PhilippSalvisberg
It never occured to me that this could be causing the issue.
I agree that making sure savepoint-name is unique within session is important.
To your point on not using timestamp...
Is it really possible to have 2 savepoints created within single session (thread) in interval < 1microsecond?
Not sure if any OS gives miliseconds only.
The challenge with appending username is the lenght limit on savepoint name.
Even UUID is too long .. PhilippSalvisberg commented on Nov 30, 2019 Actually my OS delivers only microseconds:
SQL> select to_char(systimestamp,'DD.MM.YYYY HH24:MI:SS.FF9') from dual;
TO_CHAR(SYSTIMESTAMP,'DD.MM.Y
-----------------------------
30.11.2019 16:09:10.876105000
The last 3 digits are always zero.
I do not think it is a real problem using a timestamp. I just stated that I do not like to rely on slow processing.
Regarding the naming restriction. 30 bytes is valid for 11.2 and 12.1. Both versions are end of live. We can write the code in a way to use the 128 bytes. We can even define the sequence using the CYCLE clause. In fact, we do not need a large range. The range must just be large enough to cover a single Oracle session. Typically one test run. So 9-12 digits should be really enough. The rest can be the user name limited to 15-18 chars (in Oracle Database versions < 12.2). added a commit that references this issue on Nov 30, 2019This issue will close once commit 4bb7a95 is merged into the 'develop' branch.4bb7a95
MetadataMetadataDevelopmentNo branches or pull requestsIssue actions
|