Skip to content

UTPLSQL CLI Error: Detected Oracle driver stuck during Statement initialization after 4 retries and Erro #191

Closed
Closed
UTPLSQL CLI Error: Detected Oracle driver stuck during Statement initialization after 4 retries and Erro#191

Description

@venkat-kasula
venkat-kasula
opened on Jan 27, 2021

Describe the bug
Hi All,
I m using the AWS RDS oracle instance currently for trying out the UTPLSQL POC demo.
When i m trying out in the UTPLSQL CLI, using command "utplsql run /@host:1521/ORCL -p=venkat.ut_add_contestant -f=ut_coverage_html_reporter -o=run.log -s -f=ut_coverage_html_reporter -o=coverage1.html"
while generating report, my execution is terminated after 4 retries. I m getting error as "Detected Oracle driver stuck during Statement initialization
WARNING: Caught Oracle stuck during creation of Runner-Statement. Retrying (1)"


`Use connection string jdbc:oracle:oci8:****/****@10.114.97.90:1521/ORCL
Successfully connected to database. UtPLSQL core: v3.1.10.3349
Oracle-Version: 18.0.0.0.0
Running tests now.
--------------------------------------
TestRunner initialized
Running on utPLSQL v3.1.10.3349
Initializing reporters
Detected Oracle driver stuck during Statement initialization
WARNING: Caught Oracle stuck during creation of Runner-Statement. Retrying (1)
############################## utPLSQL cli ##############################
#                                                                       #
#   utPLSQL-cli 3.1.8-SNAPSHOT.local                                    #
#   utPLSQL-java-api 3.1.8.546                                          #
#   Java-Version: 1.8.0_121                                             #
#   ORACLE_HOME: C:\Users\a622231\Pictures\SQLPLUS\instantclient_19_9   #
#   NLS_LANG: null                                                      #
#                                                                       #
#   Thanks for testing!                                                 #
#                                                                       #
#########################################################################

Use connection string jdbc:oracle:oci8:****/****@host:1521/ORCL
Successfully connected to database. UtPLSQL core: v3.1.10.3349
Oracle-Version: 18.0.0.0.0
Running tests now.
--------------------------------------
TestRunner initialized
Running on utPLSQL v3.1.10.3349
Initializing reporters
Detected Oracle driver stuck during Statement initialization
WARNING: Caught Oracle stuck during creation of Runner-Statement. Retrying (2)`

**Provide version info**

>  utPLSQL-cli 3.1.8-SNAPSHOT.local                                    #
> #   utPLSQL-java-api 3.1.8.546                                          #
> #   Java-Version: 1.8.0_121                                             #
> #   ORACLE_HOME: C:\Users\a622231\Pictures\SQLPLUS\instantclient_19_9   #
> #   NLS_LANG: null                                                      #
> #                                                                       #
> #   Thanks for testing!

Information about client software
I m using the UTPLSQL CLI for execution and using odjbc8.jar and orai18n.jar 19.9.0.0

Kindly help me in resolving the issue.

