search

go-goracle / goracle

Go database/sql driver for connecting to Oracle Database, using the ODPI-C library
273 stars 43 forks source link

Cancelling a query context leaks sessions #174

Closed hego-fdc closed 5 years ago

hego-fdc commented 5 years ago

Describe the bug Cancelling the context of a sql.QueryContext does not seem to return the session of the query to the session pool.

To Reproduce I've written a program that reproduces the problem: It creates ten queries and cancels their context in a loop. Since we limit the session pool to 20 sessions, it will at some point slow down and run into the error: error:acquirePoolConnection: ORA-24496: OCISessionGet() timed out waiting for a free connection.

package main

import (
    "context"
    "database/sql"
    _ "gopkg.in/goracle.v2"
    "log"
    "sync"
    "time"
)

type loadCreator struct {
    cancelled int
    errored   int
    completed int
    lock      sync.Mutex
    wg        sync.WaitGroup
}

func (c *loadCreator) queryRow(ctx context.Context, db *sql.DB) {
    defer c.wg.Done()
    rows, err := db.QueryContext(ctx, ".....") // insert some long running query here
    c.lock.Lock()
    defer c.lock.Unlock()
    if err != nil {
        if err == context.Canceled {
            c.cancelled++
            return
        }
        c.errored++
        log.Print("error:", err)
        return
    }
    defer rows.Close()
    c.completed++
}

func (c *loadCreator) run(ctx context.Context, db *sql.DB, num int) {
    nctx, cancel := context.WithCancel(ctx)
    c.wg.Add(num)
    for i := 0; i < num; i++ {
        go c.queryRow(nctx, db)
    }
    time.Sleep(5 * time.Millisecond)
    cancel()
    c.wg.Wait()
}

func main() {
    db, err := sql.Open("goracle", "oracle://USER:PW@//HOST/INSTANCE?poolMaxSessions=20")
    if err != nil {
        log.Fatal("could not connect to database:", err)
    }
    db.SetMaxOpenConns(1)
    ctx := context.Background()
    for i := 0; ; i++ {
        var c loadCreator
        c.run(ctx, db, 10)
        log.Printf("%d completed: %d, cancelled: %d, errored: %d\n", i, c.completed, c.cancelled, c.errored)
    }
}

Expected behavior No error being returned and the program running without blocking.

Your oracle client version Both 12.2.0.1.0 and 18.3.0.0.0 have been tried

Your goracle version 2.16.3

Your go version 1.12.4

Your gcc version 8.3.0

Machine (please complete the following information):

tgulacsi commented 5 years ago

Oracle is not fast - you have to wait longer - see b1c330b.

--- PASS: TestCancel (11.26s)
    z_test.go:2111: Before: 11
    z_test.go:2121: After: 20
    z_test.go:2130: After 0s: 20
    z_test.go:2130: After 1s: 20
    z_test.go:2130: After 2s: 21
    z_test.go:2130: After 3s: 21
    z_test.go:2130: After 4s: 21
    z_test.go:2130: After 5s: 12
PASS

So on Oracle side, the sessions are closed. Maybe on the Go side, the connections are not put back to the pool?

hego-fdc commented 5 years ago

When I added a 5 second delay into the main loop, the problem still occured, albeit a bit later. Even with 10 seconds of delay, it still happens eventually.

tgulacsi commented 5 years ago

Please help understand the problem. If I put a testDb.SetMaxOpenConns(2), then I get

$ go test -run=Cancel$ -v
Server: 19.3.0.0.0 [Oracle Database 19c Standard Edition 2 Release 19.0.0.0.0 - Production
Version 19.3.0.0.0]
Client: 18.3.0.0.0
=== RUN   TestCancel
--- PASS: TestCancel (11.79s)
    z_test.go:2115: Before: 8
    z_test.go:2125: After: 9
    z_test.go:2134: After 0s: 10
    z_test.go:2134: After 1s: 10
    z_test.go:2134: After 2s: 11
    z_test.go:2134: After 3s: 11
    z_test.go:2134: After 4s: 11
    z_test.go:2134: After 5s: 9
PASS
ok      gopkg.in/goracle.v2     12.500s
hego-fdc commented 5 years ago

Sorry, I had to bother our database admin to give me permissions for the v$session and dbms_lock tables.

When I run the test on my machine, it finishes even faster than for you:

Server: 11.2.0.4.0 [Oracle Database 11g Release 11.2.0.4.0 - 64bit Production]
Client: 18.3.0.0.0
=== RUN   TestCancel
--- PASS: TestCancel (10.07s)
    z_test.go:2118: Pid: 28559
    z_test.go:2122: Before: 1
    z_test.go:2132: After: 1
    z_test.go:2140: After 0s: 1
PASS

However, when I increase the delay before canceling from 5ms to 100ms in line 2125, I get:

Server: 11.2.0.4.0 [Oracle Database 11g Release 11.2.0.4.0 - 64bit Production]
Client: 18.3.0.0.0
=== RUN   TestCancel
--- FAIL: TestCancel (30.42s)
    z_test.go:2118: Pid: 28800
    z_test.go:2122: Before: 1
    z_test.go:2132: After: 1
    z_test.go:2140: After 0s: 2
    z_test.go:2140: After 1s: 6
    z_test.go:2140: After 2s: 6
