packets.go:336: Busy buffer. Commands out of sync. Did you run multiple statements at once?

[rocketkittens]

I am trying to build a web server using this package and when i try to log hits into database too quickly i get the error:

packets.go:336: Busy buffer. Commands out of sync. Did you run multiple statements at once?

My code works fine untill i make too many requests too quickly... Whats going on here?

res, err := db.Exec("INSERT INTO hits VALUES('', ?, ?, ?, ?)", ipaddress, useragent, path, timestamp)

[julienschmidt]

This bug was previously reported in #185 (comment) but there was never an issue opened for this specific bug.

@arnehormann seems to have found one situation where this is triggered, as confirmed by @rmulley:

@arnehormann seems to be correct. The issue happens when attempting to use the same transaction for multiple queries while a rows object is still open

package main

import (
    "database/sql"

    _ "github.com/go-sql-driver/mysql"
)

func main() {
    db, _ := sql.Open("mysql", "/")
    defer db.Close()
    tx, err := db.Begin()
    if err != nil {
        panic(err)
    }
    defer tx.Commit()
    stmt1, err := tx.Prepare("SELECT 1")
    if err != nil {
        panic(err)
    }
    rows1, err := stmt1.Query()
    if err != nil {
        panic(err)
    }
    stmt2, err := tx.Prepare("SELECT 2")
    if err != nil {
        // rows1 is not closed -> triggers busy buffer because transaction is on one connection
        // and stmt1, stmt2 use the same one.
        // Move rows1.Close() in front of tx.Prepare and it disappears
        panic(err)
    }
    rows2, err := stmt2.Query()
    if err != nil {
        panic(err)
    }
    rows1.Close()
    rows2.Close()
    stmt1.Close()
    stmt2.Close()
}

But this seems also to happen without the usage of database/sql's tx (transactions) API.

Can you maybe provide a minimal Go program with which you can trigger this bug?
Please also report us your Go and MySQL server version and your platform (e.g. linux/amd64)

[rocketkittens]

https://play.golang.org/p/aWRBMSjk1z (Hope this works, and is good enough)
go version: go1.4.1 windows/amd64
mysql server version: 10.0.16-MariaDB-1~trusty-log

[ajays20078]

Happening with me too. i have http api where there are multiple statements executed using a transaction object(*sql.Tx) and i get the following error:
MySQL] packets.go:355: Busy buffer
[MySQL] packets.go:336: Busy buffer
http: panic driver: bad connection

[rocketkittens]

ajays20078, I have a fix I am using to deal with this issue for now, check it out :)

import "sync"
var mutex = &sync.Mutex{}
mutex.Lock()
// ... db stuff here
mutex.Unlock()

Let me know your results please.

[ajays20078]

@Alandroid - If you are using Mutex lock as a alternate for mysql transaction i am afraid thats not the right way as it does not acquire a DB lock.

If you meant using Mutex along with the transaction code, NO its not working with me.

[methane]

@Alandroid Can you really reproduce it with only this code? https://play.golang.org/p/aWRBMSjk1z
If you can, could you show me create table hits?

[PuppyKhan]

I am getting a big blank with @Alandroid 's link. Do we have any other code to reproduce this issue? I am running into the same problem, but comes and goes randomly in my application.

[mstetson]

I just ran into this error, but I've traced it to a bug in my own code: I closed a *sql.Stmt which still had an open *sql.Rows and then tried to read the rows. Bad idea. It only misbehaves for me in a transaction, though I'm sure closing the Stmt first is a bug in any case. The exact behavior seems to depend on the query. Example:

package main

import (
    "database/sql"
    "fmt"
    "os"

    _ "github.com/go-sql-driver/mysql"
)

func main() {
    db, err := sql.Open("mysql", "root@/mysql")
    fmt.Println("sql.Open:", err)
    tx, err := db.Begin()
    fmt.Println("db.Begin:", err)
    stmt, err := tx.Prepare(os.Args[1])
    fmt.Println("tx.Prepare:", err)
    rs, err := stmt.Query()
    fmt.Println("stmt.Query:", err)
    fmt.Println("stmt.Close:", stmt.Close()) // Doh!
    for rs.Next() {
        var dst interface{}
        fmt.Println("rs.Scan:", rs.Scan(&dst))
    }
    fmt.Println("rs.Err:", rs.Err())
    fmt.Println("rs.Close:", rs.Close())
    fmt.Println("tx.Commit:", tx.Commit())
    fmt.Println("db.Close:", db.Close())
}

Here's the output from a couple of queries using an up-to-date master on Go 1.4, MySQL 5.6.17, Mac OS X 10.10.2:

% go run test.go 'select Db from db'
sql.Open: <nil>
db.Begin: <nil>
tx.Prepare: <nil>
stmt.Query: <nil>
[MySQL] 2015/03/25 23:39:49 packets.go:376: Busy buffer
stmt.Close: <nil>
rs.Err: Commands out of sync. Did you run multiple statements at once?
rs.Close: <nil>
[MySQL] 2015/03/25 23:39:49 packets.go:355: Busy buffer
tx.Commit: driver: bad connection
[MySQL] 2015/03/25 23:39:49 packets.go:336: Busy buffer
db.Close: driver: bad connection
% go run test.go 'select 1'
sql.Open: <nil>
db.Begin: <nil>
tx.Prepare: <nil>
stmt.Query: <nil>
[MySQL] 2015/03/25 23:40:07 packets.go:376: Busy buffer
stmt.Close: <nil>
 ... here it hangs and you have to interrupt the process ...

[arnehormann]

@mstetson thank you! I can't tell if that's the reason for ALL the busy buffer problems, but at least it's a solid hint. This really stumped Julien and me.

[methane]

I think database/sql should have option for detecting such bugs.