Activity

  1. pesse commented on Jan 27, 2021

    @pesse
    pesse
    on Jan 27, 2021
    Member

    Seems like there is a general problem with Oracle on AWS.
    This is very hard to test, because I don't have an Oracle on AWS instance.

    #145

  2. PhilippSalvisberg commented on Jan 27, 2021

    @PhilippSalvisberg
    PhilippSalvisberg
    on Jan 27, 2021
    Member

    @pesse I don't think it's a general AWS related issue. I have a customer who's using the utPLSQL CLI connecting to AWS instances. No issues AFAIK.

  3. pesse commented on Jan 27, 2021

    @pesse
    pesse
    on Jan 27, 2021
    Member

    Thanks for that information. Can you reach out to them and ask for their combination of jdbc driver/java version etc?

  4. PhilippSalvisberg commented on Jan 27, 2021

    @PhilippSalvisberg
    PhilippSalvisberg
    on Jan 27, 2021
    Member

    I can find out next week. Will update this issue then.

  5. jgebal commented on Jan 27, 2021

    @jgebal
    jgebal
    on Jan 27, 2021
    Member

    I've seen similar issues in AWS and we managed to get around them.
    It's related to java and connection security I think.
    Not sure if this is exactly same issue but can you try those solutions?
    https://stackoverflow.com/a/49775784

  6. pesse commented on Jan 27, 2021

    @pesse
    pesse
    on Jan 27, 2021
    Member

    Oh, this is an awesome hint, @jgebal !
    A timeout is exactly what's happening, we are just aborting after 2 seconds.

    @venkat-kasula can you access the file $JAVA_HOME/jre/lib/security/java.security and change securerandom.source=file:/dev/random to securerandom.source=file:/dev/urandom?

    Alternatively it should be possible to pass the necessary JVM arguments with setting the following environment variable:

    export JAVA_TOOL_OPTIONS='-Djava.security.egd=file:/dev/./urandom -Dsecurerandom.source=file:/dev/./urandom'

  7. jgebal commented on Jan 27, 2021

    @jgebal
    jgebal
    on Jan 27, 2021
    Member

    The error we saw was:

    Caused by: java.sql.SQLException: Unable to start the Universal Connection Pool: oracle.ucp.UniversalConnectionPoolException: Cannot get Connection from Datasource: java.sql.SQLRecoverableException: IO Error: Connection reset by peer, Authentication lapse 185481 ms.

  8. pesse commented on Jan 27, 2021

    @pesse
    pesse
    on Jan 27, 2021
    Member

    This kind of error would result in the "Detected Oracle driver stuck" generic error in CLI, because we abort the connection before we hit the timeout.

  9. venkat-kasula commented on Jan 28, 2021

    @venkat-kasula
    venkat-kasula
    on Jan 28, 2021
    Author

    I tried to add a User env variable JAVA_TOOL_OPTIONS and tried to re-exeute.

    i did face below issue

    2021-01-28 15:29:06 [main] INFO  org.utplsql.cli.RunAction -
