Incorrect "idle in transaction" on Tx.Commit()

[cuboci]

Hi there,

I don't know if this has been reported before or isn't considered a bug. I searched the issues for something like it but didn't find anything.

I encountered the following situation:

• open a transaction
• execute a query that returns rows
• forget to close the rows
• call Commit()
• repeat

The call to Commit() returns an error but the transaction actually gets committed (as can be checked via psql). The next call to Begin() then returns an error saying
"pq: unexpected transaction status idle in transaction", even though the previous tx got committed and PostgreSQL thinks there's no idle-in-transaction connection either (ps output says "idle", not "idle in transaction").

Maybe a little code:

func Test(user string, age int, conn *sql.DB) (int, error) {
    tx, err := conn.Begin()
        if err != nil {
            return 0, err
    }
    rollback := false

    defer func() {
        if rollback {
            tx.Rollback()
        } else {
            err := tx.Commit()
            fmt.Println(err)
        }
    }()

    rows, err := tx.Query("INSERT INTO users(id, name, age) VALUES (DEFAULT, $1, $2) RETURNING (id)", user, age)
    if err != nil {
        rollback = true
        return 0, err
    }

    var id int
    rows.Next() // because I know there will only be one row
    err = rows.Scan(&id)
    if err != nil {
        rollback = true
        return 0, err
    }

    return id, nil
}

Call this function twice and the second call will fail even though the data from the first call reached the database correctly. If the connection really were idle in transaction the data could not be seen in the corresponding database table.

Note: I know I should have used QueryRow (and I currently do), but that's how I stumbled over this. Inserting a rows.Close() call before returning works, too.

But it looks like pq and PostgreSQL have differing ideas about what constitutes a successful commit. Btw, the call to Commit() returns "unexpected command tag INSERT" in this case.

I believe this is a bug in pq or should at least be clarified in the documentation.

[johto]

Right. In that case the protocol is in an incorrect state from the driver's perspective. Ideally, we would not let this connection back to the pool to ruin subsequent queries, but there's no way to tell database/sql that "this connection is bad, but also give the user this error so he knows something's wrong". We have several other cases where we notice the protocol state being inconsistent, but currently just release the connection back to database/sql's pool. I've been meaning to fix this by setting a bit on conn signifying that next call, whatever it is, should return ErrBadConn. This would mean that the user would see the problem when it happens (as there's no other way for us to communicate with the user), but such connections wouldn't ruin the rest of the application's life cycle.

I'll probably be hacking on the bad connection handling more when I've sorted out some higher priority items, but feel free to do it if you want to. In any case, I'll be happy to commit a documentation patch warning about the effects unclosed Rows could have (outside of sql.Tx as well).

[johto]

Oh, now that I'm thinking out loud, I've also been meaning to look into storing unclosed rows inside the conn object. That would give the user a nicer error message in operator errors like this, and we could leverage it to do things like #117 and #81.

But it's not clear how much code this would require us to maintain, or whether it would be worth it, even.

[cuboci]

What I don't understand is why the driver's perspective differs from PostgreSQL's. Clearly, the server thinks the transaction is committed correctly. Wouldn't it be easier to just close any open rows on Tx.Commit() as that is more in line with the state of the db?

[johto]

What I don't understand is why the driver's perspective differs from PostgreSQL's. Clearly, the server thinks the transaction is committed correctly.

When the client sends the COMMIT message to the server, it receives the (previously unread) response to the INSERT query back. That's why it complains about the command tag being INSERT, not COMMIT.

The response to the INSERT query is read either when you call Rows.Close() or advance past the last row using Next(). You don't do either in your example, so the client never has a chance to read the response.

Wouldn't it be easier to just close any open rows on Tx.Commit() as that is more in line with the state of the db?

The problem is, the driver doesn't maintain a list of open rows objects, so it doesn't know how to do that.

[cuboci]

I'll have to take a closer look at PostgreSQL's network protocol to understand the first part, I guess. I thought calling Scan was enough to read the response. Obviously not. The second part makes sense, though.

[echlebek]

I'm periodically getting "pq: unexpected transaction status idle in transaction" as well. Eventually the connection pool fills up with what I assume to be bad connections and lib/pq refuses to service any more queries.

I've checked and re-checked that I am closing rows after opening them, and I am pretty sure that I'm cleaning up after myself. Is there some other reason this could be happening?

[johto]

Are you using using explicit transactions at all?

[echlebek]

Yes, all of my queries are done with *sql.Tx.Query. The transactions themselves are always treated with Commit() or Rollback() in a deferred func.

[johto]

Is it possible that the transaction commits before the Rows object is closed? Or a prepared statement is closed?

[echlebek]

No prepared statements in the codebase. Here is how I'm handling my transactions:

// withSession executes f, taking care of the Session lifetime.
func (s *Server) withSession(f func(Session) error) (err error) {
    var (
        session Session
        commit  bool
    )

    session, err = s.DB.GetSession()
    if err != nil {
        return err
    }
    defer func() {
        if commit {
            err = session.Commit()
            if err != nil {
                err = SessionError{Commit: true, message: err.Error()}
            }
        } else {
            if dberr := session.Rollback(); dberr != nil {
                message := fmt.Sprintf("after: %s, got: %s", err, dberr)
                err = SessionError{Commit: false, message: message}
            }
        }
    }()
    err = f(session)
    if err == nil {
        commit = true
    }
    return err
}

Session is an interface that requires Commit and Rollback (among other things), so it's an *sql.Tx for the sake of this discussion. DB is an *sql.DB. Anything involving rows happens within f. I've been using this particular piece of code since bmizerany/pq, but the errors only really started a month or two ago. (I've been using lib/pq for about 6 months, upgrading sporadically)

If nothing strikes you as obviously wrong here I guess I will start instrumenting the driver to try to gain some more insight.

[johto]

If nothing strikes you as obviously wrong here I guess I will start instrumenting the driver to try to gain some more insight.

That particular piece of code looks pristine.

Have you tried the race detector? Looks like we'll need at least a backtrace, perhaps even a race detector report to solve this :-(

[echlebek]

I have not... I'll give that a shot and report back when I learn some more. Thanks!

[johto]

Also, which exact PG version are you on?