flashmob / go-guerrilla

Mini SMTP server written in golang
MIT License
2.76k stars 361 forks source link

Close sql statement after use? #175

Closed lord-alfred closed 5 years ago

lord-alfred commented 5 years ago

I dont know this bug or not, but statements open in code by method .Prepare - but not closed anything: https://github.com/flashmob/go-guerrilla/blob/master/backends/p_sql.go#L108

Can you check your mysql with this command?

mysql> SHOW GLOBAL STATUS LIKE 'com_stmt%';
+-------------------------+-------+
| Variable_name           | Value |
+-------------------------+-------+
| Com_stmt_execute        | 46    |
| Com_stmt_close          | 23    |
| Com_stmt_fetch          | 0     |
| Com_stmt_prepare        | 41    |
| Com_stmt_reset          | 0     |
| Com_stmt_send_long_data | 0     |
| Com_stmt_reprepare      | 0     |
+-------------------------+-------+
7 rows in set (0.02 sec)

Maybe Com_stmt_prepare need to be equal Com_stmt_close?

And maybe in logs (main log file, not daemon or server logs) you see anything like this

Error 1461: Can't create more than max_prepared_stmt_count statements (current value: 16382)

?

PS: Why are you caching statements in sql backend?

flashmob commented 5 years ago

Sorry for the confusing code.

No need to close them after the query, because the prepared statements can be reused. As you have noticed, they are placed in a cache after use. We need different prepared statements because it's an optimisation trick that allows us to insert multiple rows with a single query. Since some queries have different number of rows, we need to prepare a query for each possibly.

There is a slight bug here: The statements are not closed when the backend is stopped.

Also, perhaps a comment would be needed to explain what's going on.

lord-alfred commented 5 years ago

No need to close them after the query, because the prepared statements can be reused

It's strange, because documentation say:

... When you execute the Stmt, it tries to use the connection. If it’s not available because it’s closed or busy doing something else, it gets another connection from the pool and re-prepares the statement with the database on another connection.

Because statements will be re-prepared as needed when their original connection is busy, it’s possible for high-concurrency usage of the database, which may keep a lot of connections busy, to create a large number of prepared statements. This can result in apparent leaks of statements, statements being prepared and re-prepared more often than you think, and even running into server-side limits on the number of statements.

But Com_stmt_reprepare everytime equal 0.


I asked this question because I encountered the indicated error. But I made a copy of your sql backend, where I wrote my own method with an error:

func (s *BenderSQLProcessor) doUpdateDomains(host string, db *sql.DB) (rowCnt int64) {
    var sqlstr string

    sqlstr = "UPDATE domains SET `messages_count` = `messages_count` + 1, "
    sqlstr += "`last_message` = NOW() WHERE `name` = ?"

    stmt, err := db.Prepare(sqlstr)
    if err != nil {
        Log().WithError(err).Error("doUpdateDomains: db.Prepare fail")
    }
        // added here
    res, err := stmt.Exec(host)
    if err != nil {
        Log().WithError(err).Error("doUpdateDomains: db.Exec fail")
    }
    rowCnt, err = res.RowsAffected()
    if err != nil {
        Log().WithError(err).Error("doUpdateDomains: db.RowsAffected fail")
    }

    return rowCnt
}

Now I fixed (or not...) this error by adding defer stmt.Close() before stmt.Exec. But I began to doubt if you had any errors in the code, so I decided to ask this question. After some time, if this error occurs again and there is a record in the log where it was, I will report it.


Maybe need to use interpolateParams configuration option by default for prevent this error? This answer found here: https://github.com/go-sql-driver/mysql/issues/701

flashmob commented 5 years ago

No, not getting this error message and processing millions of statements a day, but yes, ran in to this error before when working on a different thing, so it's familiar to me. The quote from the doc seems to talk about a different edge case.

On Thu., 15 Aug. 2019, 23:24 Lord Alfred, notifications@github.com wrote:

No need to close them after the query, because the prepared statements can be reused

It's strange, because documentation http://go-database-sql.org/prepared.html say:

... When you execute the Stmt, it tries to use the connection. If it’s not available because it’s closed or busy doing something else, it gets another connection from the pool and re-prepares the statement with the database on another connection.

Because statements will be re-prepared as needed when their original connection is busy, it’s possible for high-concurrency usage of the database, which may keep a lot of connections busy, to create a large number of prepared statements. This can result in apparent leaks of statements, statements being prepared and re-prepared more often than you think, and even running into server-side limits on the number of statements.


I asked this question because I encountered the indicated error. But I made a copy of your sql backend, where I wrote my own method with an error:

func (s BenderSQLProcessor) doUpdateDomains(host string, db sql.DB) (rowCnt int64) {

var sqlstr string

sqlstr = "UPDATE domains SET messages_count = messages_count + 1, "

sqlstr += "last_message = NOW() WHERE name = ?"

stmt, err := db.Prepare(sqlstr)

if err != nil {

  Log().WithError(err).Error("doUpdateDomains: db.Prepare fail")

}

res, err := stmt.Exec(host)

if err != nil {

  Log().WithError(err).Error("doUpdateDomains: db.Exec fail")

}

rowCnt, err = res.RowsAffected()

if err != nil {

  Log().WithError(err).Error("doUpdateDomains: db.RowsAffected fail")

}

return rowCnt

}

Now I fixed (or not...) this error by adding defer stmt.Close() before stmt.Exec. But I began to doubt if you had any errors in the code, so I decided to ask this question. After some time, if this error occurs again and there is a record in the log where it was, I will report it.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/flashmob/go-guerrilla/issues/175?email_source=notifications&email_token=AAE6MP7V7GMIH4NZ65TMZALQEVRJ7A5CNFSM4IL53LB2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD4L6MBY#issuecomment-521659911, or mute the thread https://github.com/notifications/unsubscribe-auth/AAE6MPYP6TT6Z7ZUNNM5PVLQEVRJ7ANCNFSM4IL53LBQ .

lord-alfred commented 5 years ago

The error in the first message was due to my code :)