2021-01-28 15:29:13 [main] INFO  o.u.c.d.TestedDataSourceProvider - Use connection string jdbc:oracle:oci8:****/****@10.114.97.90:1521/ORCL
2021-01-28 15:29:18 [main] INFO  org.utplsql.cli.RunAction - Successfully connected to database. UtPLSQL core: v3.1.10.3349
2021-01-28 15:29:19 [main] INFO  org.utplsql.cli.RunAction - Oracle-Version: 18.0.0.0.0
2021-01-28 15:30:49 [main] DEBUG org.utplsql.api.reporter.Reporter - Database-reporter initialized, Type: UT_COVERAGE_HTML_REPORTER, ID: B9F3F5BFBF7B0958E0530100007F432E
java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation

        at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:1168)
        at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:1065)
        at oracle.jdbc.driver.T2CCallableStatement.executeForDescribe(T2CCallableStatement.java:764)
        at oracle.jdbc.driver.T2CCallableStatement.executeForRows(T2CCallableStatement.java:1007)
        at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1205)
        at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3666)
        at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3778)
        at oracle.jdbc.driver.OracleCallableStatement.execute(OracleCallableStatement.java:4251)
        at oracle.jdbc.driver.OraclePreparedStatementWrapper.execute(OraclePreparedStatementWrapper.java:1081)
        at org.utplsql.api.outputBuffer.OutputBufferProvider.hasOutput(OutputBufferProvider.java:67)
        at org.utplsql.api.outputBuffer.OutputBufferProvider.getCompatibleOutputBuffer(OutputBufferProvider.java:33)
        at org.utplsql.api.compatibility.CompatibilityProxy.getOutputBuffer(CompatibilityProxy.java:187)
        at org.utplsql.api.reporter.DefaultReporter.initOutputBuffer(DefaultReporter.java:21)
        at org.utplsql.api.reporter.Reporter.init(Reporter.java:50)
        at org.utplsql.cli.reporters.LocalAssetsCoverageHTMLReporter.init(LocalAssetsCoverageHTMLReporter.java:30)
        at org.utplsql.cli.ReporterManager.initReporters(ReporterManager.java:95)
        at org.utplsql.cli.RunAction.initReporters(RunAction.java:219)
        at org.utplsql.cli.RunAction.doRun(RunAction.java:70)
        at org.utplsql.cli.RunAction.run(RunAction.java:121)
        at org.utplsql.cli.RunPicocliCommand.run(RunPicocliCommand.java:254)
        at org.utplsql.cli.Cli.runPicocliWithExitCode(Cli.java:44)
        at org.utplsql.cli.Cli.main(Cli.java:13)
Caused by: Error : 1013, Position : 0, Sql = declare    l_result int;begin    begin        execute immediate '       begin            :x := case ' || dbms_assert.simple_sql_name( :1  ) || '() is of (ut_output_reporter_base) when true then 1 else 0 end;       end;'       using out l_result;   end;   :2  := l_result;end;, OriginalSql = declare    l_result int;begin    begin        execute immediate '       begin            :x := case ' || dbms_assert.simple_sql_name( ? ) || '() is of (ut_output_reporter_base) when true then 1 else 0 end;       end;'       using out l_result;   end;   ? := l_result;end;, Error Msg = ORA-01013: user requested cancel of current operation

        at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:1181)
        ... 21 more

  10. pesse commented on Jan 28, 2021

    @pesse
    pesse
    on Jan 28, 2021
    Member

    Did you try it with a different (non-coverage) reporter?
    Also - there should be a message of JVM picking up the JAVA_TOOL_OPTIONS values...

  11. venkat-kasula commented on Jan 28, 2021

    @venkat-kasula
    venkat-kasula
    on Jan 28, 2021
    Author

    i did not try with any other non - coverage reporter tool . Any specific report you want to run and verify???

    After setting up the Variable, i ran in debug mode and shared the complete log here. But one thing i observed is it did not go into retry loop 4 times. That's the difference i observed when i executed after setting up the JAVA_TOOL_OPTIONS.

  12. pesse commented on Jan 28, 2021

    @pesse
    pesse
    on Jan 28, 2021
    Member

    UT_DOCUMENTATION_REPORTER would be a good start

    utplsql run /@host:1521/ORCL -p=venkat.ut_add_contestant -f=ut_documentation_reporter -o=run.log -s

  13. venkat-kasula commented on Jan 28, 2021

    @venkat-kasula
    venkat-kasula
    on Jan 28, 2021
    Author

    I tried and got below connection error.

    Picked up JAVA_TOOL_OPTIONS: -Djava.security.egd=file:/dev/./urandom -Dsecurerandom.source=file:/dev/./urandom
############################## utPLSQL cli ##############################
#                                                                       #
#   utPLSQL-cli 3.1.8-SNAPSHOT.local                                    #
#   utPLSQL-java-api 3.1.8.546                                          #
#   Java-Version: 1.8.0_121                                             #
#   ORACLE_HOME: C:\Users\a622231\Pictures\SQLPLUS\instantclient_19_9   #
#   NLS_LANG: null                                                      #
#                                                                       #
#   Thanks for testing!                                                 #
#                                                                       #
#########################################################################

jdbc:oracle:oci8:****/****@host:1521/ORCL: ORA-12546: TNS:permission denied

