backend
/
db
8
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Starting to migrate to unified logger

This commit is contained in:
Pavel Shevaev 2022-11-02 17:55:53 +03:00
parent 02ab848efe
commit daf3766a22
6 changed files with 65 additions and 128 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.gitignore vendored Normal file
View File

@ -0,0 +1 @@
tags

9
db.go
View File

@ -5,10 +5,11 @@ import (
"reflect"
"time"
"git.bit5.ru/backend/colog"
"git.bit5.ru/backend/dbr"
"git.bit5.ru/backend/errors"
"git.bit5.ru/backend/mysql"
"github.com/go-logr/logr"
)
type Settings struct {
@ -34,7 +35,7 @@ func (p *Pool) Close() {
}
type DBC struct {
Logger *colog.CoLog
Logger logr.Logger
P *Pool
//NOTE: it's not a 'connection', it embeds sql.Pool (dbr uses strange names for entities)
con *dbr.Connection
@ -71,9 +72,9 @@ func OpenPool(s Settings) *Pool {
return &Pool{DB: sqlDb, S: s}
}
func GetDBC(p *Pool, logger *colog.CoLog) *DBC {
func GetDBC(p *Pool, logger logr.Logger) *DBC {
logger = logger.Clone().AddPrefix("[" + p.S.Prefix + "] ")
logger = logger.WithValues("db", p.S.Prefix)
con := dbr.NewConnection(p.DB, nil)
sess := con.NewSession(&EventReceiver{logger: logger, s: p.S})

127
db_test.go
View File

@ -1,17 +1,19 @@
package db_test
import (
"log"
"os"
"testing"
"git.bit5.ru/backend/colog"
"git.bit5.ru/backend/db"
"git.bit5.ru/backend/errors"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"github.com/go-logr/stdr"
)
var logger = colog.NewCoLog(os.Stderr, "", 0)
var logger = stdr.New(log.New(os.Stdout, "", log.Lshortfile))
func getSettings() db.Settings {
//TODO: use ENV settings as well
@ -33,8 +35,8 @@ func TestDefaultClientCharsetAndCollation(t *testing.T) {
var result = make(map[string]string)
characterSets, err := dbc.DB().Query("show variables where Variable_name in ('character_set_client', 'character_set_connection', 'character_set_results');")
assert.Nil(t, err)
characterSets, err := dbc.DB().Query("SHOW VARIABLES WHERE Variable_name in ('character_set_client', 'character_set_connection', 'character_set_results');")
require.Nil(t, err)
for characterSets.Next() {
@ -47,7 +49,7 @@ func TestDefaultClientCharsetAndCollation(t *testing.T) {
}
collations, err := dbc.DB().Query("show variables where Variable_name = 'collation_connection';")
assert.Nil(t, err)
require.Nil(t, err)
for collations.Next() {
@ -76,7 +78,7 @@ func TestClientCharsetAndCollation(t *testing.T) {
dbLatin1 := db.GetDBC(pool, logger)
characterSets, err := dbLatin1.DB().Query("show variables where Variable_name in ('character_set_client', 'character_set_connection', 'character_set_results');")
assert.Nil(t, err)
require.Nil(t, err)
for characterSets.Next() {
var variableName string
@ -88,7 +90,7 @@ func TestClientCharsetAndCollation(t *testing.T) {
}
collations, err := dbLatin1.DB().Query("show variables where Variable_name = 'collation_connection';")
assert.Nil(t, err)
require.Nil(t, err)
for collations.Next() {
@ -113,9 +115,9 @@ func createFooTable(t *testing.T) {
defer p.Close()
_, err := dbc.DB().Exec("DROP TABLE IF EXISTS foo")
assert.Nil(t, err)
require.Nil(t, err)
_, err = dbc.DB().Exec("CREATE TABLE IF NOT EXISTS foo(id int not null)")
assert.Nil(t, err)
require.Nil(t, err)
}
func TestTransactionCommit(t *testing.T) {
@ -125,7 +127,7 @@ func TestTransactionCommit(t *testing.T) {
dbc := getDBC(p)
defer p.Close()
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1),(2)").Exec()
//let's try a fresh connection
@ -148,7 +150,7 @@ func TestTransactionCommitNestedAllOk(t *testing.T) {
dbc := getDBC(p)
defer p.Close()
//begin 1
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1),(2)").Exec()
//let's try a fresh connection
@ -156,7 +158,7 @@ func TestTransactionCommitNestedAllOk(t *testing.T) {
assert.EqualValues(t, 0, countFoos(t, dbc1))
//begin 2
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(3)").Exec()
//commit 2
dbc.Commit()
@ -182,7 +184,7 @@ func TestTransactionCommitNestedRollback(t *testing.T) {
dbc := getDBC(p)
defer p.Close()
//begin 1
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1),(2)").Exec()
//let's try a fresh connection
@ -190,7 +192,7 @@ func TestTransactionCommitNestedRollback(t *testing.T) {
assert.EqualValues(t, 0, countFoos(t, dbc1))
//begin 2
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(3)").Exec()
//rollback 2
dbc.Rollback()
@ -283,7 +285,7 @@ func TestTransaction(t *testing.T) {
dbc := getDBC(p)
defer p.Close()
assert.Nil(t, dbc.Transaction(func(dbs *db.DBC) error {
require.Nil(t, dbc.Transaction(func(dbs *db.DBC) error {
dbs.UpdateBySQL("INSERT INTO foo(id) VALUES(1),(2)").Exec()
//let's try a fresh connection
@ -350,7 +352,7 @@ func TestTransactionRollbackOnPanic(t *testing.T) {
func countFoos(t *testing.T, dbc *db.DBC) int {
var res int
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
return res
}
@ -360,23 +362,23 @@ func TestTransactionRollback(t *testing.T) {
p := getPool()
dbc := getDBC(p)
defer p.Close()
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
{
_, err := dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1),(2)").Exec()
assert.Nil(t, err)
require.Nil(t, err)
}
var res int
{
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 2, res)
}
dbc.Rollback()
{
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 0, res)
}
@ -384,7 +386,7 @@ func TestTransactionRollback(t *testing.T) {
dbc2 := getDBC(p)
{
err := dbc2.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 0, res)
}
}
@ -396,24 +398,24 @@ func TestTransactionNestedRollback(t *testing.T) {
dbc := getDBC(p)
defer p.Close()
//begin 1
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
{
_, err := dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1)").Exec()
assert.Nil(t, err)
require.Nil(t, err)
}
var res int
{
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 1, res)
}
//begin 2
assert.Nil(t, dbc.Begin())
require.Nil(t, dbc.Begin())
{
_, err := dbc.UpdateBySQL("INSERT INTO foo(id) VALUES(1)").Exec()
assert.Nil(t, err)
require.Nil(t, err)
}
//no real rollback happens here since we are in a 'bigger' transaction
@ -421,7 +423,7 @@ func TestTransactionNestedRollback(t *testing.T) {
dbc.Rollback()
{
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 2, res)
}
@ -430,75 +432,8 @@ func TestTransactionNestedRollback(t *testing.T) {
{
err := dbc.SelectBySQL("SELECT COUNT(id) FROM foo").LoadValue(&res)
assert.Nil(t, err)
require.Nil(t, err)
assert.EqualValues(t, 0, res)
}
}
//func makePlayers(t *testing.T, env *env.Env, amount int) []uint32 {
// var players []uint32
// mainDb := env.MainDb()
//
// for i := 0; i < amount; i++ {
// shardPlayer, err := dbshrd.CreateShardPlayer(env.Settings.DB_SHARDS, mainDb, 1)
// require.NoError(t, err)
// players = append(players, shardPlayer.Id)
// }
//
// //Note: There is only one test shard db, so the shard id = 1 for all players
// shardDb, err := dbshrd.GetShardDb(env.Logger, env.Settings.DB_SHARDS, 1)
// require.NoError(t, err)
// require.NotNil(t, shardDb)
// defer shardDb.Close()
//
// for i := 0; i < len(players); i++ {
// player := autogen.NewDataPlayer()
// player.Id = players[i]
// err = dbmeta.SaveRow(shardDb, player)
// require.NoError(t, err)
// }
//
// return players
//}
//func TestSelectBySQLWithChunkedIN(t *testing.T) {
// env := tests.NewEnvCleanStorage()
// defer env.Close()
//
// //Note: There is only one test shard db, so the shard id = 1 for all players
// shardDb, err := dbshrd.GetShardDb(env.Logger, env.Settings.DB_SHARDS, 1)
// require.NoError(t, err)
// require.NotNil(t, shardDb)
// defer shardDb.Close()
//
// var playersAmount = 100
// var playerIds []uint32
// playerIds = makePlayers(t, env, playersAmount)
//
// for chunkSizeForIN := 1; chunkSizeForIN <= 101; chunkSizeForIN++ {
// var totalIds []uint32
// fullChunksAmount := playersAmount / chunkSizeForIN
// modulo := playersAmount % chunkSizeForIN
// sql := "SELECT id FROM player WHERE 1 = ? AND id IN ? AND 2 = ?"
// builders := shardDb.SelectBySQLWithChunkedIN(sql, chunkSizeForIN, 1, playerIds, 2)
//
// require.Len(t, builders, fullChunksAmount+util.BoolToInt(modulo > 0))
//
// for queryIndex, builder := range builders {
// var queryIds []uint32
// _, err := builder.LoadValues(&queryIds)
// require.NoError(t, err)
// require.NotNil(t, queryIds)
// totalIds = append(totalIds, queryIds...)
//
// if queryIndex < fullChunksAmount {
// require.Len(t, queryIds, chunkSizeForIN)
// } else {
// require.Len(t, queryIds, modulo)
// }
// }
//
// require.Len(t, totalIds, playersAmount)
// }
//}

3
go.mod
View File

@ -3,10 +3,11 @@ module git.bit5.ru/backend/db
go 1.13
require (
git.bit5.ru/backend/colog v1.0.0
git.bit5.ru/backend/dbr v1.2.0
git.bit5.ru/backend/errors v1.0.0
git.bit5.ru/backend/mysql v1.0.0
git.bit5.ru/backend/res_tracker v1.1.1
github.com/go-logr/logr v1.2.3
github.com/go-logr/stdr v1.2.2 // indirect
github.com/stretchr/testify v1.8.1
)

5
go.sum
View File

@ -13,6 +13,11 @@ git.bit5.ru/backend/res_tracker v1.1.1/go.mod h1:ffjnItxqkGc6rxOK9XgrQDirGhmIBwo
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0=
github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag=
github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE=
github.com/go-sql-driver/mysql v1.4.1 h1:g24URVg0OFbNUTx9qqY1IRZ9D9z3iPyi5zKhQZpNwpA=
github.com/go-sql-driver/mysql v1.4.1/go.mod h1:zAC/RDZ24gD3HViQzih4MyKcchzm+sOG5ZlKdlhCg5w=
github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=

48
logger.go
View File

@ -3,28 +3,24 @@ package db
import (
"strings"
"git.bit5.ru/backend/colog"
"github.com/go-logr/logr"
)
// EventReceiver logs db stuff if neccessary
type EventReceiver struct {
logger *colog.CoLog
logger logr.Logger
s Settings
}
// Event receives a simple notification when various events occur
func (n *EventReceiver) Event(eventName string) {
if n.logger != nil {
n.logger.Output(colog.LDebug, 5, eventName)
}
n.logger.WithCallDepth(5).V(1).Info(eventName)
}
// EventKv receives a notification when various events occur along with
// optional key/value data
func (n *EventReceiver) EventKv(eventName string, kvs map[string]string) {
if n.logger != nil {
n.logger.Output(colog.LDebug, 5, eventName)
}
n.logger.WithCallDepth(5).V(1).Info(eventName)
}
// EventErr receives a notification of an error if one occurs
@ -42,23 +38,21 @@ func (n *EventReceiver) Timing(eventName string, nanoseconds int64) {
// TimingKv receives the time an event took to happen along with optional key/value data
func (n *EventReceiver) TimingKv(eventName string, nanoseconds int64, kvs map[string]string) {
if n.logger != nil {
sql := kvs["sql"]
sp := strings.Index(sql, " ")
if sp != -1 {
query := sql[:sp]
if n.s.LogLevel > 1 {
n.logger.Output(colog.LDebug, 6, sql)
} else {
if len(sql) > 50 {
sql = sql[:50] + "..."
}
if query == "SELECT" && n.s.LogLevel > 0 {
n.logger.Output(colog.LDebug, 6, sql)
} else {
n.logger.Output(colog.LDebug, 6, sql)
}
}
}
}
sql := kvs["sql"]
sp := strings.Index(sql, " ")
if sp != -1 {
query := sql[:sp]
if n.s.LogLevel > 1 {
n.logger.WithCallDepth(6).V(1).Info(sql)
} else {
if len(sql) > 50 {
sql = sql[:50] + "..."
}
if query == "SELECT" && n.s.LogLevel > 0 {
n.logger.WithCallDepth(6).V(1).Info(sql)
} else {
n.logger.WithCallDepth(6).V(1).Info(sql)
}
}
}
}