go-sql-driver/mysqlを使ってMySQLにSQLを投げて、その結果をあれこれするAPIを作成していたときにちょっとはまったことのメモ。

問題の発覚

MySQLのタイムゾーンの確認。

show variables like '%time_zone%'
=>
|Variable_name|Value|
|system_time_zone|UTC|
|time_zone|SYSTEM|

MySQLのタイムゾーンがUTCなのにgo-sql-driver/mysqlを使ったSQLの実行結果を見るとJSTで返ってきてしまっていた。

MySQL: 2020-01-01 00:00:00 UTC
SQL実行結果のパース: 2020-01-01 00:00:00 JST

そこでmain.goに下記を書いて、Goアプリケーションでのタイムゾーンを確認。

main.go

fmt.Println(time.Now())
=> 2020-01-15 13:46:07.4988314 +0000 UTC m=+1.180576601

で返ってきていた。

Goアプリケーション内でもMySQLでもUTCなのになんでSQLの実行結果だけJSTになるんだ？？？

解決

http://kenzo0107.hatenablog.com/entry/2015/08/19/165310

上記の記事を見ていて気づいたが、

mysql.go

db, err := sql.Open("mysql", "xxxx:zzzzzzz@/dbname?parseTime=true&loc=Asia%2FTokyo")

としてしまっていたため、MySQLがUTCなのにGoで受け取ったときはそれにJSTのラベルをわざわざ付けてしまっていた…
そこで下記のように修正。

mysql.go

db, err := sql.Open("mysql", "xxxx:zzzzzzz@/dbname?parseTime=true")

単純な理由だけど1時間位はまったのでメモ。

Google Cloud Functions（以下Cloud Functions）でログレベルを分けたいことあります。

よく Go (go111) で Cloud Functions を利用するのですが、標準のlogパッケージを利用しても、ログレベルを出し分けできません。

• https://cloud.google.com/functions/docs/monitoring/logging#functions-log-helloworld-go
• https://cloud.google.com/logging/docs/setup/go

上記ドキュメントを参考にすると、 Cloud Functions では以下のような書き方になります:

func ExampleLogging(w http.ResponseWriter, r *http.Request) {
        ctx := context.Background()

        projectID := os.Getenv("GCP_PROJECT")

        client, err := logging.NewClient(ctx, projectID)
        if err != nil {
                log.Fatalf("Failed to create client: %v", err)
        }
        defer client.Close()

        logName := "cloudfunctions.googleapis.com%2Fcloud-functions"

        logger := client.Logger(logName).StandardLogger(logging.Info)
        logger.Println("info")
}

ちょっと煩雑ですね。また、logパッケージでの出力とは異なり、execution_id が付与されないため、functionの実行ごとのログがまとめて検索できません。

github.com/groove-x/cloudfunctions/log を使う

この問題を解決するサポートパッケージ github.com/groove-x/cloudfunctions/log を紹介します。

package function

import (
    "fmt"
    "net/http"

    "github.com/groove-x/cloudfunctions/log"
)

func ExampleLogging(w http.ResponseWriter, r *http.Request) {
    log.WithRequest(r)

    log.Debug("debug")
    log.Info("info")
    log.Warn("warn")
    log.Error("error")
}

シンプルですね！

結果はこちら:

log.WithRequest(r) でリクエストの情報をloggerに覚えさせることで、 execution_id や、トレースに関する情報が自動的に追加されます。

以上。

はじめに

Go AWS lambdaでRDSに接続する処理を書く必要が出てきた際
connectionを作るのは init() で良いのですが果たして close をいつどこで行えば良いのか悩み、公式のリファレンスを参照しましたが肝心のライフサイクルについて具体的な記載が見当たらないため、実際に各func内の実行回数のcountを取って調査しました。

検証

init() main() Handler() それぞれの実行countをグローバルに保持しその値を出力する検証コードを作成して実行してみます。

package main

import (
    "fmt"
    "github.com/aws/aws-lambda-go/lambda"
    "log"
)

var invokeCount = 0
var initCount = 0
var mainCount = 0

func init() {
    log.Print("init start")
    initCount++
    log.Print("init end")
}

func Handler() (string, error) {
    log.Print("handler start")
    invokeCount++
    log.Printf("invoke=%d, main=%d, init=%d", invokeCount, mainCount, initCount)
    log.Print("handler end")
    return fmt.Sprintf("invoke=%d, main=%d, init=%d", invokeCount, mainCount, initCount), nil
}

func main() {
    log.Print("main start")
    mainCount++
    lambda.Start(Handler)
    log.Print("main end")
}

実行結果は以下の通り

[1st request]
2020/01/15 06:34:47 init start
2020/01/15 06:34:47 init end
2020/01/15 06:34:47 main start
2020/01/15 06:34:47 handler start
2020/01/15 06:34:47 invoke=1, main=1, init=1
2020/01/15 06:34:47 handler end

[2nd request]
2020/01/15 06:43:17 handler start
2020/01/15 06:43:17 invoke=2, main=1, init=1
2020/01/15 06:43:17 handler end

[3rd request]
2020/01/15 06:43:19 handler start
2020/01/15 06:43:19 invoke=3, main=1, init=1
2020/01/15 06:43:19 handler end

初回起動でlambda.Start(Handler)を呼んだ際にHandler()をreceiverとしてserverに登録して、2回目以降はHandler()を呼ぶようになっているようです。

次にしばらく時間を置いて "main end" が呼ばれるかどうかを確認しましたがどうも出力されていないよう。
こちらはcontainer自体がkillされたのか、呼ばれているがログが出ていないのか判断がつかず。何かいい方法がないものか。

結論

• init()及びmain()が呼ばれるのは初回requestのみ

• 2回目以降はHandler()が直接実行される

• 一定時間経過後、container自体がkillされる？　lambda.Start() 以降の処理は実行されているかどうか不明。

Database connection の close を呼ぶタイミングがなさそう・・・
呼ばれるかどうかは不明ですが、main()内でlambda.Start()を呼ぶ前にdeferで定義するのが良いんだろうか。

ことのはじまり

普段のお仕事でも趣味でも、僕は頻繁にプロジェクトを cd コマンドで移動します。Androidのプロジェクトは ~/AndroidProjects に置いてますし、Goのプロジェクトは ~/go/src に置いてあります。
業務はWindowsで、パスの長さ回避のためにCドライブ直下に顧客ごとにディレクトリを切ったりしてその中にプロジェクトがたくさんあったりします。OSSコードを読んだりプルリクエストを送るために別の人のプロジェクトをcloneすることもたくさんあります。

そんなこんなでいろいろなディレクトリでソースコードを管理していると移動が大変面倒なわけです。

そこでghqと言うツールがあります。
ghqはGo製のコマンドツールで、リモートリポジトリを一元管理するためのツールです（ネーミングセンスやばくない？
ghqを使うことによって所定のディレクトリでプロジェクトを管理するようになり、またfzfやpecoなどのツールと連携することで爆速で移動もできるようになると言うものです。

僕もこれを最初使おうと思ったのですが。。。
ghqはあくまでリポジトリの管理が主目的のツール。僕はプロジェクトのディレクトリ配置は今のままが気に入っています。Androidは ~/AndroidProjects におきたいし、WindowsではCドライブ直下におきたいこともあります。そしてGoはやっぱり ~/go/src で管理したいです。

そうなると欲しいのはプロジェクトの一元管理ではなく、たくさんあるプロジェクトに一発で「ぽい」っと移動できるGo製のツール「poi」でした。

What is poi

poiは ghq list に着想を得たツールです。poiは poi.yml ファイルで指定されたディレクトリを探索して、Gitプロジェクトのフルパスを列挙します。ただそれだけです。

# projects - you can specify the directories had projects managed by git.
projects:
  - ~/AndroidStudioProjects
  - ~/IdeaProjects
  - ~/source
  - ~/go/src

このような感じのymlファイルを ~/.config/poi.yml として配置します。そして poi コマンドをどこでもいいので実行すると、こんな感じで指定ディレクトリ配下にあるGitプロジェクトが一瞬で全部出てきます。ファンタスティック！

しかしこれだけだと何にもできません。poiはぽいっとプロジェクトを出力してくれるだけです。そこで、fzfやpecoなどのfuzzy-finderツールを使います。

fzfなどのfuzzy-finderツールは、標準出力で受け取ったリストを対話的に絞り込みできるツールです。これにpoiから取得したプロジェクトを渡してあげて、cdで移動すれば爆速で移動できるようになります。

cd "$(poi | fzf)"

もういっちょ。aliasにも登録してあげましょう！

alias po = 'cd "$(poi | fzf)"'

はやい
もはやポイッとする間も無く「ぽ」でプロジェクトに移動できちゃいます。

poiを使ってみよう！

poiのインストールはとっても簡単。最新のGo言語をインストールしてgo getしたらもう使えます。

go get -u github.com/yasukotelin/poi

これでインストールは完了です。

poi と打つともう動くはずです。まだ設定ファイルがない場合は、見つからないよエラーが出ると思います。下の手順で設定ファイルを配置してください。
poi コマンドがないよエラーが発生した場合は、Go getしたバイナリへのパスが通ってないと思います。~/go/bin をパスに通して実行してみてください。

poiは poi.yml ファイルで指定されたディレクトリを対象にGitプロジェクトを探索します。まず、 ~/.config/poi/poi.yml を作成します。Windowsの場合も同じ場所です（%HOME%\.config\poi\poi.yml）。

記載の仕方はこんな感じ。とってもシンプル。

# projects
projects:
  - ~/AndroidStudioProjects
  - ~/IdeaProjects
  - ~/source
  - ~/go/src

# others
others:
  - ~/.config/nvim
  - ~/.config/poi

projects: に好きなだけディレクトリを指定してください。とは言え探索量が増えると困るけど。指定されたディレクトリをルートとしてGitプロジェクトを探索します。ちなみに、 .git ディレクトリを見つけてもさらに配下を見るので、サブプロジェクトも見つかる。はずです。

さらに、Gitのプロジェクトじゃないし、なんなら何のプロジェクトでもないんだけど、よく頻繁に移動するディレクトリにもpoiっと移動したいという場合むけに others: があります。
例えば、 ~/.config/nvim ディレクトリはNeoVimの設定ディレクトリでよくアクセスしますし、他にもブログ記事を管理しているディレクトリとか、直接飛びたいディレクトリって結構あります。そう言うものをここに指定してください。プロジェクトに混ぜてそれらもフルパスを返してくれます。なので、 poi+fzfでプロジェクト以外のところにも飛んで行けるようになりますよ?

Windowsでも動くよ！

poi自体はWindowsのコマンドプロンプトでもPowerShellでも、git bashでもしっかりと動きます。

肝心のfzfやpecoとの連携の部分ですが、powershellの場合は cd "$(poi | fzf)" もバッチリです。コマンドプロンプトの場合はfzfの結果をcdに渡すやり方が分からず。。あと、git bashでの連携のやり方もちょっと分からなかったので知っている方いましたら教えてください?‍♂️

また、Macだと高速に動作するのですが、Windowsだとかなり遅い感じになってしまいました。
それでは意味がないので色々調べてると、ghqへの速度改善のプルリクエストのツイートをたまたま発見しました。探索の関数をGo言語標準のものではなくライブラリを使用するように変更するもので、poiもこちらのsaracen/walkerを使用するように変更した結果、Macでは一瞬、Windowsでもなかなかに速くなりました。一瞬とは行かないまでも、快適だと思います。

poi.yml ファイルにフルパスで指定する場合は、バックスラッシュをエスケープして指定してください。
~から相対パスの場合は/指定でも大丈夫です。

# projects
projects:
  - ~/AndroidStudioProjects
  - ~/IdeaProjects
  - ~/source
  - ~/go/src
  # Cドライブから指定はこんな感じ
  - C:\\Work

# others
others:
  - ~/.config/nvim
  - ~/.config/poi

終わりに

poi自体は非常にシンプルなコマンドです。ただ標準出力するだけなので、移動だけじゃなくて直接エディタで開いたり、色々できるかもしれません。
また、僕は探索処理のど素人です。おそらく非常にあれな実装になっていると思います。より一瞬で移動できるように改善していきたいと思ってます?

では、良きpoiライフを！