slowlog_bin_args.go

package main

import (
	"crypto/rand"
	"database/sql"
	"encoding/hex"
	"fmt"
	"log"
	"os"
	"strconv"
	"time"

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

const tableDDL = `
CREATE TABLE IF NOT EXISTS slowlog_bin_args_test (
  id BIGINT UNSIGNED NOT NULL AUTO_INCREMENT,
  bin_id BINARY(16) NOT NULL,
  ts TIMESTAMP(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6),
  payload VARCHAR(64) DEFAULT NULL,
  bin_id_hex CHAR(32) NOT NULL,
  PRIMARY KEY (id),
  KEY idx_bin_id (bin_id),
  KEY idx_ts (ts)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;
`

func mustEnv(key, def string) string {
	v := os.Getenv(key)
	if v == "" {
		return def
	}
	return v
}

func openDB() (*sql.DB, error) {
	// Example:
	// root:@tcp(127.0.0.1:4000)/test?charset=utf8mb4&parseTime=true&loc=Local
	dsn := mustEnv("MYSQL_DSN", "root:@tcp(127.0.0.1:4000)/test?charset=utf8mb4&parseTime=true&loc=Local")
	return sql.Open("mysql", dsn)
}

// setupTable creates table and inserts N rows, then prints one target bin_id (hex).
func setupTable(db *sql.DB, rows int) (targetBytes []byte, targetHex string, err error) {
	if _, err = db.Exec("DROP TABLE IF EXISTS slowlog_bin_args_test"); err != nil {
		return nil, "", err
	}
	if _, err = db.Exec(tableDDL); err != nil {
		return nil, "", err
	}

	ins, err := db.Prepare("INSERT INTO slowlog_bin_args_test (bin_id, payload, bin_id_hex) VALUES (?, ?, ?)")
	if err != nil {
		return nil, "", err
	}
	defer ins.Close()

	var last []byte
	var lastHex string

	for i := 0; i < rows; i++ {
		b := make([]byte, 16)
		if _, err := rand.Read(b); err != nil {
			return nil, "", err
		}
		h := hex.EncodeToString(b)
		if _, err := ins.Exec(b, fmt.Sprintf("row_%d", i), h); err != nil {
			return nil, "", err
		}
		last = b
		lastHex = h
	}

	fmt.Printf("[setupTable] inserted rows=%d\n", rows)
	fmt.Printf("[setupTable] target bin_id_hex=%s\n", lastHex)
	fmt.Printf("[setupTable] done\n\n")
	return last, lastHex, nil
}

// bytesToRawString preserves bytes 1:1 inside a Go string.
// (Go strings can contain arbitrary bytes, even if not valid UTF-8.)
func bytesToRawString(b []byte) string {
	return string(b)
}

func runTwoQueries(db *sql.DB) error {
	if _, err := db.Exec("SET @@session.tidb_slow_log_threshold = 0"); err == nil {
		fmt.Println("[runTwoQueries] set @@session.tidb_slow_log_threshold = 0")
	} else {
		fmt.Println("[runTwoQueries] couldn't set tidb_slow_log_threshold (ok):", err)
	}

	var enable string
	if err := db.QueryRow("SHOW VARIABLES LIKE 'tidb_enable_slow_log'").Scan(new(string), &enable); err == nil {
		fmt.Println("[runTwoQueries] tidb_enable_slow_log:", enable)
	}

	// Fetch target
	var targetBytes []byte
	var targetHex string
	if err := db.QueryRow("SELECT bin_id, bin_id_hex FROM slowlog_bin_args_test ORDER BY id DESC LIMIT 1").
		Scan(&targetBytes, &targetHex); err != nil {
		return err
	}

	sqlText := `
SELECT /* slowlog_bin_args_test */
       id, bin_id_hex, payload
FROM slowlog_bin_args_test
WHERE bin_id = ?
ORDER BY ts DESC, id DESC
LIMIT 1
`

	// Query 1: bind as "string" but preserve raw bytes
	argStr := bytesToRawString(targetBytes)
	t0 := time.Now()
	var id1 uint64
	var hex1, payload1 string
	err := db.QueryRow(sqlText, argStr).Scan(&id1, &hex1, &payload1)
	if err != nil {
		fmt.Printf("[runTwoQueries] query1 (STRING param) elapsed_ms=%.2f, ERROR=%v\n",
			float64(time.Since(t0).Microseconds())/1000.0, err)
	} else {
		fmt.Printf("[runTwoQueries] query1 (STRING param) elapsed_ms=%.2f, result=(id=%d, hex=%s, payload=%s)\n",
			float64(time.Since(t0).Microseconds())/1000.0, id1, hex1, payload1)
	}

	// Query 2: bind as bytes
	t1 := time.Now()
	var id2 uint64
	var hex2, payload2 string
	err = db.QueryRow(sqlText, targetBytes).Scan(&id2, &hex2, &payload2)
	if err != nil {
		fmt.Printf("[runTwoQueries] query2 (BYTES param)  elapsed_ms=%.2f, ERROR=%v\n",
			float64(time.Since(t1).Microseconds())/1000.0, err)
	} else {
		fmt.Printf("[runTwoQueries] query2 (BYTES param)  elapsed_ms=%.2f, result=(id=%d, hex=%s, payload=%s)\n",
			float64(time.Since(t1).Microseconds())/1000.0, id2, hex2, payload2)
	}

	fmt.Println("\n[runTwoQueries] Now check TiDB slow log for these two statements.")
	fmt.Println("  Search for: /* slowlog_bin_args_test */")
	fmt.Println("  Compare the `[arguments: ...]` section for STRING vs BYTES.\n")
	_ = targetHex
	return nil
}

func main() {
	db, err := openDB()
	if err != nil {
		log.Fatal(err)
	}
	defer db.Close()

	rows := 200
	if v := os.Getenv("ROWS"); v != "" {
		if n, err := strconv.Atoi(v); err == nil {
			rows = n
		}
	}

	if _, _, err := setupTable(db, rows); err != nil {
		log.Fatal(err)
	}
	if err := runTwoQueries(db); err != nil {
		log.Fatal(err)
	}

	// Small hint: print the slow log file variable if available
	var name, val string
	if err := db.QueryRow("SHOW VARIABLES LIKE 'tidb_slow_log_file'").Scan(&name, &val); err == nil {
		fmt.Println("[hint] tidb_slow_log_file:", val)
	} else {
		// Not always available depending on version/config
		_ = err
	}
	fmt.Println("[done]")
	fmt.Println("If you paste the two slow log entries here (just the arguments lines), I can help interpret what TiDB logged.")
	fmt.Println("Tip: grep for 'slowlog_bin_args_test' in the slow log file.")
	_ = hex.DecodeString // keep import stable in some environments
}