Skip to content

bug: Dubbed binding that cause redundant logs #1784

Open
@Ilyaa2

Description

@Ilyaa2

Bug Report

YDB GO SDK version:

go1.24.2, v3.104.5

Environment

$lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 22.04.4 LTS
Release: 22.04
Codename: jammy
$uname -m
x86_64
$ uname -a
6.8.0-58-generic #60~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 28 16:09:21 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

Current behavior:

When an error occurs in the execution of a query then a lot of redundant logs appears (bindings):
2025/04/25 22:07:59 operation/BAD_REQUEST (code = 400010, address = localhost:2136, nodeID = 1, issues = [{21:9 => #4536 'Duplicate declaration of '$p0' will be ignored'},{22:9 => #4536 'Duplicate declaration of '$p1' will be ignored'},{23:9 => #4536 'Duplicate declaration of '$p10' will be ignored'},{24:9 => #4536 'Duplicate declaration of '$p2' will be ignored'},{25:9 => #4536 'Duplicate declaration of '$p3' will be ignored'},{26:9 => #4536 'Duplicate declaration of '$p4' will be ignored'},{27:9 => #4536 'Duplicate declaration of '$p5' will be ignored'},{28:9 => #4536 'Duplicate declaration of '$p6' will be ignored'},{29:9 => #4536 'Duplicate declaration of '$p7' will be ignored'},{30:9 => #4536 'Duplicate declaration of '$p8' will be ignored'},{31:9 => #4536 'Duplicate declaration of '$p9' will be ignored'},{'ydb/core/kqp/session_actor/kqp_session_actor.cpp:910: Invalid Timestamp value'}]) at github.com/ydb-platform/ydb-go-sdk/v3/internal/conn.(*grpcClientStream).RecvMsg(grpc_client_stream.go:180) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.nextPart(result.go:221) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*streamResult).nextPart(result.go:203) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.newResult(result.go:166) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.execute(execute_query.go:147) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*Session).execute(session.go:149) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*Session).Query(session.go:197) at github.com/ydb-platform/ydb-go-sdk/v3/internal/xsql/xquery.(*Conn).Query(conn.go:94)

Expected behavior:

just an error without redundant logs. Something like this:
2025/04/25 22:07:59 operation/BAD_REQUEST (code = 400010, address = localhost:2136, nodeID = 1, issues =
[{'ydb/core/kqp/session_actor/kqp_session_actor.cpp:910: Invalid Timestamp value'}]) at github.com/ydb-platform/ydb-go-sdk/v3/internal/conn.(*grpcClientStream).RecvMsg(grpc_client_stream.go:180) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.nextPart(result.go:221) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*streamResult).nextPart(result.go:203) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.newResult(result.go:166) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.execute(execute_query.go:147) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*Session).execute(session.go:149) at github.com/ydb-platform/ydb-go-sdk/v3/internal/query.(*Session).Query(session.go:197) at github.com/ydb-platform/ydb-go-sdk/v3/internal/xsql/xquery.(*Conn).Query(conn.go:94)

Steps to reproduce:

create a table:
CREATE TABLE identity_verifiable_addresses (
id Utf8 NOT NULL,
status Utf8 NOT NULL,
via Utf8 NOT NULL,
verified Bool NOT NULL,
value Utf8 NOT NULL,
verified_at Timestamp,
identity_id Utf8 NOT NULL,
created_at Timestamp NOT NULL,
updated_at Timestamp NOT NULL,
nid Utf8,
PRIMARY KEY (id)
);

code

func main() {
  db, err := sql.Open("ydb", "grpc://localhost:2136/local?query_mode=query&go_query_bind=numeric,declare,table_path_prefix(/local)")
  if err != nil {
    fmt.Println(err)
  }
  err = db.Ping()
  if err != nil {
    fmt.Println("ghbdtn")
    log.Fatal(err)
  }

  var t interface{} = (*time.Time)(nil)
  rows, err := db.QueryContext(context.Background(), "UPDATE `identity_verifiable_addresses` SET `created_at` = $1, `identity_id` = $2, `nid` = $3, `status` = $4, `updated_at` = $5, `value` = $6, `verified_at` = $7, `verified` = $8, `via` = $9 WHERE identity_verifiable_addresses.id = $10 AND `identity_verifiable_addresses`.nid = $11 returning nid",
    time.Time{},
    "identity_id",
    "nid",
    "status",
    time.Time{},
    "value",
    t,
    true,
    "via",
    "id",
    "nid",
  )
  if err != nil {
    log.Fatal(err)
  }
}

Other information:

this query with double binding is sent to db in internal/query.execute(execute_query/go:147):

-- bind TablePathPrefix
PRAGMA TablePathPrefix("/local");

-- bind TablePathPrefix
PRAGMA TablePathPrefix("/local");

-- bind declares
DECLARE $p0 AS Timestamp;
DECLARE $p1 AS Utf8;
DECLARE $p10 AS Utf8;
DECLARE $p2 AS Utf8;
DECLARE $p3 AS Utf8;
DECLARE $p4 AS Timestamp;
DECLARE $p5 AS Utf8;
DECLARE $p6 AS Optional<Timestamp>;
DECLARE $p7 AS Bool;
DECLARE $p8 AS Utf8;
DECLARE $p9 AS Utf8;

-- bind declares
DECLARE $p0 AS Timestamp;
DECLARE $p1 AS Utf8;
DECLARE $p10 AS Utf8;
DECLARE $p2 AS Utf8;
DECLARE $p3 AS Utf8;
DECLARE $p4 AS Timestamp;
DECLARE $p5 AS Utf8;
DECLARE $p6 AS Optional<Timestamp>;
DECLARE $p7 AS Bool;
DECLARE $p8 AS Utf8;
DECLARE $p9 AS Utf8;

-- origin query with numeric args replacement
-- origin query with numeric args replacement
UPDATE `identity_verifiable_addresses` SET `created_at` = $p0, `identity_id` = $p1, `nid` = $p2, `status` = $p3, `updated_at` = $p4, `value` = $p5, `verified_at` = $p6, `verified` = $p7, `via` = $p8 WHERE identity_verifiable_addresses.id = $p9 AND `identity_verifiable_addresses`.nid = $p10 returning nid

databaseSQLOptions parameter is passed two times in function xsql.Open()

the first time:

Image

the second time:

Image

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions