Monitoring of sql queries happening on Slack

A simple Go tip to get notifications about slow queries, unexpected errors, and other important logs.

My Slack bot prompted me about a SQL query that was running for a long time. I should fix it as soon as possible.

We cannot manage what we cannot measure. Every backend application requires us to monitor its performance on the database. If a particular query slows down as the amount of data grows, you must optimize it before it becomes too slow.

As Slack has become central to our work, it is also changing the way we monitor our systems. While we already have pretty good monitoring tools, it’s also a great idea to have a Slack bot tell us if anything in the system is trending away. For example, a SQL query takes too long to complete, or a fatal error occurs in a specific Go package.

In this blog post, we will tell you how to set up a simple logging system that already supports these features and an existing database library to achieve this goal.

Use logger

logger is a small library designed for use with Go libraries and applications. In this example we use its three important features:

It provides a simple timer for measuring performance.
Supports complex output filters, so you can select logs from specified packages. For example, you can tell the logger to only output from database packets, and only output timer logs that are longer than 500 ms.
It has a Slack hook, so you can filter and feed logs into Slack.
Let's see how to use a timer in this example. Later we will also use filters:

package main
import (
    "github.com/azer/logger"
    "time"
)
var (
  users = logger.New("users")
  database = logger.New("database")
)
func main () {
  users.Info("Hi!")
  timer := database.Timer()
  time.Sleep(time.Millisecond * 250) // sleep 250ms
  timer.End("Connected to database")
  users.Error("Failed to create a new user.", logger.Attrs{
    "e-mail": "[email protected]",
  })
  database.Info("Just a random log.")
  fmt.Println("Bye.")
}

There is no output when running this program:

The logger is silent by default, so it can be used inside the library. We simply use an environment variable to view the log: For example:

$ LOG=database@timer go run example-01.go
01:08:54.997 database(250.095587ms): Connected to database.
Bye

In the above example, we used the database@timer filter to view the timer log output in the database package. You can also try other filters, such as:

LOG=*: All logs
LOG=users@error,database: all error logs from users, all logs from database
LOG=*@timer,database@info: timer logs and error logs from all packages, and all logs from database
LOG=*,users@mute: All logs except users

Send logs to Slack

The console log is for the development environment, but we need the product to provide a friendly interface. Thanks to slack-hook, we can easily integrate it using Slack in the example above:

import (
  "github.com/azer/logger"
  "github.com/azer/logger-slack-hook"
)
func init () {
  logger.Hook(&slackhook.Writer{
    WebHookURL: "https://hooks.slack.com/services/...",
    Channel: "slow-queries",
    Username: "Query Person",
    Filter: func (log *logger.Log) bool {
      return log.Package == "database" && log.Level == "TIMER" && log.Elapsed >= 200
    }
  })
}

Let’s explain what we did in the above example:

Line #5: Set the inbound webhook url. The URL is linked here.
Line #6: Select the entry channel for the flow log.
Line #7: Displayed username of the sender.
Line #11: Use a stream filter to only output timer logs older than 200 ms.
Hope this example can give you a general idea. If you have more questions, check out the logger documentation.

A real example: CRUD

crud is an ORM-style class library for Go databases. One of its hidden features is that the internal logging system uses logger. This allows us to easily monitor running SQL queries.

Inquire

Here is a simple query that returns the username for a given e-mail:

func GetUserNameByEmail (email string) (string, error) {
  var name string
  if err := DB.Read(&name, "SELECT name FROM user WHERE email=?", email); err != nil {
    return "", err
  }
  return name, nil
}

Okay, this is too short, it feels like it's missing something, let's add full context:

import (
  "github.com/azer/crud"
  _ "github.com/go-sql-driver/mysql"
  "os"
)
var db *crud.DB
func main () {
  var err error
  DB, err = crud.Connect("mysql", os.Getenv("DATABASE_URL"))
  if err != nil {
    panic(err)
  }
  username, err := GetUserNameByEmail("[email protected]")
  if err != nil {
    panic(err)
  }
  fmt.Println("Your username is: ", username)
}

So we have a crud instance connected to the MySQL database via the environment variable DATABASE_URL. If we run this program, we will see a line of output:

$ DATABASE_URL=root:123456@/testdb go run example.go
Your username is: azer

As I mentioned earlier, the log is silent by default. Let's take a look at crud's internal log:

$ LOG=crud go run example.go
22:56:29.691 crud(0): SQL Query Executed: SELECT username FROM user WHERE email='[email protected]'
Your username is: azer

This is simple and enough for us to see how the query is executed in our development environment.

CRUD and Slack integration

The logger is designed for configuration management of application-level "internal logging systems". This means that you can have crud logs flow into Slack by configuring the logger at your application level:

import (
  "github.com/azer/logger"
  "github.com/azer/logger-slack-hook"
)
func init () {
  logger.Hook(&slackhook.Writer{
    WebHookURL: "https://hooks.slack.com/services/...",
    Channel: "slow-queries",
    Username: "Query Person",
    Filter: func (log *logger.Log) bool {
      return log.Package == "mysql" && log.Level == "TIMER" && log.Elapsed >= 250
    }
  })
}

In the above code:

We imported the logger and logger-slack-hook libraries.
We configure the logger logs to flow into Slack. This configuration covers all uses of the logger in the code base, including third-party dependencies.
We used a stream filter to only output timer logs from the MySQL package that are longer than 250 ms.
This usage can be extended beyond just slow query reporting. I personally use it to track important errors in specified packages, and also for statistics like new user logins or payment generation logs.

Packages mentioned in this article

crud

logger

logger-slack-hook

Tell us if you have any questions or suggestions

The above is the detailed content of Monitoring of sql queries happening on Slack. For more information, please follow other related articles on the PHP Chinese website!