From 35060d4c729f5a9ca6f74fc1d99534744a59e420 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Fri, 13 Jun 2025 11:33:32 -0600 Subject: [PATCH 01/11] Add logging --- connection.go | 1 + 1 file changed, 1 insertion(+) diff --git a/connection.go b/connection.go index 5648e47d..2cf77f03 100644 --- a/connection.go +++ b/connection.go @@ -350,6 +350,7 @@ func (mc *mysqlConn) Exec(query string, args []driver.Value) (driver.Result, err if mc.closed.Load() { return nil, driver.ErrBadConn } + mc.log("Exec", query) if len(args) != 0 { if !mc.cfg.InterpolateParams { return nil, driver.ErrSkip From 55754a626bc7d05305586e3d6822a8d7b9de0064 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 16 Jun 2025 13:46:09 -0600 Subject: [PATCH 02/11] Modify logging (for testing) --- connection.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/connection.go b/connection.go index 2cf77f03..b326ef79 100644 --- a/connection.go +++ b/connection.go @@ -350,7 +350,8 @@ func (mc *mysqlConn) Exec(query string, args []driver.Value) (driver.Result, err if mc.closed.Load() { return nil, driver.ErrBadConn } - mc.log("Exec", query) + queryStart := query[:20] + mc.log("Exec: **** ", queryStart, " ****") if len(args) != 0 { if !mc.cfg.InterpolateParams { return nil, driver.ErrSkip From 87fa1394263127ededf75770f8f731878c9dda36 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 23 Jun 2025 09:33:42 -0600 Subject: [PATCH 03/11] Add some logging to see if logging is going to work in calvin. --- connection.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/connection.go b/connection.go index b326ef79..8b417b9b 100644 --- a/connection.go +++ b/connection.go @@ -505,17 +505,20 @@ func (mc *mysqlConn) finish() { // Ping implements driver.Pinger interface func (mc *mysqlConn) Ping(ctx context.Context) (err error) { + mc.log("Ping mysql connection") if mc.closed.Load() { return driver.ErrBadConn } if err = mc.watchCancel(ctx); err != nil { + mc.log(err.Error()) return } defer mc.finish() handleOk := mc.clearResult() if err = mc.writeCommandPacket(comPing); err != nil { + mc.log(err.Error()) return mc.markBadConn(err) } From a263d0fc299c979dfc084410e06602622bbb2fc1 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 23 Jun 2025 09:51:33 -0600 Subject: [PATCH 04/11] Add more logging of errors --- connection.go | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/connection.go b/connection.go index 8b417b9b..ca03dafc 100644 --- a/connection.go +++ b/connection.go @@ -359,6 +359,7 @@ func (mc *mysqlConn) Exec(query string, args []driver.Value) (driver.Result, err // try to interpolate the parameters to save extra roundtrips for preparing and closing a statement prepared, err := mc.interpolateParams(query, args) if err != nil { + mc.log(err.Error()) return nil, err } query = prepared @@ -369,6 +370,7 @@ func (mc *mysqlConn) Exec(query string, args []driver.Value) (driver.Result, err copied := mc.result return &copied, err } + mc.log(err.Error()) return nil, mc.markBadConn(err) } @@ -377,23 +379,27 @@ func (mc *mysqlConn) exec(query string) error { handleOk := mc.clearResult() // Send command if err := mc.writeCommandPacketStr(comQuery, query); err != nil { + mc.log(err.Error()) return mc.markBadConn(err) } // Read Result resLen, _, err := handleOk.readResultSetHeaderPacket() if err != nil { + mc.log(err.Error()) return err } if resLen > 0 { // columns if err := mc.skipColumns(resLen); err != nil { + mc.log(err.Error()) return err } // rows if err := mc.skipRows(); err != nil { + mc.log(err.Error()) return err } } @@ -418,6 +424,7 @@ func (mc *mysqlConn) query(query string, args []driver.Value) (*textRows, error) // try client-side prepare to reduce roundtrip prepared, err := mc.interpolateParams(query, args) if err != nil { + mc.log(err.Error()) return nil, err } query = prepared @@ -425,6 +432,7 @@ func (mc *mysqlConn) query(query string, args []driver.Value) (*textRows, error) // Send command err := mc.writeCommandPacketStr(comQuery, query) if err != nil { + mc.log(err.Error()) return nil, mc.markBadConn(err) } @@ -432,6 +440,7 @@ func (mc *mysqlConn) query(query string, args []driver.Value) (*textRows, error) var resLen int resLen, _, err = handleOk.readResultSetHeaderPacket() if err != nil { + mc.log(err.Error()) return nil, err } @@ -505,7 +514,6 @@ func (mc *mysqlConn) finish() { // Ping implements driver.Pinger interface func (mc *mysqlConn) Ping(ctx context.Context) (err error) { - mc.log("Ping mysql connection") if mc.closed.Load() { return driver.ErrBadConn } @@ -572,10 +580,12 @@ func (mc *mysqlConn) QueryContext(ctx context.Context, query string, args []driv func (mc *mysqlConn) ExecContext(ctx context.Context, query string, args []driver.NamedValue) (driver.Result, error) { dargs, err := namedValueToValue(args) if err != nil { + mc.log(err.Error()) return nil, err } if err := mc.watchCancel(ctx); err != nil { + mc.log(err.Error()) return nil, err } defer mc.finish() From 8318d60801ebf35540965aa7ff310fab42486060 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 23 Jun 2025 15:48:12 -0600 Subject: [PATCH 05/11] More logging --- connection.go | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/connection.go b/connection.go index ca03dafc..af41172e 100644 --- a/connection.go +++ b/connection.go @@ -738,7 +738,13 @@ func (mc *mysqlConn) ResetSession(ctx context.Context) error { // IsValid implements driver.Validator interface // (From Go 1.15) func (mc *mysqlConn) IsValid() bool { - return !mc.closed.Load() && !mc.buf.busy() + retIsValid := !mc.closed.Load() && !mc.buf.busy() + if retIsValid { + mc.log("mysql connection is valid") + } else { + mc.log("mysql connection is invalid") + } + return retIsValid } var _ driver.SessionResetter = &mysqlConn{} From a7231040421ce76d7a92c83010c39f403b6da76a Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 23 Jun 2025 16:06:28 -0600 Subject: [PATCH 06/11] Determined this logging wasn't useful --- connection.go | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/connection.go b/connection.go index af41172e..ca03dafc 100644 --- a/connection.go +++ b/connection.go @@ -738,13 +738,7 @@ func (mc *mysqlConn) ResetSession(ctx context.Context) error { // IsValid implements driver.Validator interface // (From Go 1.15) func (mc *mysqlConn) IsValid() bool { - retIsValid := !mc.closed.Load() && !mc.buf.busy() - if retIsValid { - mc.log("mysql connection is valid") - } else { - mc.log("mysql connection is invalid") - } - return retIsValid + return !mc.closed.Load() && !mc.buf.busy() } var _ driver.SessionResetter = &mysqlConn{} From f0fdfba54a0f48ed958f29b9591fb7cf68e5e456 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Mon, 23 Jun 2025 16:40:00 -0600 Subject: [PATCH 07/11] more logging --- connection.go | 1 + 1 file changed, 1 insertion(+) diff --git a/connection.go b/connection.go index ca03dafc..16b1070e 100644 --- a/connection.go +++ b/connection.go @@ -157,6 +157,7 @@ func (mc *mysqlConn) begin(readOnly bool) (driver.Tx, error) { } func (mc *mysqlConn) Close() (err error) { + mc.log("Connection closed") // Makes Close idempotent if !mc.closed.Load() { err = mc.writeCommandPacket(comQuit) From 43788e33229261d69319a2943540b0a57e8a0dd1 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Tue, 24 Jun 2025 11:13:27 -0600 Subject: [PATCH 08/11] Another log entry --- connection.go | 1 + 1 file changed, 1 insertion(+) diff --git a/connection.go b/connection.go index 16b1070e..b4baa9cd 100644 --- a/connection.go +++ b/connection.go @@ -716,6 +716,7 @@ func (mc *mysqlConn) ResetSession(ctx context.Context) error { // could cause data corruption, so it's safe to return ErrBadConn // if the check fails. if mc.cfg.CheckConnLiveness { + mc.log("Checking conn liveness in ResetSession") conn := mc.netConn if mc.rawConn != nil { conn = mc.rawConn From 89219149bb486a0bd6460b1c6d41a8f268b5e77c Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Tue, 24 Jun 2025 11:28:19 -0600 Subject: [PATCH 09/11] Remove unnecessary logging. --- connection.go | 1 - 1 file changed, 1 deletion(-) diff --git a/connection.go b/connection.go index b4baa9cd..16b1070e 100644 --- a/connection.go +++ b/connection.go @@ -716,7 +716,6 @@ func (mc *mysqlConn) ResetSession(ctx context.Context) error { // could cause data corruption, so it's safe to return ErrBadConn // if the check fails. if mc.cfg.CheckConnLiveness { - mc.log("Checking conn liveness in ResetSession") conn := mc.netConn if mc.rawConn != nil { conn = mc.rawConn From 2ef029a8b1a760ebb01ee624a92e48633e81ce56 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Thu, 26 Jun 2025 15:09:06 -0600 Subject: [PATCH 10/11] Remove not needed logging --- connection.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/connection.go b/connection.go index 16b1070e..3b69f7f9 100644 --- a/connection.go +++ b/connection.go @@ -157,7 +157,6 @@ func (mc *mysqlConn) begin(readOnly bool) (driver.Tx, error) { } func (mc *mysqlConn) Close() (err error) { - mc.log("Connection closed") // Makes Close idempotent if !mc.closed.Load() { err = mc.writeCommandPacket(comQuit) @@ -351,8 +350,6 @@ func (mc *mysqlConn) Exec(query string, args []driver.Value) (driver.Result, err if mc.closed.Load() { return nil, driver.ErrBadConn } - queryStart := query[:20] - mc.log("Exec: **** ", queryStart, " ****") if len(args) != 0 { if !mc.cfg.InterpolateParams { return nil, driver.ErrSkip From 78a05533d248f5273bb1bf37a4bf12f0b7dc1401 Mon Sep 17 00:00:00 2001 From: Jerry Buss Date: Fri, 27 Jun 2025 16:36:41 -0600 Subject: [PATCH 11/11] Add more logging around areas with possible timeouts --- packets.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packets.go b/packets.go index 6ef5a3e2..fc9c7bd6 100644 --- a/packets.go +++ b/packets.go @@ -31,6 +31,7 @@ func (mc *mysqlConn) readNext(n int) ([]byte, error) { if mc.buf.len() < n { err := mc.buf.fill(n, mc.readWithTimeout) if err != nil { + mc.log(err) return nil, err } } @@ -53,6 +54,7 @@ func (mc *mysqlConn) readPacket() ([]byte, error) { if err != nil { mc.close() if cerr := mc.canceled.Value(); cerr != nil { + mc.log(cerr) return nil, cerr } mc.log(err) @@ -95,6 +97,7 @@ func (mc *mysqlConn) readPacket() ([]byte, error) { if err != nil { mc.close() if cerr := mc.canceled.Value(); cerr != nil { + mc.log(cerr) return nil, cerr } mc.log(err)