go-ora icon indicating copy to clipboard operation
go-ora copied to clipboard

ORA-01013 error reproduces again

Open freeNestor opened this issue 8 months ago • 3 comments

I upgraded go-ora recently due to issue #548. My application reproduces this error again after upgrading in production. seems issue is not solved completely. go-ora version: 2.8.17 or 2.8.19 oracle version: 19c

pls try blew sample code to reproduce and run longer, my test results:

# ./test > testnew.log
# grep fail testnew.log
2024-06-20 14:05:31.335920972 +0800 CST ping db failed[count: 506] execdur: 3.299548ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:10:10.38685891 +0800 CST ping db failed[count: 784] execdur: 54.770632ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:18:13.024509272 +0800 CST ping db failed[count: 1265] execdur: 1.554644ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:19:57.386923779 +0800 CST ping db failed[count: 1369] execdur: 2.056954ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:20:29.485044594 +0800 CST ping db failed[count: 1401] execdur: 1.297867ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:25:08.456694193 +0800 CST ping db failed[count: 1679] execdur: 1.881563ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:36:14.982894251 +0800 CST ping db failed[count: 2343] execdur: 2.835757ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:45:10.060514971 +0800 CST ping db failed[count: 2876] execdur: 2.43114ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:50:05.181439867 +0800 CST ping db failed[count: 3170] execdur: 2.501114ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:55:10.293671734 +0800 CST ping db failed[count: 3474] execdur: 2.66867ms, error: query db current time error: ORA-01013: user requested cancel of current operation
2024-06-20 14:59:34.279711608 +0800 CST ping db failed[count: 3737] execdur: 2.051858ms, error: query db current time error: ORA-01013: user requested cancel of current operation

# cat testnew.log |wc -l
144462
# grep fail testnew.log |wc -l
11

reproduce code:

package main

import (
	"context"
	"fmt"
	"sync"
	"time"

	"github.com/jmoiron/sqlx"
	go_ora "github.com/sijms/go-ora/v2"
)

func main() {

	options := map[string]string{
		"TIMEOUT":    "60",
		"TRACE FILE": "trace.log",
	}
	dsn := go_ora.BuildUrl("192.168.x.x", 1521, "db", "user", "pass", options)

	conn, err := sqlx.Open("oracle", dsn)
	if err != nil {
		fmt.Printf("create pool fail: %v\n", err)
		return
	}
	conn.SetMaxIdleConns(5)
	conn.SetMaxOpenConns(5)
	defer func() {
		err = conn.Close()
		if err != nil {
			fmt.Println("can't close db:", err)
		}
	}()

	selecttest := "SELECT TO_CHAR(CURRENT_TIMESTAMP(0),'yyyy-MM-dd HH24:MI:SS') FROM dual"
	var wg sync.WaitGroup
	wg.Add(10)
	for i := 0; i < 37; i++ {

		go func(wgc *sync.WaitGroup) {
			defer wgc.Done()
			count := 0
			for {
				p1 := time.Now().Local()
				dbt, err := GetDBCurrTimestamp(conn, selecttest, 5)
				p2 := time.Now().Local()
				count++

				if err != nil {
					fmt.Printf("%v ping db failed[count: %d] execdur: %v, error: %v\n", time.Now().Local(), count, p2.Sub(p1), err)
				} else {
					fmt.Printf("%v ping db succeeded[count: %d, val: %s] execdur: %v\n", time.Now().Local(), count, dbt, p2.Sub(p1))
				}
				time.Sleep(time.Second)
			}
		}(&wg)
	}
	wg.Wait()
}
func GetDBCurrTimestamp(dbconn *sqlx.DB, sqlstr string, timeout int) (string, error) {
	ctxTimeout, cancel := context.WithTimeout(context.Background(), time.Second*time.Duration(timeout))
	defer cancel()
	getconn, err := dbconn.Connx(ctxTimeout)
	if err != nil {
		return "", fmt.Errorf("query db current time, getconn error: %v - sql: %s", err, sqlstr)
	}
	defer getconn.Close()

	res, err := getconn.QueryxContext(ctxTimeout, sqlstr)
	if err != nil {
		return "", fmt.Errorf("query db current time error: %v - sql: %s", err, sqlstr)
	}
	defer res.Close()

	var currt any
	if res.Next() {
		res.Scan(&currt)
	}
	switch val := currt.(type) {
	case string:
		return val, nil
	case []uint8:
		return string(val), nil
	default:
		return "", fmt.Errorf("dbtime cannot be converted to string: %v", currt)
	}
}

freeNestor avatar Jun 20 '24 07:06 freeNestor