[...]
    z_test.go:2140: After 28s: 6
    z_test.go:2140: After 29s: 6
    z_test.go:2147: cancelation timed out
FAIL

This happens with and without a connection limit.

tgulacsi commented 5 years ago

A simple DBMS_LOCK.SLEEP is not enough - it's easily interruptible and does not consume a cursor. I've updated TestCancel, but that shows an even more peculiar behaviour: After starting 10 concurrent queries, v$session shows zero of them; after canceling and waiting a little bit, it shows 4. After waiting more, it shows 10.

So, it seems now I see what you've reported here, but sorry, I cannot make an explanation...

! ODPI_DEBUG_LEVEL=28 go test -run=Cancel$ -v
Server: 11.2.0.4.0 [Oracle Database 11g Release 11.2.0.4.0 - 64bit Production]
Client: 18.3.0.0.0
=== RUN   TestCancel
--- FAIL: TestCancel (30.84s)
    z_test.go:2124: Pid: 25796
    z_test.go:2128: Before: 2
    z_test.go:2148: After exec, before cancel: 2
    z_test.go:2150: After cancel: 2
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 0s: 2
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 1s: 9
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 2s: 10
    z_test.go:2156: After 3s: 10
    z_test.go:2156: After 4s: 10
    z_test.go:2156: After 5s: 10
    z_test.go:2156: After 6s: 10
    z_test.go:2156: After 7s: 10
    z_test.go:2156: After 8s: 10
    z_test.go:2156: After 9s: 10
    z_test.go:2156: After 10s: 10
    z_test.go:2156: After 11s: 10
    z_test.go:2156: After 12s: 10
    z_test.go:2156: After 13s: 10
    z_test.go:2156: After 14s: 10
    z_test.go:2156: After 15s: 10
    z_test.go:2156: After 16s: 10
    z_test.go:2156: After 17s: 10
    z_test.go:2156: After 18s: 10
    z_test.go:2156: After 19s: 10
    z_test.go:2156: After 20s: 10
    z_test.go:2156: After 21s: 10
    z_test.go:2156: After 22s: 10
    z_test.go:2156: After 23s: 10
    z_test.go:2156: After 24s: 10
    z_test.go:2156: After 25s: 10
    z_test.go:2156: After 26s: 10
    z_test.go:2156: After 27s: 10
    z_test.go:2156: After 28s: 10
    z_test.go:2156: After 29s: 10
    z_test.go:2162: cancelation timed out
