RequestId付きのRailsのログをvimで便利に見る

Railsではconfig.log_tagsuuidを指定することでRequestId付きのログを出力できます。 RequestIdつきのログを確認するとき、以下のような欲望があります。

  1. 特定のパターンでフィルタしたい
  2. マッチした行だけでなく、関連するRequestIdの行を全部表示し、リクエスト全体の流れが知りたい。

例えば特定のControllrのActionのログをフィルタしたいときや、特定のユーザーのログを見たいときなどです。 vimで関数を定義することで実現できたので記しておきます。

検証環境:

Railsのログはconfig/application.rbとかに以下のようなconfigがはいってるやつです。

config.log_tags = [:uuid]

関数

VimのvimrcとかNeovimのinit.vimに以下の関数を雑に追加してみます。

function! RailsLogGrep(pattern)
  let l:pattern = empty(a:pattern) ?  expand("<cword>") : a:pattern
  execute 'Ag'.' '.l:pattern.' %'
  execute 'ccl'

  let l:uiid_pattern = '\('
  for d in getqflist()
    let l:uiid = matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}')
    if !empty(l:uiid)
      let l:uiid_pattern = l:uiid_pattern.matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}').'\|'
    endif
  endfor
  let l:uiid_pattern = l:uiid_pattern[:-3].'\)'
  execute 'Ag'.' '.l:uiid_pattern.' %'
  execute 'resize 50'
endfunction

command! -nargs=1 Rl call RailsLogGrep(<f-args>)

やってることは

  • Agコマンドで該当のパターンで検索し
  • getqflist()で該当行のテキスト一覧を取得
  • 各行のRequestIdを取得し再Ag

vimgrep版の関数は以下(遅い)

function! RailsLogGrep(pattern)
  let l:pattern = empty(a:pattern) ?  expand("<cword>") : a:pattern
  execute 'vimgrep'.'/'.l:pattern.'/j %'

  let l:uiid_pattern = '/\('
  for d in getqflist()
    let l:uiid = matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}')
    if !empty(l:uiid)
      let l:uiid_pattern = l:uiid_pattern.matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}').'\|'
    endif
  endfor
  let l:uiid_pattern = l:uiid_pattern[:-3].'\)/'
  execute 'vimgrep'.' '.l:uiid_pattern.'j %'
  execute 'cwin 50'
endfunction

結果

白画面ですんません。

f:id:koyamay:20181222143002g:plain
Railsログフィルタの実行

以下のようなログがあるとします。

[2018-09-24 18:26:21.929801 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Started GET "/ja/questions/33" for 127.0.0.1 at 2018-09-24 18:26:21 +0900
[2018-09-24 18:26:21.975337 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Processing by Web::QuestionsController#show as HTML
[2018-09-24 18:26:22.533603 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Completed 200 OK in 558ms (Views: 479.9ms | ActiveRecord: 28.5ms)

[2018-09-24 18:38:34.053576 #17152]    INFO: [127.0.0.1] [d02950c9-437d-4680-a4ca-6b7d73b20fc1] Started GET "/ja/questions" for 127.0.0.1 at 2018-09-24 18:38:34 +0900
[2018-09-24 18:38:34.053576 #17152]    INFO: [127.0.0.1] [d02950c9-437d-4680-a4ca-6b7d73b20fc1] Processing by Web::QuestionsController#index as HTML
[2018-09-24 18:38:34.549076 #17152]    INFO: [127.0.0.1] [d02950c9-437d-4680-a4ca-6b7d73b20fc1] Completed 200 OK in 455ms (Views: 431.3ms | ActiveRecord: 2.4ms)

[2018-12-10 19:23:06.690552 #45343]    INFO: [127.0.0.1] [0a19d272-6633-4389-9aec-749c2820391e] Started GET "/ja/notebooks/65" for 127.0.0.1 at 2018-12-10 19:23:06 +0900
[2018-12-10 19:23:06.720870 #45343]    INFO: [127.0.0.1] [0a19d272-6633-4389-9aec-749c2820391e] Processing by Web::NotebooksController#public as HTML
[2018-12-10 19:23:07.960144 #45343]    INFO: [127.0.0.1] [0a19d272-6633-4389-9aec-749c2820391e] Completed 200 OK in 1239ms (Views: 944.3ms | ActiveRecord: 102.3ms)

:Rl Web::QuestionsController\\\#showを実行すると、以下のようにフィルタできます。 (注: ag.vim#などエスケープ方法が独特です 参考)

[2018-09-24 18:26:21.929801 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Started GET "/ja/questions/33" for 127.0.0.1 at 2018-09-24 18:26:21 +0900
[2018-09-24 18:26:21.975337 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Processing by Web::QuestionsController#show as HTML
[2018-09-24 18:26:22.533603 #17152]    INFO: [127.0.0.1] [8f915b0a-69ca-4496-8f31-49ccb73b97da] Completed 200 OK in 558ms (Views: 479.9ms | ActiveRecord: 28.5ms)

個人的には便利です。 更に自分の場合は以下の様にLeaderにmappingし、カーソル上の単語でフィルタできるようにしています。

nnoremap <silent> <Leader>rl :<C-u>Rl('')<CR>

おまけ: リモートサーバーのログファイルもフィルタしたい(WIP)

VimはSCPを用いてリモートサーバー上のファイルにアクセスすることができます。

vim scp://ユーザ名@リモートホスト(IPアドレス)//編集対象のファイル

orebibou.com

例えばステージングや本番環境のログをSCPを使ってアクセスし、みたい箇所をフィルタしたい場合、ag.vimは使えません。 :vimgrep pattern %はうまく動くのですが、:Ag pattern %はうまくSCP経由で開いたファイルに対して検索をかけることができないからです。 かといってvimgrepを使うと遅いので、以下のように:vをつかって該当行以外を削除する方法で対応しています。

function! RailsLogGrepRemote(pattern)
  let l:pattern = empty(a:pattern) ?  expand("<cword>") : a:pattern
  execute 'vimgrep'.'/'.l:pattern.'/j %'

  let l:uiid_pattern = '/\('
  for d in getqflist()
    let l:uiid = matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}')
    if !empty(l:uiid)
      let l:uiid_pattern = l:uiid_pattern.matchstr(d.text, '\x\{8}-\x\{4}-\x\{4}-\x\{4}-\x\{12}').'\|'
    endif
  endfor
  let l:uiid_pattern = l:uiid_pattern[:-3].'\)/'
  execute 'v'.l:uiid_pattern.'d'
endfunction

にしても遅すぎるので、いいやり方無いかなーと悩んでいる感じです。