`jdbc:oracle:thin:****/****@10.114.97.90:1521/ORCL:` IO Error: The Network Adapter could not establish the connection
Could not establish connection to database. Reason: IO Error: The Network Adapter could not establish the connection``

  14. pesse commented on Jan 28, 2021

    @pesse
    pesse
    on Jan 28, 2021
    Member

    ORACLE_HOME: C:\Users\a622231\Pictures\SQLPLUS\instantclient_19_9

    That doesn't look like it's running on a linux system 🤔

  15. venkat-kasula commented on Jan 28, 2021

    @venkat-kasula
    venkat-kasula
    on Jan 28, 2021
    Author

    i m using windows machine to run it on my local.. is this is the issue ?

  16. 10 remaining items

  17. pesse
    transferred this issue fromutPLSQL/utPLSQLon Feb 4, 2021

  18. venkat-kasula commented on Feb 4, 2021

    @venkat-kasula
    venkat-kasula
    on Feb 4, 2021
    Author

    @pesse Sure, once done committing, please do let me know, so that i can try again and share the result

  19. francisco-palma-m commented on May 19, 2022

    @francisco-palma-m
    francisco-palma-m
    on May 19, 2022

    Hi.
    I reproduce randomly this problem against AWS server. I reproduce this using both utPLSQL-cli and utplsql-maven-plugin.

    I have found that TestRunner.initStatementWithTimeout method in utPLSQL-java-api has a hardcoded timeout of 2 seconds.

    If I increase the timeout, the problem dissapears and all works right.

    Could I parameterize that timeout and open a pull-request?

  20. jgebal commented on May 19, 2022

    @jgebal
    jgebal
    on May 19, 2022
    Member

    Absolutely!

  21. walker99 commented on May 24, 2022

    @walker99
    walker99
    on May 24, 2022

    Works fine for me too! :-)
    Thank you.

  22. srinivasaprabhu-java commented on Jun 8, 2022

    @srinivasaprabhu-java
    srinivasaprabhu-java
    on Jun 8, 2022

    Is there any update on this issue . We are also facing the same issue of time out. The solution what ever is given of changing the parameter TestRunner.initStatementWithTimeout to more than 2 , we could not do as it is a jar file java-api. Where do we give this value ?

  23. jgebal commented on Jun 8, 2022

    @jgebal
    jgebal
    on Jun 8, 2022
    Member

    @pesse - is there a chance to make a new release of cli and java-api, where we:L

    • increase default timeout
    • make the timeout a parameter

  24. francisco-palma-m commented on Jun 8, 2022

    @francisco-palma-m
    francisco-palma-m
    on Jun 8, 2022

    @pesse - is there a chance to make a new release of cli and java-api, where we:L

    • increase default timeout
    • make the timeout a parameter

    I'm on it

  25. pesse commented on Jun 8, 2022

    @pesse
    pesse
    on Jun 8, 2022
    Member

    I will work on java-api and cli tonight, trying to create a new Release.

    The timeout was originally introduced to work around a problem with Oracle 11g. I will leave it in, but as an opt-in option via parameter (where you can also set the time).
    New Default-behaviour will be without that timeout.

    @francisco-palma-m sorry if that interrupts your efforts. If you'd like to, it would be awesome if you could step into development of java-api and cli, since my focus and time budget keep being very limited.

  26. francisco-palma-m commented on Jun 8, 2022

    @francisco-palma-m
    francisco-palma-m
    on Jun 8, 2022

    I will work on java-api and cli tonight, trying to create a new Release.

    The timeout was originally introduced to work around a problem with Oracle 11g. I will leave it in, but as an opt-in option via parameter (where you can also set the time). New Default-behaviour will be without that timeout.

    @francisco-palma-m sorry if that interrupts your efforts. If you'd like to, it would be awesome if you could step into development of java-api and cli, since my focus and time budget keep being very limited.

    Ok. No problem, but it's necessary create a new release on utplsql-maven-plugin that use the new timeout parameter.

  27. pesse commented on Jun 8, 2022

    @pesse
    pesse
    on Jun 8, 2022
    Member

    Ok. No problem, but it's necessary create a new release on utplsql-maven-plugin that use the new timeout parameter.

    @francisco-palma-m can you take care of the maven-plugin after I change java-api?

  28. francisco-palma-m commented on Jun 8, 2022

    @francisco-palma-m
    francisco-palma-m
    on Jun 8, 2022

    Ok. No problem, but it's necessary create a new release on utplsql-maven-plugin that use the new timeout parameter.

    @francisco-palma-m can you take care of the maven-plugin after I change java-api?

    @pesse Of course

  29. pesse
    added a commit that references this issue on Jun 8, 2022

    New parameter --ora-stuck-timeout

    322a3f0
  30. pesse
    closed this as completedin 322a3f0on Jun 9, 2022

  31. srinivasaprabhu-java commented on Jun 11, 2022

    @srinivasaprabhu-java
    srinivasaprabhu-java
    on Jun 11, 2022

    Thanks for the release . the timeout issue is gone now .

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions