Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

database/sql: Stmt.Exec is wasting database resources #4902

Closed
alexbrainman opened this issue Feb 25, 2013 · 11 comments
Closed

database/sql: Stmt.Exec is wasting database resources #4902

alexbrainman opened this issue Feb 25, 2013 · 11 comments
Milestone

Comments

@alexbrainman
Copy link
Member

This new test

diff --git a/src/pkg/database/sql/sql_test.go b/src/pkg/database/sql/sql_test.go
--- a/src/pkg/database/sql/sql_test.go
+++ b/src/pkg/database/sql/sql_test.go
@@ -708,3 +708,21 @@
        t.Errorf("error = %q; want %q", err.Error(), want)
    }
 }
+
+func TestPrepareCount(t *testing.T) {
+   db := newTestDB(t, "people")
+   defer closeDB(t, db)
+   prepares0 := numPrepares(t, db)
+   stmt, err := db.Prepare("INSERT|people|name=?,age=?")
+   if err != nil {
+       t.Fatal(err)
+   }
+   defer stmt.Close()
+   _, err = stmt.Exec("Alice", 10)
+   if err != nil {
+       t.Fatal(err)
+   }
+   if prepares := numPrepares(t, db) - prepares0; prepares != 1 {
+       t.Errorf("executed %d Prepare statements; want 1", prepares)
+   }
+}

fails with

=== RUN TestPrepareCount
--- FAIL: TestPrepareCount (0.00 seconds)
    sql_test.go:726: executed -4 Prepare statements; want 1
FAIL
exit status 1
FAIL    database/sql    0.007s
@bradfitz
Copy link
Contributor

Comment 1:

Wasting resources? Negative four seems pretty efficient to me.

@alexbrainman
Copy link
Member Author

Comment 2:

You just don't want to look at it, Brad :-)
# hg diff .
diff -r 33d3e7bbd3ef src/pkg/database/sql/fakedb_test.go
--- a/src/pkg/database/sql/fakedb_test.go       Mon Feb 25 10:37:17 2013 +1100
+++ b/src/pkg/database/sql/fakedb_test.go       Tue Feb 26 12:13:51 2013 +1100
@@ -388,6 +388,7 @@
 }
 func (c *fakeConn) Prepare(query string) (driver.Stmt, error) {
+       fmt.Printf("*fakeConn(%p).Prepare(%s)\n", c, query)
        c.numPrepare++
        if c.db == nil {
                panic("nil c.db; conn = " + fmt.Sprintf("%#v", c))
diff -r 33d3e7bbd3ef src/pkg/database/sql/sql_test.go
--- a/src/pkg/database/sql/sql_test.go  Mon Feb 25 10:37:17 2013 +1100
+++ b/src/pkg/database/sql/sql_test.go  Tue Feb 26 12:13:51 2013 +1100
@@ -708,3 +708,21 @@
                t.Errorf("error = %q; want %q", err.Error(), want)
        }
 }
+
+func TestPrepareCount(t *testing.T) {
+       db := newTestDB(t, "people")
+       defer closeDB(t, db)
+       prepares0 := numPrepares(t, db)
+       stmt, err := db.Prepare("INSERT|people|name=?,age=?")
+       if err != nil {
+               t.Fatal(err)
+       }
+       defer stmt.Close()
+       _, err = stmt.Exec("Alice", 10)
+       if err != nil {
+               t.Fatal(err)
+       }
+       if prepares := numPrepares(t, db) - prepares0; prepares != 1 {
+               t.Errorf("executed %d Prepare statements; want 1", prepares)
+       }
+}
# go test -run=Prepare
*fakeConn(0x183457e0).Prepare(WIPE)
*fakeConn(0x183457e0).Prepare(CREATE|people|name=string,age=int32,photo=blob,dead=bool,bdate=datetime)
*fakeConn(0x183457e0).Prepare(INSERT|people|name=Alice,age=?,photo=APHOTO)
*fakeConn(0x183457e0).Prepare(INSERT|people|name=Bob,age=?,photo=BPHOTO)
*fakeConn(0x183457e0).Prepare(INSERT|people|name=Chris,age=?,photo=CPHOTO,bdate=?)
*fakeConn(0x183457e0).Prepare(INSERT|people|name=?,age=?)
*fakeConn(0x18345bc0).Prepare(INSERT|people|name=?,age=?)
--- FAIL: TestPrepareCount (0.00 seconds)
        sql_test.go:726: executed -4 Prepare statements; want 1
FAIL
exit status 1
FAIL    database/sql    0.007s
#
See how "INSERT|people|name=?,age=?" gets prepared twice (on two different connections)?
Why so?
Alex

@julienschmidt
Copy link
Contributor

Comment 3:

Just wanted to open a new Issue, but this here seems highly related:
The bug seems to be introduced by 
http://code.google.com/p/go/source/detail?r=ddb9e6365e570c2619d88427176a465e8b76b4aa
http://code.google.com/p/go/source/browse/src/pkg/database/sql/sql.go#447 adds
dependency on stmt. The connection is never released again.
Output from the attached example:
go1.0.3:
>go run prepareBug.go
Prepare 1:
Prepare StmtID: 1 ConnID: 0
Close 1:
Close StmtID: 1 ConnID: 0
Prepare 2:
Prepare StmtID: 2 ConnID: 0
Query 1:
Query StmtID: 2 ConnID: 0
Query 2:
Query StmtID: 2 ConnID: 0
Close 2:
Close StmtID: 2 ConnID: 0
go-tip:
>go run prepareBug.go
Prepare 1:
Prepare StmtID: 1 ConnID: 0
Close 1:
Prepare 2:
Prepare StmtID: 1 ConnID: 1
Query 1:
Prepare StmtID: 1 ConnID: 2
Query StmtID: 1 ConnID: 2
Query 2:
Query StmtID: 1 ConnID: 2
Close 2:
Close StmtID: 1 ConnID: 2
The modified driver with debug output is available here:
https://github.com/Go-SQL-Driver/MySQL/tree/tip-prepare

Attachments:

  1. prepareBug.go (736 bytes)

@bradfitz
Copy link
Contributor

Comment 4:

Labels changed: added go1.1, removed priority-triage, go1.1maybe.

Owner changed to @bradfitz.

Status changed to Accepted.

@gopherbot
Copy link

Comment 5 by serbaut:

A related problem is that a database connection can have state, e.g. temporary tables,
transaction isolation settings and other variables. As I understand it each Query/Exec
may get a new/different database connection which breaks this state. For example in
mysql you can set variables like this:
db.Exec("set @foo=1")
db.Query("select @foo")
Not sure how this is supposed to work with database/sql.

@bradfitz
Copy link
Contributor

bradfitz commented Mar 5, 2013

Comment 6:

Re #5: use a transaction per-Conn state. That's unrelated to this bug.

@gopherbot
Copy link

Comment 7 by serbaut:

Sorry about that, just re-read the DB doc and realized transactions supports this and
clicked Delete at the same time you replied.

@bradfitz
Copy link
Contributor

bradfitz commented Mar 7, 2013

Comment 8:

Re #3: Julien, the stmt dep is removed at line 1030: return s.db.removeDep(s, s)

@bradfitz
Copy link
Contributor

bradfitz commented Mar 8, 2013

Comment 9:

Issue #4935 has been merged into this issue.

@bradfitz
Copy link
Contributor

bradfitz commented Mar 8, 2013

Comment 10:

Sent out https://golang.org/cl/7579045/ for review.

Status changed to Started.

@bradfitz
Copy link
Contributor

bradfitz commented Mar 8, 2013

Comment 11:

This issue was closed by revision 3cdf8ba.

Status changed to Fixed.

This issue was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants