lovetodream
commented
5 months ago Thanks for reporting this, can you provide a repro? And are using the latest version of oracle-nio (just to make sure 😀)
Closed iliasaz closed 4 months ago
lovetodream
commented
5 months ago Thanks for reporting this, can you provide a repro? And are using the latest version of oracle-nio (just to make sure 😀)
iliasaz
commented
5 months ago I don't have a solid repro at the moment. It'd been running fine for about 2 weeks before it crashed all of a sudden. I'll see if I can reproduce it in an isolated standalone setting. And yes - it was the latest version as of 2 weeks back.
lovetodream
commented
4 months ago Did you find a repro? If not, are you still facing the issue in your app?
iliasaz
commented
4 months ago Yes, I did create a reproducible test case. Here is it.
func loadTLSConfigurationFromWallet(walletPath: String, walletPassword: String) throws -> TLSConfiguration? {
let privateKey = try NIOSSLPrivateKey(file: walletPath, format: .pem) { completion in
completion(walletPassword.utf8)
}
// This was the missing piece in my config. It's needed to validate the full certificate path.
let certificate = try NIOSSLCertificate(file: ProcessInfo.processInfo.environment["ORA_WALLET"] ?? "ewallet.pem", format: .pem)
var tlsConfig = TLSConfiguration.makeClientConfiguration()
tlsConfig.privateKey = NIOSSLPrivateKeySource.privateKey(privateKey)
tlsConfig.certificateChain = [.certificate(certificate)]
return tlsConfig
}
func createOracleClient() throws -> OracleClient? {
var logger = Logger(label: "oracle-logger")
logger.logLevel = .debug
// get TLS config
guard let tlsConfig = try loadTLSConfigurationFromWallet(
walletPath: ProcessInfo.processInfo.environment["ORA_WALLET"] ?? "ewallet.pem",
walletPassword: ProcessInfo.processInfo.environment["ORA_WALLET_PASSWORD"] ?? "password"
) else {
logger.debug("got nil TLS Configuration")
return nil
}
logger.debug("got TLS configuration")
let config = try OracleConnection.Configuration(
host: ProcessInfo.processInfo.environment["ORA_HOST"] ?? "localhost",
port: ProcessInfo.processInfo.environment["ORA_PORT"].flatMap(Int.init(_:)) ?? 1521,
service: .serviceName(ProcessInfo.processInfo.environment["ORA_SERVICE"] ?? "orcl"),
username: ProcessInfo.processInfo.environment["ORA_USERNAME"] ?? "scott",
password: ProcessInfo.processInfo.environment["ORA_PASSWORD"] ?? "tiger",
tls: .require(.init(configuration: tlsConfig)) // important!
)
logger.debug("created config: \(config)")
// setting pool options
var options = OracleClient.Options()
options.minimumConnections = 1
options.maximumConnections = 10
// create and return a client object that has a connection pool in it
let client = OracleClient(configuration: config, options: options, backgroundLogger: logger)
logger.debug("created OracleClient")
return client
}
class Pool {
var oraClient: OracleClient
init() throws {
do {
if let oraClient = try createOracleClient() {
self.oraClient = oraClient
// start Oracle connection pool and the client task
Task {
await self.oraClient.run()
}
print("started conn pool")
} else {
fatalError("Oracle Client not configured")
}
} catch {
fatalError("Error configuring Oracle Client: \(error)")
}
}
func testSQL() async throws {
try await oraClient.withConnection { conn in
print("got connection")
let rows = try await conn.query("SELECT count(*) FROM user_objects")
for try await row in rows {
print(row)
}
print("connection is working")
}
}
func runloop() async throws {
while( true ) {
let secondsWait: Int64 = 30
try await Task.sleep(for: Duration(secondsComponent: secondsWait, attosecondsComponent: 0))
print("mark \(secondsWait) wait")
}
}
}
let pool = try Pool()
try await pool.testSQL()
try await pool.runloop()First set the env variables with the proper DB credentials, wallet, and etc. Then run the program. It will connect to the DB and execute a simple query. Then it just waits and marks 30 second intervals. You'll also see ping pong traffic in the log.
2024-05-28T14:24:28-0700 debug oracle-logger : [oranio_test_cmd] got TLS configuration
2024-05-28T14:24:28-0700 debug oracle-logger : [oranio_test_cmd] created config: Configuration(options: OracleNIO.OracleConnection.Configuration.Options(connectTimeout: NIOCore.TimeAmount(nanoseconds: 10000000000), tlsServerName: nil), host: "adb.us-ashburn-1.oraclecloud.com", port: 1522, tls: OracleNIO.OracleConnection.Configuration.TLS(base: OracleNIO.OracleConnection.Configuration.TLS.Base.require(NIOSSL.NIOSSLContext)), proxyUser: nil, authenticationMethod: (Function), service: OracleNIO.OracleServiceMethod.serviceName("ge045b813707f2d_omoprwd1m_tp.adb.oraclecloud.com"), mode: DEFAULT, disableOOB: false, debugJDWP: nil, customTimezone: nil, _connectionIDPrefix: "", connectionID: "", _programName: "oranio-test-cmd", _machineName: "mbp3ora.local", pid: 21900, _processUsername: "ilia", _terminalName: "unknown", purity: DEFAULT, serverType: nil, drcpEnabled: false, cclass: nil)
2024-05-28T14:24:28-0700 debug oracle-logger : [oranio_test_cmd] created OracleClient
started conn pool
2024-05-28T14:24:28-0700 debug oracle-logger : oraclesql_connection_id=0 [OracleNIO] Creating new connection
got connection
OracleRow(lookupTable: ["COUNT(*)": 0], data: OracleNIO.DataRow(columnCount: 1, bytes: ByteBuffer { readerIndex: 0, writerIndex: 3, readableBytes: 3, capacity: 4, storageCapacity: 4, slice: _ByteBufferSlice { 0..<4 }, storage: 0x0000600001ab4440 (4 bytes) }
readable bytes (max 1k): [ 02 c1 02 ]), columns: [OracleNIO.DescribeInfo.Column(name: "COUNT(*)", dataType: OracleNIO.OracleDataType(key: 2, number: OracleNIO.OracleDataTypeNumber(backing: OracleNIO.OracleDataTypeNumber.Backing.number), name: "DB_TYPE_NUMBER", oracleName: "NUMBER", _oracleType: Optional(NUMBER), defaultSize: 0, csfrm: 0, bufferSizeFactor: 22), dataTypeSize: 0, precision: 0, scale: 0, bufferSize: 22, nullsAllowed: true)])
connection is working
mark 30 wait
2024-05-28T14:24:59-0700 debug oracle-logger : oraclesql_connection_id=0 [OracleNIO] run ping pongNow simulate 100% packet loss using Network Link Conditioner or any other tool. Here is what I see in the log after enabling the total packet loss. The first ping pong packet shows as a success although the network is already dysfunctional, which is a bug. Then the crash occurs.
mark 30 wait
2024-05-28T14:27:30-0700 debug oracle-logger : oraclesql_connection_id=0 [OracleNIO] run ping pong
nw_socket_handle_socket_event [C1.1.1:1] Socket SO_ERROR [60: Operation timed out]
nw_read_request_report [C1] Receive failed with error "Operation timed out"
nw_protocol_socket_reset_linger [C1.1.1:1] setsockopt SO_LINGER failed [22: Invalid argument]
2024-05-28T14:28:04-0700 debug oracle-logger : oraclesql_connection_id=0 oraclesql_error=POSIXErrorCode(rawValue: 60): Operation timed out [OracleNIO] Channel error caught.
2024-05-28T14:28:04-0700 debug oracle-logger : oraclesql_connection_id=0 oraclesql_error=OracleSQLError(code: connectionError, underlying: POSIXErrorCode(rawValue: 60): Operation timed out) [OracleNIO] Cleaning up and closing connection.
nw_flow_service_writes [C1 147.154.27.228:1522 failed parent-flow (satisfied (Path is satisfied), interface: en0[802.11], ipv4, dns, uses wifi)] No output handler
2024-05-28T14:28:04-0700 debug oracle-logger : oraclesql_connection_id=0 oraclesql_error=POSIXErrorCode(rawValue: 60): Operation timed out [OracleNIO] Channel error caught.
2024-05-28T14:28:04-0700 debug oracle-logger : oraclesql_connection_id=0 oraclesql_error=uncleanShutdown [OracleNIO] Channel error caught.
2024-05-28T14:28:04-0700 debug oracle-logger : oraclesql_connection_id=0 [OracleNIO] Connection closedHere is Xcode debug screenshot at the point of the crash.
Hope this is helpful.
Thanks!
lovetodream
commented
4 months ago Thanks for the repro, it's extremely helpful. I've identified the cause, there's some testing to do and then I'll release a fix in the upcoming days.
lovetodream
commented
4 months ago The issue should be fixed with the latest release. Thanks again for reporting and taking the time to find a repro.
Hi,
There seems to be an issue with handling a failed ping that leads to a crash. Here are the details from my app log. There was no activity on the connection apart from the ping pong.
Thanks!