BUG: cannot unlock unlocked connection

[edulop91]

@edulop91 Can you provide an example that demonstrates the panic or at least a stack trace? I'd like to tag a release with this fix, but I'd like to make sure it is totally fixed. Also, if you can run your example with the race detector that would be helpful. I reviewed the connection lock/unlock code this morning and was unable to find anything that might be causing the issue.

Originally posted by @jackc in #1791 (comment)

BUG: cannot unlock unlocked connection

2023-11-15T10:51:56.453-05:00	panic({0x6d638c0?, 0x8a27030?})

2023-11-15T10:51:56.453-05:00	/usr/local/go/src/runtime/panic.go:914 +0x218

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5/pgconn.(*PgConn).unlock(...)

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/pgconn/pgconn.go:708

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5/pgconn.(*MultiResultReader).receiveMessage(0x4001621310)

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/pgconn/pgconn.go:1422 +0x3c0

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5/pgconn.(*ResultReader).receiveMessage(0x4001621290)

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/pgconn/pgconn.go:1622 +0x2c

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5/pgconn.(*ResultReader).Close(0x4001621290)

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/pgconn/pgconn.go:1570 +0x60

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5.(*Conn).execSimpleProtocol(0x7039cc0?, {0x8a69548?, 0x4016117710?}, {0x78deede?, 0x400f8f40b8?}, {0x0?, 0x400f8f40d8?, 0xb0560?})

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/conn.go:544 +0xa0

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5.(*Conn).exec(0x4000ca9e60, {0x8a69548, 0x4016117710}, {0x78deede, 0x8}, {0x0?, 0x4015861718?, 0x4015861710?})

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/conn.go:528 +0x468

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5.(*Conn).Exec(0x4000ca9e60, {0x8a69548?, 0x4016117710?}, {0x78deede, 0x8}, {0x0, 0x0, 0x0})

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/conn.go:448 +0xd8

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5.(*dbTx).Rollback(0x40161d3488, {0x8a69548?, 0x4016117710?})

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/tx.go:204 +0x50

2023-11-15T10:51:56.453-05:00	github.com/jackc/pgx/v5/stdlib.wrapTx.Rollback(...)

2023-11-15T10:51:56.453-05:00	/go/pkg/mod/github.com/jackc/pgx/v5@v5.5.1-0.20231111155103-e11027287171/stdlib/sql.go:884

2023-11-15T10:51:56.453-05:00	database/sql.(*Tx).rollback.func1()

2023-11-15T10:51:56.453-05:00	/usr/local/go/src/database/sql/sql.go:2307 +0x34

2023-11-15T10:51:56.453-05:00	database/sql.withLock({0x8a47da0, 0x4015860fc0}, 0x400f8f42f0)

2023-11-15T10:51:56.453-05:00	/usr/local/go/src/database/sql/sql.go:3502 +0x7c

2023-11-15T10:51:56.453-05:00	database/sql.(*Tx).rollback(0x40161e4180, 0x0)

2023-11-15T10:51:56.453-05:00	/usr/local/go/src/database/sql/sql.go:2306 +0xf0

2023-11-15T10:51:56.453-05:00	database/sql.(*Tx).Rollback(0xfffe4d443df8?)

	/usr/local/go/src/database/sql/sql.go:2321 +0x20
/usr/local/go/src/database/sql/sql.go:2321 +0x20

github.com/withluminary/platform/server/pkg/storage/ent.(*Tx).Rollback.func1({0x10, 0x71a2a00}, 0x40161d3401)

sorry I'd missed your earlier comment @jackc !

One other thing that might be relevant here is that I was wrapping a pgx pool with pgx stdlib. I'll run with the race detector and see if anything comes up.

[jackc]

Thanks! I still don't see any what's going on. But there are a few things that jump out at me that might help narrow it down.

1. stdlib - whether this issue can occur in the lower level pgx interface or not.
2. Does the error always occur in a tx rollback? (possibly a rollback can be forced somewhere it wasn't expected)
3. The simple protocol is being used. Does it occur when using other execution modes.