Skip to content

Connecting to Autonomous DB from linux fails when providing wallet #148

New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

#

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Jump to bottom
Closed
ChaosEngine opened this issue Feb 26, 2021 · 4 comments
Closed

Connecting to Autonomous DB from linux fails when providing wallet #148

ChaosEngine opened this issue Feb 26, 2021 · 4 comments

Comments

@ChaosEngine
Copy link

ChaosEngine commented Feb 26, 2021 •
edited
Loading

When providing wallet directory (and necessary credentials and settings) creating ODP.NET connection fails. On Windows same code runs ok.
I've created a repro here: https://github.com/ChaosEngine/dotnet-db-samples/tree/autonomous-linux-fail/samples/dotnet-core/autonomous-db/console with guidance applied from here: #59

In my autonomous-linux-fail branch for reproducing the issue I've created 21c Oracle ADB (always free) and downloaded wallet zip.
Then it was unzipped with content placed inside console/wallet directory. I've also enabled tracing and which is placed inside console/traces directory.
I've run the linux-x64 code both in ubuntu (with dotnet5) and from inside alpine container (mcr.microsoft.com/dotnet/sdk:5.0-alpine3.13 image.

The output of this trivial console example gives:

$ dotnet run
Connection request timed out

I've tried various combinations of tnsnames.ora, wallet locations inside code and other options for ODP.NET OracleConnection.

For what it's wort in tracing I can see this


2021-02-26 18:38:16.265582 TID:1   (CFG) (TNSNAMES) FilePath : wallet/tnsnames.ora
.....
2021-02-26 18:38:16.269375 TID:1   (PRI) (.NET) (sqlnet.ora) Searching for 'wallet/sqlnet.ora' : found!
2021-02-26 18:38:16.270354 TID:1   (CFG) (SQLNET)   SSL_SERVER_DN_MATCH : yes
2021-02-26 18:38:16.270400 TID:1   (PRI) (.NET) (ldap.ora) Searching for 'wallet/ldap.ora' : not found
2021-02-26 18:38:16.274032 TID:1   (PRI) (ENT) (CP) OracleConnectionDispenser..cctor()
2021-02-26 18:38:16.275041 TID:1   (PRI) (EXT) (CP) OracleConnectionDispenser..cctor()
2021-02-26 18:38:16.275072 TID:1   (PRI) (ENT) (CP) OracleConnectionDispenser.Get()
2021-02-26 18:38:16.278756 TID:1   (PRI) (ENT) (CP) PoolManager.ctor()
2021-02-26 18:38:16.280405 TID:1   (PRI) (EXT) (CP) PoolManager.ctor()
2021-02-26 18:38:16.282257 TID:1   (PRI) (ENT) (CP) PoolManager.Initialize() (constr=User Id=ADMIN;Password=;Data Source=dataplayground_low;)
2021-02-26 18:38:16.282965 TID:1   (PRI) (EXT) (CP) PoolManager.Initialize() (pmid=43942917) (constr=User Id=ADMIN;Password=;Data Source=dataplayground_low;)
2021-02-26 18:38:16.286520 TID:1   (PRI) (BUF) (OBP.CTOR) (poolid:59941933) (OracleConnectionDispenser`3.GetPM)
2021-02-26 18:38:16.291651 TID:1   (PRI) (ENT) (CP) OraclePoolManager.Get()
2021-02-26 18:38:16.484823 TID:1   (PRI) (ENT) (CP) PoolManager.Get() (txnid=n/a) (bForceMatch=F)
2021-02-26 18:38:16.485832 TID:1   (PRI) (ENT) (CP) PoolManager.Get() MultiTenant : Searching for a idle connection, retryCountWithoutAffinity: 0
2021-02-26 18:38:16.486514 TID:1   (PRI) (ENT) PoolManager.ProcessCriteriaCtx_NonEnlistedConnection()
2021-02-26 18:38:16.486545 TID:1   (PRI) (EXT) PoolManager.ProcessCriteriaCtx_NonEnlistedConnection()
2021-02-26 18:38:16.572470 TID:1   (PRI) (ENT) (CP) PoolManager.CreateNewPR() (txnid=n/a) 
2021-02-26 18:38:31.599928 TID:1   (PRI) (CP) PoolManager.CreateNewPR() (DUMP)
(CP) =================================
(CP) User Id=ADMIN;Password=;Data Source=dataplayground_low;
(CP) pmid=
43942917(CP) =================================

2021-02-26 18:38:31.600853 TID:1   (PRI) (ENT) OracleException.ctor()
2021-02-26 18:38:31.601383 TID:1   (PRI) (ENT) OracleError.ctor()
2021-02-26 18:38:31.601710 TID:1   (PRI) (EXT) OracleError.ctor()
2021-02-26 18:38:31.601729 TID:1   (PRI) (ENT) OracleError.ctor()
2021-02-26 18:38:31.601736 TID:1   (PRI) (EXT) OracleError.ctor()

Seems like it can find all necessary params, but this missing ldap.ora is specifically peculiar :/

The very same code runs ok from within windows without any wallet files changed and run from console and VS2019.

If needed I can provide full trace files.
@alexkeh
Copy link
Member

alexkeh commented Feb 26, 2021

@ChaosEngine
Can you add "Connection Timeout=300" to your connection string and run it again? The connection timeout is currently too low before the error root cause can manifest itself.

My suspicion is inability to find the wallet. If you get an error, you can send the trace to us at dotnet_us(at)oracle.com.

@ChaosEngine
Copy link
Author

Ok, now it shows something in the area of SSL handshake:

2021-02-26 22:01:28.675391 TID:1   (PRI) (.NET) (sqlnet.ora) Searching for 'wallet/sqlnet.ora' : found!^M
2021-02-26 22:01:28.675536 TID:1   (CFG) (SQLNET)   SSL_SERVER_DN_MATCH : yes^M
2021-02-26 22:01:28.675585 TID:1   (PRI) (.NET) (ldap.ora) Searching for 'wallet/ldap.ora' : not found^M
2021-02-26 22:01:28.678369 TID:1   (PRI) (ENT) (CP) OracleConnectionDispenser..cctor()^M
2021-02-26 22:01:28.679127 TID:1   (PRI) (EXT) (CP) OracleConnectionDispenser..cctor()^M
2021-02-26 22:01:28.679153 TID:1   (PRI) (ENT) (CP) OracleConnectionDispenser.Get()^M
2021-02-26 22:01:28.682062 TID:1   (PRI) (ENT) (CP) PoolManager.ctor()^M
2021-02-26 22:01:28.683323 TID:1   (PRI) (EXT) (CP) PoolManager.ctor()^M
2021-02-26 22:01:28.684758 TID:1   (PRI) (ENT) (CP) PoolManager.Initialize() (constr=User Id=ADMIN;Password=;Data Source=dataplayground_low;Connection Timeout=300)^M
2021-02-26 22:01:28.685386 TID:1   (PRI) (EXT) (CP) PoolManager.Initialize() (pmid=43942917) (constr=User Id=ADMIN;Password=;Data Source=dataplayground_low;Connection Timeout=300)^M
2021-02-26 22:01:28.686485 TID:1   (PRI) (BUF) (OBP.CTOR) (poolid:59941933) (OracleConnectionDispenser`3.GetPM)^M
2021-02-26 22:01:28.690474 TID:1   (PRI) (ENT) (CP) OraclePoolManager.Get()^M
2021-02-26 22:01:28.794653 TID:1   (PRI) (ENT) (CP) PoolManager.Get() (txnid=n/a) (bForceMatch=F)^M
2021-02-26 22:01:28.795093 TID:1   (PRI) (ENT) (CP) PoolManager.Get() MultiTenant : Searching for a idle connection, retryCountWithoutAffinity: 0^M
2021-02-26 22:01:28.795622 TID:1   (PRI) (ENT) PoolManager.ProcessCriteriaCtx_NonEnlistedConnection()^M
2021-02-26 22:01:28.795646 TID:1   (PRI) (EXT) PoolManager.ProcessCriteriaCtx_NonEnlistedConnection()^M
2021-02-26 22:01:28.802427 TID:1   (PRI) (ENT) (CP) PoolManager.CreateNewPR() (txnid=n/a) ^M
2021-02-26 22:02:31.982635 TID:1   (PRI) (ENT) PoolManager.CreateNewPR()^M
2021-02-26 22:02:31.982986 TID:1   (PRI) (ERR) (CP) PoolManager.CreateNewPR() (txnid=n/a) Oracle.ManagedDataAccess.Client.OracleException (0x80004005): ORA-00542: Failure during SSL handshake
 ---> OracleInternal.Network.NetworkException (0x80004005): ORA-00542: Failure during SSL handshake
 ---> System.Security.Authentication.AuthenticationException: Authentication failed, see inner exception.
 ---> Interop+OpenSsl+SslException: SSL Handshake failed with OpenSSL error - SSL_ERROR_SSL.
 ---> Interop+Crypto+OpenSslCryptographicException: error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure
   --- End of inner exception stack trace ---
   at Interop.OpenSsl.DoSslHandshake(SafeSslHandle context, ReadOnlySpan`1 input, Byte[]& sendBuf, Int32& sendCount)
   at System.Net.Security.SslStreamPal.HandshakeInternal(SafeFreeCredentials credential, SafeDeleteSslContext& context, ReadOnlySpan`1 inputBuffer, Byte[]& outputBuffer, SslAuthenticationOptions sslAuthenticationOptions)
   --- End of inner exception stack trace ---
   at System.Net.Security.SslStream.ForceAuthenticationAsync[TIOAdapter](TIOAdapter adapter, Boolean receiveFirst, Byte[] reAuthenticationData, Boolean isApm)
   at System.Net.Security.SslStream.ProcessAuthentication(Boolean isAsync, Boolean isApm, CancellationToken cancellationToken)
   at System.Net.Security.SslStream.AuthenticateAsClient(SslClientAuthenticationOptions sslClientAuthenticationOptions)
   at OracleInternal.Network.TcpsTransportAdapter.Negotiate(ConnectionOption conOption)
   at OracleInternal.Network.OracleCommunication.DoConnect(String tnsDescriptor)
   at OracleInternal.Network.OracleCommunication.Connect(String tnsDescriptor, Boolean doNAHandshake, String IName, ConnectionOption CO)
   at OracleInternal.ServiceObjects.OracleConnectionImpl.Connect(ConnectionString cs, Boolean bOpenEndUserSession, OracleConnection connRefForCriteria, String instanceName)
   at OracleInternal.ConnectionPool.PoolManager`3.CreateNewPR(Int32 reqCount, Boolean bForPoolPopulation, ConnectionString csWithDiffOrNewPwd, OracleConnection connRefForCriteria, String instanceName, List`1 switchFailedInstNames)^M
2021-02-26 22:02:31.983027 TID:1   (PRI) (EXT) PoolManager.CreateNewPR()^M
2021-02-26 22:02:31.983242 TID:1   (PRI) (EXT) (CP) PoolManager.CreateNewPR() (aff=n/a) (inst=) (affmatch=n/a) (pr.service=) (pr.pdb=) (pr.edition=) (sessid=-1:-1) (F;F;F;;N) (pmid=43942917) ^M

and of course visibly failing with:
ORA-00542: Failure during SSL handshake

I think it founds the wallet though.

@alexkeh
Copy link
Member

alexkeh commented Feb 27, 2021

@ChaosEngine

We can reproduce this error.

Are you using Ubuntu 20.04? If so, you may be hitting the same issue we're seeing, which has this workaround.

Another way to workaround the issue is to downgrade to .NET Core 3.1.

I believe .NET 5 is requiring the use of TLS 1.3 here for Ubuntu. ADB uses TLS 1.2 currently.

@ChaosEngine
Copy link
Author

Yes,! this fixes things. So it is related to SSL. @alexkeh thank you for quick response and tests :-)

# for free to join this conversation on GitHub. Already have an account? # to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ChaosEngine @alexkeh