FAIL
exit status 1
FAIL    gopkg.in/goracle.v2     31.047s
:tgulacsi@tgulacsi-dell: ~/src/gopkg.in/goracle.v2
! DPI_DEBUG_LEVEL=28 go test -run=Cancel$ -v
ODPI [26347] 2019-07-01 15:59:11.925: ODPI-C 3.1.4
ODPI [26347] 2019-07-01 15:59:11.925: debugging messages initialized at level 28
ODPI [26347] 2019-07-01 15:59:11.926: fn start dpiContext_create
ODPI [26347] 2019-07-01 15:59:11.933: fn end dpiContext_create -> 0
ODPI [26347] 2019-07-01 15:59:11.933: fn start dpiContext_getClientVersion(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:11.933: fn end dpiContext_getClientVersion(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:11.933: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:11.933: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:11.933: fn start dpiContext_initCommonCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:11.933: fn end dpiContext_initCommonCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:11.933: fn start dpiContext_initPoolCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:11.933: fn end dpiContext_initPoolCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:11.933: fn start dpiPool_create(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.101: fn end dpiPool_create(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.101: fn start dpiPool_setStmtCacheSize(0xdceca0)
ODPI [26347] 2019-07-01 15:59:12.101: fn end dpiPool_setStmtCacheSize(0xdceca0) -> 0
ODPI [26347] 2019-07-01 15:59:12.101: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.101: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.101: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.101: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.101: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26347] 2019-07-01 15:59:12.101: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26347] 2019-07-01 15:59:12.101: fn start dpiConn_getServerVersion(0xe6b6f0)
ODPI [26347] 2019-07-01 15:59:12.115: fn end dpiConn_getServerVersion(0xe6b6f0) -> 0
ODPI [26347] 2019-07-01 15:59:12.117: fn start dpiConn_prepareStmt(0xe6b6f0)
ODPI [26347] 2019-07-01 15:59:12.117: SQL SELECT DBTIMEZONE FROM DUAL
ODPI [26347] 2019-07-01 15:59:12.117: fn end dpiConn_prepareStmt(0xe6b6f0) -> 0
ODPI [26350] 2019-07-01 15:59:12.117: fn start dpiConn_setCallTimeout(0xe6b6f0)
ODPI [26350] 2019-07-01 15:59:12.118: fn end dpiConn_setCallTimeout(0xe6b6f0) -> 0
ODPI [26350] 2019-07-01 15:59:12.118: fn start dpiStmt_execute(0xe6b9a0)
ODPI [26350] 2019-07-01 15:59:12.131: fn end dpiStmt_execute(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_setFetchArraySize(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_setFetchArraySize(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_getQueryInfo(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_getQueryInfo(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiConn_newVar(0xe6b6f0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiConn_newVar(0xe6b6f0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_define(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_define(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_addRef(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_addRef(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_fetchRows(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_fetchRows(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiVar_release(0xe6ba50)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiVar_release(0xe6ba50) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_release(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_release(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_getInfo(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_getInfo(0xe6b9a0) -> 0
ODPI [26347] 2019-07-01 15:59:12.132: fn start dpiStmt_release(0xe6b9a0)
ODPI [26347] 2019-07-01 15:59:12.132: fn end dpiStmt_release(0xe6b9a0) -> 0
Server: 11.2.0.4.0 [Oracle Database 11g Release 11.2.0.4.0 - 64bit Production]
Client: 18.3.0.0.0
=== RUN   TestCancel
ODPI [26347] 2019-07-01 15:59:12.134: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.134: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.134: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.134: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.134: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26347] 2019-07-01 15:59:12.279: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26347] 2019-07-01 15:59:12.279: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.279: SQL SET TRANSACTION READ ONLY
ODPI [26347] 2019-07-01 15:59:12.279: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.279: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.279: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.279: fn start dpiStmt_execute(0xe95220)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_execute(0xe95220) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiStmt_getInfo(0xe95220)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_getInfo(0xe95220) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiStmt_getRowCount(0xe95220)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_getRowCount(0xe95220) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiStmt_getInfo(0xe95220)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_getInfo(0xe95220) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiStmt_release(0xe95220)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_release(0xe95220) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.293: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiStmt_getBindCount(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.293: fn end dpiStmt_getBindCount(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.293: fn start dpiConn_newVar(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.294: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.294: fn start dpiStmt_bindByPos(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.294: fn end dpiStmt_bindByPos(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.294: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.294: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.294: fn start dpiStmt_execute(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_execute(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiStmt_setFetchArraySize(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_setFetchArraySize(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiStmt_getQueryInfo(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_getQueryInfo(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiConn_newVar(0xe6bb10)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiStmt_define(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_define(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiStmt_addRef(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_addRef(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.307: fn start dpiStmt_fetchRows(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.307: fn end dpiStmt_fetchRows(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiVar_release(0xea6b80)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiVar_release(0xea6b80) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiStmt_release(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiStmt_release(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiVar_release(0xe95df0)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiVar_release(0xe95df0) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiStmt_getInfo(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiStmt_getInfo(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiStmt_release(0xe95d40)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiStmt_release(0xe95d40) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.308: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26349] 2019-07-01 15:59:12.308: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26347] 2019-07-01 15:59:12.308: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26349] 2019-07-01 15:59:12.309: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26350] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26350] 2019-07-01 15:59:12.309: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26350] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26350] 2019-07-01 15:59:12.309: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26355] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26356] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26357] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26349] 2019-07-01 15:59:12.309: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26350] 2019-07-01 15:59:12.310: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26349] 2019-07-01 15:59:12.310: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26355] 2019-07-01 15:59:12.310: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26356] 2019-07-01 15:59:12.310: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26349] 2019-07-01 15:59:12.311: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26357] 2019-07-01 15:59:12.311: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26357] 2019-07-01 15:59:12.311: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26357] 2019-07-01 15:59:12.311: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26357] 2019-07-01 15:59:12.311: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26359] 2019-07-01 15:59:12.311: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26356] 2019-07-01 15:59:12.311: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26355] 2019-07-01 15:59:12.312: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:12.312: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26356] 2019-07-01 15:59:12.312: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26359] 2019-07-01 15:59:12.313: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26355] 2019-07-01 15:59:12.313: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26356] 2019-07-01 15:59:12.313: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26361] 2019-07-01 15:59:12.313: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26359] 2019-07-01 15:59:12.313: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26359] 2019-07-01 15:59:12.313: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26360] 2019-07-01 15:59:12.313: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26361] 2019-07-01 15:59:12.313: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26359] 2019-07-01 15:59:12.313: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26361] 2019-07-01 15:59:12.313: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26360] 2019-07-01 15:59:12.313: fn start dpiContext_initConnCreateParams(0xd9d2b0)
ODPI [26360] 2019-07-01 15:59:12.313: fn end dpiContext_initConnCreateParams(0xd9d2b0) -> 0
ODPI [26360] 2019-07-01 15:59:12.313: fn start dpiPool_acquireConnection(0xdceca0)
ODPI [26355] 2019-07-01 15:59:12.318: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.318: fn start dpiStmt_getBindCount(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.318: fn end dpiStmt_getBindCount(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.318: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.318: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.318: fn start dpiStmt_bindByPos(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.319: fn end dpiStmt_bindByPos(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.319: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.319: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.319: fn start dpiStmt_execute(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_execute(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_setFetchArraySize(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_setFetchArraySize(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_getQueryInfo(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_getQueryInfo(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_define(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_define(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_addRef(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_addRef(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_fetchRows(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiStmt_fetchRows(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiVar_release(0x7fd67c041ef0)
ODPI [26355] 2019-07-01 15:59:12.331: fn end dpiVar_release(0x7fd67c041ef0) -> 0
ODPI [26355] 2019-07-01 15:59:12.331: fn start dpiStmt_release(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiStmt_release(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiVar_release(0x7fd67c041850)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiVar_release(0x7fd67c041850) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiStmt_getInfo(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiStmt_getInfo(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiStmt_release(0x7fd67c00dc70)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiStmt_release(0x7fd67c00dc70) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.332: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiStmt_getBindCount(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiStmt_getBindCount(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiStmt_bindByPos(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiStmt_bindByPos(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.332: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.332: fn start dpiStmt_execute(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.345: fn end dpiStmt_execute(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.345: fn start dpiStmt_setFetchArraySize(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.345: fn end dpiStmt_setFetchArraySize(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.345: fn start dpiStmt_getQueryInfo(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.345: fn end dpiStmt_getQueryInfo(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_define(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_define(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_addRef(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_addRef(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_fetchRows(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_fetchRows(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiVar_release(0x7fd67c0422d0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiVar_release(0x7fd67c0422d0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_release(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_release(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiVar_release(0x7fd67c042060)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiVar_release(0x7fd67c042060) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_getInfo(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_getInfo(0x7fd67c041fb0) -> 0
ODPI [26355] 2019-07-01 15:59:12.346: fn start dpiStmt_release(0x7fd67c041fb0)
ODPI [26355] 2019-07-01 15:59:12.346: fn end dpiStmt_release(0x7fd67c041fb0) -> 0
ODPI [26347] 2019-07-01 15:59:12.453: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26350] 2019-07-01 15:59:12.691: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26349] 2019-07-01 15:59:13.037: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:13.347: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:13.347: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiStmt_getBindCount(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.347: fn end dpiStmt_getBindCount(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:13.347: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiStmt_bindByPos(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.347: fn end dpiStmt_bindByPos(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:13.347: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:13.347: fn start dpiStmt_execute(0x7fd67c042390)
ODPI [26356] 2019-07-01 15:59:13.362: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_execute(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_setFetchArraySize(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_setFetchArraySize(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_getQueryInfo(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_getQueryInfo(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_define(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_define(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_addRef(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_addRef(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_fetchRows(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_fetchRows(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiVar_release(0x7fd67c0426b0)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiVar_release(0x7fd67c0426b0) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_release(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiStmt_release(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiVar_release(0x7fd67c042440)
ODPI [26355] 2019-07-01 15:59:13.378: fn end dpiVar_release(0x7fd67c042440) -> 0
ODPI [26355] 2019-07-01 15:59:13.378: fn start dpiStmt_getInfo(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.379: fn end dpiStmt_getInfo(0x7fd67c042390) -> 0
ODPI [26355] 2019-07-01 15:59:13.379: fn start dpiStmt_release(0x7fd67c042390)
ODPI [26355] 2019-07-01 15:59:13.379: fn end dpiStmt_release(0x7fd67c042390) -> 0
ODPI [26360] 2019-07-01 15:59:13.517: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26357] 2019-07-01 15:59:13.647: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26361] 2019-07-01 15:59:13.788: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26361] 2019-07-01 15:59:13.788: fn start dpiConn_release(0x7fd65800dc10)
ODPI [26361] 2019-07-01 15:59:13.788: fn end dpiConn_release(0x7fd65800dc10) -> 0
ODPI [26359] 2019-07-01 15:59:13.924: fn end dpiPool_acquireConnection(0xdceca0) -> 0
ODPI [26359] 2019-07-01 15:59:13.924: fn start dpiConn_release(0x7fd66000daa0)
ODPI [26359] 2019-07-01 15:59:13.924: fn end dpiConn_release(0x7fd66000daa0) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:14.379: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:14.379: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiStmt_getBindCount(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.379: fn end dpiStmt_getBindCount(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:14.379: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiStmt_bindByPos(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.379: fn end dpiStmt_bindByPos(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:14.379: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:14.379: fn start dpiStmt_execute(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_execute(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiStmt_setFetchArraySize(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_setFetchArraySize(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiStmt_getQueryInfo(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_getQueryInfo(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiStmt_define(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_define(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiStmt_addRef(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_addRef(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.396: fn start dpiStmt_fetchRows(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.396: fn end dpiStmt_fetchRows(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.397: fn start dpiVar_release(0x7fd65806a0a0)
ODPI [26361] 2019-07-01 15:59:14.397: fn end dpiVar_release(0x7fd65806a0a0) -> 0
ODPI [26361] 2019-07-01 15:59:14.397: fn start dpiStmt_release(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.397: fn end dpiStmt_release(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.397: fn start dpiVar_release(0x7fd658060210)
ODPI [26361] 2019-07-01 15:59:14.397: fn end dpiVar_release(0x7fd658060210) -> 0
ODPI [26361] 2019-07-01 15:59:14.397: fn start dpiStmt_getInfo(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.397: fn end dpiStmt_getInfo(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:14.397: fn start dpiStmt_release(0x7fd65804b650)
ODPI [26361] 2019-07-01 15:59:14.397: fn end dpiStmt_release(0x7fd65804b650) -> 0
ODPI [26361] 2019-07-01 15:59:15.397: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:15.397: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:15.397: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:15.398: fn start dpiStmt_getBindCount(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.398: fn end dpiStmt_getBindCount(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.398: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:15.398: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:15.398: fn start dpiStmt_bindByPos(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.398: fn end dpiStmt_bindByPos(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.398: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:15.398: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:15.398: fn start dpiStmt_execute(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_execute(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_setFetchArraySize(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_setFetchArraySize(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_getQueryInfo(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_getQueryInfo(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_define(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_define(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_addRef(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_addRef(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_fetchRows(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_fetchRows(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiVar_release(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiVar_release(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_release(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_release(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiVar_release(0x7fd6580741b0)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiVar_release(0x7fd6580741b0) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_getInfo(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.420: fn end dpiStmt_getInfo(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:15.420: fn start dpiStmt_release(0x7fd65806a160)
ODPI [26361] 2019-07-01 15:59:15.421: fn end dpiStmt_release(0x7fd65806a160) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:16.421: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:16.421: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiStmt_getBindCount(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.421: fn end dpiStmt_getBindCount(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:16.421: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiStmt_bindByPos(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.421: fn end dpiStmt_bindByPos(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:16.421: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:16.421: fn start dpiStmt_execute(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiStmt_execute(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.436: fn start dpiStmt_setFetchArraySize(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiStmt_setFetchArraySize(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.436: fn start dpiStmt_getQueryInfo(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiStmt_getQueryInfo(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.436: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:16.436: fn start dpiStmt_define(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiStmt_define(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.436: fn start dpiStmt_addRef(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.436: fn end dpiStmt_addRef(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiStmt_fetchRows(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiStmt_fetchRows(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiVar_release(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiVar_release(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiStmt_release(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiStmt_release(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiVar_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiVar_release(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiStmt_getInfo(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiStmt_getInfo(0x7fd658074380) -> 0
ODPI [26361] 2019-07-01 15:59:16.437: fn start dpiStmt_release(0x7fd658074380)
ODPI [26361] 2019-07-01 15:59:16.437: fn end dpiStmt_release(0x7fd658074380) -> 0
ODPI [26359] 2019-07-01 15:59:17.437: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26359] 2019-07-01 15:59:17.437: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26359] 2019-07-01 15:59:17.438: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26359] 2019-07-01 15:59:17.438: fn start dpiStmt_getBindCount(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.438: fn end dpiStmt_getBindCount(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.438: fn start dpiConn_newVar(0xe6bb10)
ODPI [26359] 2019-07-01 15:59:17.438: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26359] 2019-07-01 15:59:17.438: fn start dpiStmt_bindByPos(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.438: fn end dpiStmt_bindByPos(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.438: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26359] 2019-07-01 15:59:17.438: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26359] 2019-07-01 15:59:17.438: fn start dpiStmt_execute(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_execute(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_setFetchArraySize(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_setFetchArraySize(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_getQueryInfo(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_getQueryInfo(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiConn_newVar(0xe6bb10)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_define(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_define(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_addRef(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_addRef(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_fetchRows(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_fetchRows(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiVar_release(0x7fd66006a0c0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiVar_release(0x7fd66006a0c0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiStmt_release(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiStmt_release(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.455: fn start dpiVar_release(0x7fd6600600a0)
ODPI [26359] 2019-07-01 15:59:17.455: fn end dpiVar_release(0x7fd6600600a0) -> 0
ODPI [26359] 2019-07-01 15:59:17.456: fn start dpiStmt_getInfo(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.456: fn end dpiStmt_getInfo(0x7fd66004b4e0) -> 0
ODPI [26359] 2019-07-01 15:59:17.456: fn start dpiStmt_release(0x7fd66004b4e0)
ODPI [26359] 2019-07-01 15:59:17.456: fn end dpiStmt_release(0x7fd66004b4e0) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:18.456: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:18.456: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiStmt_getBindCount(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.456: fn end dpiStmt_getBindCount(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:18.456: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiStmt_bindByPos(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.456: fn end dpiStmt_bindByPos(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:18.456: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:18.456: fn start dpiStmt_execute(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_execute(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_setFetchArraySize(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_setFetchArraySize(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_getQueryInfo(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_getQueryInfo(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_define(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_define(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_addRef(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_addRef(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_fetchRows(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_fetchRows(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiVar_release(0x7fd6580747d0)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiVar_release(0x7fd6580747d0) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_release(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiVar_release(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiVar_release(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_getInfo(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.473: fn end dpiStmt_getInfo(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:18.473: fn start dpiStmt_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:18.474: fn end dpiStmt_release(0x7fd658074430) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:19.474: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26360] 2019-07-01 15:59:19.474: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiStmt_getBindCount(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.474: fn end dpiStmt_getBindCount(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:19.474: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiStmt_bindByPos(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.474: fn end dpiStmt_bindByPos(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:19.474: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:19.474: fn start dpiStmt_execute(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_execute(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_setFetchArraySize(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_setFetchArraySize(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_getQueryInfo(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_getQueryInfo(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_define(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_define(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_addRef(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_addRef(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_fetchRows(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_fetchRows(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiVar_release(0x7fd66406c180)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiVar_release(0x7fd66406c180) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_release(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_release(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiVar_release(0x7fd664062160)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiVar_release(0x7fd664062160) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_getInfo(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_getInfo(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:19.492: fn start dpiStmt_release(0x7fd66404d5a0)
ODPI [26360] 2019-07-01 15:59:19.492: fn end dpiStmt_release(0x7fd66404d5a0) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:20.493: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26360] 2019-07-01 15:59:20.493: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiStmt_getBindCount(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.493: fn end dpiStmt_getBindCount(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:20.493: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiStmt_bindByPos(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.493: fn end dpiStmt_bindByPos(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:20.493: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:20.493: fn start dpiStmt_execute(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_execute(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_setFetchArraySize(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_setFetchArraySize(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_getQueryInfo(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_getQueryInfo(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_define(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_define(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_addRef(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_addRef(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_fetchRows(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_fetchRows(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiVar_release(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiVar_release(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_release(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_release(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiVar_release(0x7fd66406c2f0)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiVar_release(0x7fd66406c2f0) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_getInfo(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_getInfo(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:20.509: fn start dpiStmt_release(0x7fd66406c240)
ODPI [26360] 2019-07-01 15:59:20.509: fn end dpiStmt_release(0x7fd66406c240) -> 0
ODPI [26360] 2019-07-01 15:59:21.509: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:21.509: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26360] 2019-07-01 15:59:21.510: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:21.510: fn start dpiStmt_getBindCount(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.510: fn end dpiStmt_getBindCount(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.510: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:21.510: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:21.510: fn start dpiStmt_bindByPos(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.510: fn end dpiStmt_bindByPos(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.510: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:21.510: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:21.510: fn start dpiStmt_execute(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.528: fn end dpiStmt_execute(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.528: fn start dpiStmt_setFetchArraySize(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.528: fn end dpiStmt_setFetchArraySize(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.528: fn start dpiStmt_getQueryInfo(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.528: fn end dpiStmt_getQueryInfo(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.528: fn start dpiConn_newVar(0xe6bb10)
ODPI [26360] 2019-07-01 15:59:21.528: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26360] 2019-07-01 15:59:21.528: fn start dpiStmt_define(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.528: fn end dpiStmt_define(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.528: fn start dpiStmt_addRef(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiStmt_addRef(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiStmt_fetchRows(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiStmt_fetchRows(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiVar_release(0x7fd664076770)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiVar_release(0x7fd664076770) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiStmt_release(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiStmt_release(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiVar_release(0x7fd664076550)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiVar_release(0x7fd664076550) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiStmt_getInfo(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiStmt_getInfo(0x7fd6640764a0) -> 0
ODPI [26360] 2019-07-01 15:59:21.529: fn start dpiStmt_release(0x7fd6640764a0)
ODPI [26360] 2019-07-01 15:59:21.529: fn end dpiStmt_release(0x7fd6640764a0) -> 0
ODPI [26361] 2019-07-01 15:59:22.529: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:22.529: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:22.529: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:22.530: fn start dpiStmt_getBindCount(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.530: fn end dpiStmt_getBindCount(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.530: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:22.530: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:22.530: fn start dpiStmt_bindByPos(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.530: fn end dpiStmt_bindByPos(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.530: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:22.530: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:22.530: fn start dpiStmt_execute(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_execute(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiStmt_setFetchArraySize(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_setFetchArraySize(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiStmt_getQueryInfo(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_getQueryInfo(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiStmt_define(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_define(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiStmt_addRef(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_addRef(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.557: fn start dpiStmt_fetchRows(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.557: fn end dpiStmt_fetchRows(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.558: fn start dpiVar_release(0x7fd6580748e0)
ODPI [26361] 2019-07-01 15:59:22.558: fn end dpiVar_release(0x7fd6580748e0) -> 0
ODPI [26361] 2019-07-01 15:59:22.558: fn start dpiStmt_release(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.558: fn end dpiStmt_release(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.558: fn start dpiVar_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:22.558: fn end dpiVar_release(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:22.558: fn start dpiStmt_getInfo(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.558: fn end dpiStmt_getInfo(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:22.558: fn start dpiStmt_release(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:22.558: fn end dpiStmt_release(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:23.558: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:23.558: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26361] 2019-07-01 15:59:23.558: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:23.558: fn start dpiStmt_getBindCount(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.558: fn end dpiStmt_getBindCount(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.558: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:23.558: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:23.558: fn start dpiStmt_bindByPos(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.558: fn end dpiStmt_bindByPos(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.558: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:23.558: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:23.559: fn start dpiStmt_execute(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiStmt_execute(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiStmt_setFetchArraySize(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiStmt_setFetchArraySize(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiStmt_getQueryInfo(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiStmt_getQueryInfo(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiConn_newVar(0xe6bb10)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiStmt_define(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiStmt_define(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiStmt_addRef(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.576: fn end dpiStmt_addRef(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.576: fn start dpiStmt_fetchRows(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiStmt_fetchRows(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.577: fn start dpiVar_release(0x7fd6580749f0)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiVar_release(0x7fd6580749f0) -> 0
ODPI [26361] 2019-07-01 15:59:23.577: fn start dpiStmt_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiStmt_release(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.577: fn start dpiVar_release(0x7fd658074600)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiVar_release(0x7fd658074600) -> 0
ODPI [26361] 2019-07-01 15:59:23.577: fn start dpiStmt_getInfo(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiStmt_getInfo(0x7fd658074430) -> 0
ODPI [26361] 2019-07-01 15:59:23.577: fn start dpiStmt_release(0x7fd658074430)
ODPI [26361] 2019-07-01 15:59:23.577: fn end dpiStmt_release(0x7fd658074430) -> 0
ODPI [26355] 2019-07-01 15:59:24.577: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:24.577: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:24.578: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:24.578: fn start dpiStmt_getBindCount(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.578: fn end dpiStmt_getBindCount(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.578: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:24.578: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:24.578: fn start dpiStmt_bindByPos(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.578: fn end dpiStmt_bindByPos(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.578: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:24.578: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:24.578: fn start dpiStmt_execute(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_execute(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiStmt_setFetchArraySize(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_setFetchArraySize(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiStmt_getQueryInfo(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_getQueryInfo(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiStmt_define(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_define(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiStmt_addRef(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_addRef(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiStmt_fetchRows(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.594: fn end dpiStmt_fetchRows(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.594: fn start dpiVar_release(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:24.595: fn end dpiVar_release(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:24.595: fn start dpiStmt_release(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.595: fn end dpiStmt_release(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.595: fn start dpiVar_release(0x7fd67c042820)
ODPI [26355] 2019-07-01 15:59:24.595: fn end dpiVar_release(0x7fd67c042820) -> 0
ODPI [26355] 2019-07-01 15:59:24.595: fn start dpiStmt_getInfo(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.595: fn end dpiStmt_getInfo(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:24.595: fn start dpiStmt_release(0x7fd67c042770)
ODPI [26355] 2019-07-01 15:59:24.595: fn end dpiStmt_release(0x7fd67c042770) -> 0
ODPI [26355] 2019-07-01 15:59:25.595: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:25.595: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:25.595: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:25.595: fn start dpiStmt_getBindCount(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.596: fn end dpiStmt_getBindCount(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.596: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:25.596: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:25.596: fn start dpiStmt_bindByPos(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.596: fn end dpiStmt_bindByPos(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.596: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:25.596: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:25.596: fn start dpiStmt_execute(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_execute(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_setFetchArraySize(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_setFetchArraySize(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_getQueryInfo(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_getQueryInfo(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_define(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_define(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_addRef(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_addRef(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_fetchRows(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_fetchRows(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiStmt_release(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiStmt_release(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.612: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:25.612: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:25.613: fn start dpiStmt_getInfo(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.613: fn end dpiStmt_getInfo(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:25.613: fn start dpiStmt_release(0x7fd67c042a70)
ODPI [26355] 2019-07-01 15:59:25.613: fn end dpiStmt_release(0x7fd67c042a70) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:26.613: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:26.613: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.613: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:26.613: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.613: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:26.613: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:26.613: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiVar_release(0x7fd67c042fe0)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiVar_release(0x7fd67c042fe0) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:26.630: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:26.630: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:27.631: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:27.631: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.631: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:27.631: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.631: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:27.631: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:27.631: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.646: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.646: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.646: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.646: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.646: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.646: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:27.646: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:27.646: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.646: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.646: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiVar_release(0x7fd67c043170)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiVar_release(0x7fd67c043170) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:27.647: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:27.647: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:28.647: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:28.647: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:28.647: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:28.647: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.647: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.647: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:28.647: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:28.648: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.648: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.648: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:28.648: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:28.648: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:28.661: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.661: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:28.662: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:28.662: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:29.662: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:29.662: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.662: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:29.662: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.662: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:29.662: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:29.662: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:29.679: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:29.679: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:30.680: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:30.680: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.680: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:30.680: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.680: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:30.680: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:30.680: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.697: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:30.697: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:30.698: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.698: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:30.698: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:30.698: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:31.698: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:31.698: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.698: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:31.698: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.698: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:31.698: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:31.698: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.716: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.716: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:31.717: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:31.717: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:32.718: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:32.718: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.718: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:32.718: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.718: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:32.718: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:32.718: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.735: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.735: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.735: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.735: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:32.736: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:32.736: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:33.737: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:33.737: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.737: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:33.737: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.737: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:33.737: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:33.737: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.753: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.753: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.753: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.753: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.753: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.753: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:33.753: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:33.753: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.753: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:33.754: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:33.754: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:34.754: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:34.754: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.754: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:34.754: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.754: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:34.754: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:34.754: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:34.769: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:34.769: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:35.770: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:35.770: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.770: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:35.770: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.770: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:35.770: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:35.770: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.790: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.790: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:35.791: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:35.791: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.791: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:35.791: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:35.791: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:36.791: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:36.791: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.791: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:36.791: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.791: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:36.791: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:36.791: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:36.812: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:36.812: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:37.813: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:37.813: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.813: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:37.813: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.813: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:37.813: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:37.813: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.847: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:37.848: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:37.848: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:38.849: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:38.849: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.849: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:38.849: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.849: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:38.849: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:38.849: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.889: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.889: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.889: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:38.889: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.889: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.889: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:38.890: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:38.890: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:39.890: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:39.891: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:39.891: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:39.891: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.891: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.891: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:39.891: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:39.891: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.891: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.891: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:39.891: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:39.891: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:39.935: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.935: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.936: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:39.936: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:39.936: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.936: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:39.936: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:39.936: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:40.936: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:40.936: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiStmt_getBindCount(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.936: fn end dpiStmt_getBindCount(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:40.936: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiStmt_bindByPos(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.936: fn end dpiStmt_bindByPos(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:40.936: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:40.936: fn start dpiStmt_execute(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiStmt_execute(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiStmt_setFetchArraySize(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiStmt_setFetchArraySize(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiStmt_getQueryInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiStmt_getQueryInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiStmt_define(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiStmt_define(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiStmt_addRef(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.953: fn end dpiStmt_addRef(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.953: fn start dpiStmt_fetchRows(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiStmt_fetchRows(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.954: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:40.954: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.954: fn start dpiVar_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiVar_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:40.954: fn start dpiStmt_getInfo(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiStmt_getInfo(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:40.954: fn start dpiStmt_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:40.954: fn end dpiStmt_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiConn_prepareStmt(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:41.955: SQL SELECT COUNT(0) FROM v$session WHERE username = USER AND process = TO_CHAR(:1)
ODPI [26355] 2019-07-01 15:59:41.955: fn end dpiConn_prepareStmt(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiStmt_getBindCount(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.955: fn end dpiStmt_getBindCount(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:41.955: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiStmt_bindByPos(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.955: fn end dpiStmt_bindByPos(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiConn_setCallTimeout(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:41.955: fn end dpiConn_setCallTimeout(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:41.955: fn start dpiStmt_execute(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_execute(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_setFetchArraySize(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_setFetchArraySize(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_getQueryInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_getQueryInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiConn_newVar(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiConn_newVar(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_define(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_define(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_addRef(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_addRef(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_fetchRows(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_fetchRows(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiVar_release(0x7fd67c043300)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiVar_release(0x7fd67c043300) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiVar_release(0x7fd67c042b20)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiVar_release(0x7fd67c042b20) -> 0
ODPI [26355] 2019-07-01 15:59:41.971: fn start dpiStmt_getInfo(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.971: fn end dpiStmt_getInfo(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:41.972: fn start dpiStmt_release(0x7fd67c042d90)
ODPI [26355] 2019-07-01 15:59:41.972: fn end dpiStmt_release(0x7fd67c042d90) -> 0
ODPI [26355] 2019-07-01 15:59:42.972: fn start dpiConn_rollback(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_rollback(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0xe6bb10)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0xe6bb10) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0xea6c40)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0xea6c40) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0x7fd698040bd0)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0x7fd698040bd0) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0x7fd69400dbf0)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0x7fd69400dbf0) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0x7fd67400daa0)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0x7fd67400daa0) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0x7fd66400db30)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0x7fd66400db30) -> 0
ODPI [26355] 2019-07-01 15:59:42.984: fn start dpiConn_release(0x7fd66c00daa0)
ODPI [26355] 2019-07-01 15:59:42.984: fn end dpiConn_release(0x7fd66c00daa0) -> 0
--- FAIL: TestCancel (30.85s)
    z_test.go:2124: Pid: 26347
    z_test.go:2128: Before: 2
    z_test.go:2148: After exec, before cancel: 2
    z_test.go:2150: After cancel: 2
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 0s: 2
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 1s: 6
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2140: BEGIN FOR rows IN (SELECT 1 FROM DUAL) LOOP DBMS_LOCK.SLEEP(10); END LOOP; END;: context canceled
    z_test.go:2156: After 2s: 10
    z_test.go:2156: After 3s: 10
    z_test.go:2156: After 4s: 10
    z_test.go:2156: After 5s: 10
    z_test.go:2156: After 6s: 10
    z_test.go:2156: After 7s: 10
    z_test.go:2156: After 8s: 10
    z_test.go:2156: After 9s: 10
    z_test.go:2156: After 10s: 10
    z_test.go:2156: After 11s: 10
    z_test.go:2156: After 12s: 10
    z_test.go:2156: After 13s: 10
    z_test.go:2156: After 14s: 10
    z_test.go:2156: After 15s: 10
    z_test.go:2156: After 16s: 10
    z_test.go:2156: After 17s: 10
    z_test.go:2156: After 18s: 10
    z_test.go:2156: After 19s: 10
    z_test.go:2156: After 20s: 10
    z_test.go:2156: After 21s: 10
    z_test.go:2156: After 22s: 10
    z_test.go:2156: After 23s: 10
    z_test.go:2156: After 24s: 10
    z_test.go:2156: After 25s: 10
    z_test.go:2156: After 26s: 10
    z_test.go:2156: After 27s: 10
    z_test.go:2156: After 28s: 10
    z_test.go:2156: After 29s: 10
    z_test.go:2162: cancelation timed out
FAIL
exit status 1
FAIL    gopkg.in/goracle.v2     31.064s
ankushgupta84 commented 5 years ago

Was there a fix for the problem?

tgulacsi commented 5 years ago

I see no such problem in any of my production programs... So no, but neither I see a problem.

ankushgupta84 commented 5 years ago

Thanks for your reply

hego-fdc commented 4 years ago

After investigating this issue some more, I've tried to replicate it in plain C on the ODPI level. I noticed that dpiStmt_execute does not terminate when it is canceled using dpiConn_breakExecution. See https://github.com/oracle/odpi/issues/116 for the example. The solution for this seems to be to disable out-of-band breaks, as suggested in the ticket. However, this still does not solve the problem on the goracle level. I believe that lines 392 and 545 in stmt.go should not return driver.ErrBadConn, because the Close function keeps the connection re-usable. I'm not sure what needs to be returned instead, so I didn't make a merge request, but returning any other error actually solved the problem for me.