Redash 開発時のデバッグ方法あれこれ

# はじめに

[Redash](https://github.com/getredash/redash) の開発におけるデバッグ方法を「サーバサイド」「ワーカ」「フロントエンド」に分類して紹介します。

開発環境の構築については次のエントリを参考にしてください。

- [Redashの開発環境を作る手順 \- Qiita](https://qiita.com/kyoshidajp/items/d927b33cfff10c77c5bd)

# サーバサイド

Redash のサーバサイドは Python による軽量フレームワーク [Flask](http://flask.pocoo.org/) で書かれています。

## 注意

Redash では Python 2.7 を使っているのですが、一部で [`__future__`](https://docs.python.jp/2.7/library/__future__.html) モジュールを使っているファイルがあります。このモジュールを使うと記述が一部 Python 3 になるのですが、Python 3 では後方互換性が失われていています。シンタックスエラーになった場合は該当のファイルで `__future__` モジュールが使われていないか確認してください。

該当するファイル一覧は例えば [Github の検索結果](https://github.com/getredash/redash/search?utf8=%E2%9C%93&q=__future__&type=)から確認できます。

## `print` デバッグ

確認したい値を標準出力に出力する、単純かつ古典的な手法です。

次はモデル定義がまとまっている `models.py` で、ユーザ情報を辞書形式で返す [`User#to_dict`](https://github.com/getredash/redash/blob/release/3.0.x/redash/models.py#L390) にユーザの名前を出力する処理を追加した例です。デバッグ用文字列である事を分かりやすくするため、文字列 `debug: =======` を一緒に出力しています。

```redash/models.py
def to_dict(self, with_api_key=False):
    print "debug: ======="  # 追加
    print self.name         # 追加
    d = {
        'id': self.id,
        'name': self.name,
        'email': self.email,
```

上記の仕込みを行った後、トップページの右上にあるユーザアイコンをクリックして**「Edit Profile」**をクリックします。

<img width="670" alt="edit_profile.png" src="https://qiita-image-store.s3.amazonaws.com/0/36122/e4c8e74e-c758-1fba-8d1d-11a1c9a13115.png">

サーバを実行しているターミナルに次の様にユーザの名前が出力されます。

```
[2017-12-28 08:59:38,752][PID:34710][DEBUG][metrics] table=organizations query=select duration=2.63
[2017-12-28 08:59:38,752][PID:34710][DEBUG][root] Current organization: home (15) (slug: default)
[2017-12-28 08:59:38,756][PID:34710][DEBUG][metrics] table=users query=select duration=2.63
[2017-12-28 08:59:38,761][PID:34710][DEBUG][metrics] table=users query=select duration=2.74
debug: =======
kyoshida
[2017-12-28 08:59:38,763][PID:34710][INFO][metrics] method=GET path=/api/users/10 endpoint=user status=200 content_type=application/json content_length=366 duration=15.14 query_count=3 query_duration=7.99
[2017-12-28 08:59:38,765][PID:34710][INFO][werkzeug] 127.0.0.1 - - [28/Dec/2017 08:59:38] "GET /api/users/10 HTTP/1.1" 200 -
```

サーバを実行しているターミナルは [Redashの開発環境を作る手順 \- Qiita](https://qiita.com/kyoshidajp/items/d927b33cfff10c77c5bd) だと、次のコマンドを実行したターミナルになります。

```
bin/run ./manage.py runserver --debugger --reload --host 0.0.0.0
```

print デバッグとして、次のように [logging](https://docs.python.jp/2.7/howto/logging.html) モジュールを使う方法もあります。

```models.py
  def to_dict(self, with_api_key=False):
      logging.debug('=======')  # 追加
      logging.debug(self.name)  # 追加
      d = {
          'id': self.id,
          'name': self.name,
          'email': self.email,
```

該当処理が実行されると次のような出力が行われます。

```
[2017-12-28 10:43:16,225][PID:3375][DEBUG][metrics] table=users query=select duration=2.92
[2017-12-28 10:43:16,232][PID:3375][DEBUG][metrics] table=users query=select duration=3.47
[2017-12-28 10:43:16,233][PID:3375][DEBUG][root] =======
[2017-12-28 10:43:16,233][PID:3375][DEBUG][root] kyoshida
[2017-12-28 10:43:16,234][PID:3375][INFO][metrics] method=GET path=/api/users/10 endpoint=user status=200 content_type=application/json content_length=366 duration=20.34 query_count=3 query_duration=9.42
[2017-12-28 10:43:16,236][PID:3375][INFO][werkzeug] 127.0.0.1 - - [28/Dec/2017 10:43:16] "GET /api/users/10 HTTP/1.1" 200 -
```

ちなみに `logging` モジュールは事前に

```
import logging
```

を宣言しておく必要があります（`models.py` には宣言済み）。

## pdb

print デバッグは確認対象が特定できている場合には便利なのですが、対象があいまいだとアタリをつけて出力を確認し、再度対象を指定し直して実行、の流れを繰り返す事になります。

例えば先程の print デバッグでユーザの所属グループも確認したくなった場合、その定義を行い、再度ページを読み込む必要があります。

```models.py
def to_dict(self, with_api_key=False):
    print "debug: ======="
    print self.name
    print self.group_ids         # さらに追加
    d = {
        'id': self.id,
        'name': self.name,
        'email': self.email,
```

さらにユーザの id も確認したくなったらまた修正して読み込むのは面倒です。

また、出力が大量にあると `debug: =======` のような目印を入れていても見逃してしまいやすくなるため、grep　のようなフィルタリングを導入する必要が出てきてしまいます。

このようなケースで pdb を使うと効率的にデバッグを行えるようになります。

pdb の起動方法は、まず確認したい箇所に `import pdb; pdb.set_trace()` を定義します。その後、処理が該当の箇所を通るとデバッガが起動します。

先程の models.py の例では、次のように定義を追加します。

```models.py
def to_dict(self, with_api_key=False):
    import pdb; pdb.set_trace()  # 追加
    d = {
        'id': self.id,
        'name': self.name,
        'email': self.email,
```

対象ページを読み込むと、サーバを起動したターミナルでデバッガが起動します。

```
[2017-12-28 09:49:06,485][PID:67389][DEBUG][metrics] table=organizations query=select duration=6.34
[2017-12-28 09:49:06,486][PID:67389][DEBUG][root] Current organization: home (15) (slug: default)
[2017-12-28 09:49:06,493][PID:67389][DEBUG][metrics] table=users query=select duration=3.50
[2017-12-28 09:49:06,501][PID:67389][DEBUG][metrics] table=users query=select duration=4.37
> /Users/katsuhiko.yoshida/work/redash/redash/models.py(416)to_dict()
-> d = {
(Pdb) 
```

ちょっと見づらいので、続きはシンタックスハイライトを効かせて表示します。

```python
(Pdb) print self.name
kyoshida
(Pdb) self.name         # print なしでも値が確認できる
u'kyoshida'
(Pdb) self.group_ids    # コンテキストに合わせて値が確認できる 
[22, 23]
(Pdb) l                 # 周辺のソースコードを表示
411                 kwargs['email'] = kwargs['email'].lower()
412             super(User, self).__init__(*args, **kwargs)
413
414         def to_dict(self, with_api_key=False):
415             import pdb; pdb.set_trace()
416  ->         d = {
417                 'id': self.id,
418                 'name': self.name,
419                 'email': self.email,
420                 'profile_image_url': self.profile_image_url,
421                 'groups': self.group_ids,
(Pdb) n                 # 次の行に進む
> /Users/katsuhiko.yoshida/work/redash/redash/models.py(417)to_dict()
-> 'id': self.id,
(Pdb) c                 # 処理を再開
```

pdb の詳細についてはドキュメントを参照してください。

- [26\.2\. pdb — Python デバッガ — Python 2\.7\.14 ドキュメント](https://docs.python.jp/2.7/library/pdb.html)

ちなみに `import pdb; pdb.set_trace()` は `import pdb` と `pdb.set_trace()` の２つの処理を1行で実行しています。仕組みとして、2回目以降の `import` は読まれないので、次のように2回目以降だからと言って `import db` を除く必要はありません。

```models.py
def to_dict(self, with_api_key=False):
    import pdb; pdb.set_trace()  # 1個目
    d = {
        'id': self.id,
        'name': self.name,
        'email': self.email, ...}
    pdb.set_trace()  # import db 無し
```

# ワーカ

Redash ではワーカ（タスクキュー）として [Celery](http://www.celeryproject.org/) を使っています。
ワーカのデバッグにはサーバサイドと同様に print デバッグが使えますが、pdb には先に述べた通常の方法ではなく、Celery 用の指定が必要です。

次は Python データソースのクエリを実行する時のメソッド `run_query` にデバッグ用定義を入れた例です。

```redash/query_runner/python.py
 def run_query(self, query, user):
     from celery.contrib import rdb; rdb.set_trace() # 追加
     try:
         error = None

         code = compile_restricted(query, '<string>', 'exec')
```

サーバはコードを修正すると自動的にリロードされるのですが、ワーカは自動的にリロードされません。手動でプロセスを終了（終了シグナルの送信 Ctrl + C）して、再起動します。

```
[2017-12-28 12:41:15,648][PID:52756][WARNING][MainProcess] celery@JMPC-077.local ready.
[2017-12-28 12:41:20,101][PID:52828][WARNING][Worker-6] Remote Debugger:6905: Please telnet into 127.0.0.1 6905.

Type `exit` in session to continue.

Remote Debugger:6905: Waiting for client...

```

上記のようにデバッグ用のポート番号が出力されるので別のターミナルから telnet で接続します。

```
telnet localhost 6905
Trying ::1...
telnet: connect to address ::1: Connection refused
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
> /Users/katsuhiko.yoshida/work/redash/redash/query_runner/python.py(221)run_query()
-> try:
(Pdb)
```

接続成功後の pdb の操作は通常と同じです。

```
(Pdb) query
u'print "Hello world!"'
```

# フロントエンド

フロントエンドでは JavaScript フレームワークとして Angular が使用されています。ここでは Google Chrome の Dev Tools で確認する方法を紹介します。

## print デバッグ

例として、クエリ実行（**「Execute」**ボタンを押した）時に通る `executeQuery` 内でログを出力してみます。

```client/app/pages/queries/view.js
  $scope.executeQuery = () => {
    console.info($scope.query);   // 追加
    if (!$scope.canExecuteQuery()) {
      return;
    }
```

クエリを実行するとコンソールに `$scope.query` の値が出力されます。

<img width="595" alt="log_info.png" src="https://qiita-image-store.s3.amazonaws.com/0/36122/9b34deb4-107e-f34c-780c-0669483d162e.png">

console だとログ出力の一括オン・オフが切り替えられないので、`$logProvider` を使う方法もあります。詳しくは次を参考にしてください。

- [AngularJS $logProviderを使ってログの表示/非表示を切り替える \- Qiita](https://qiita.com/kappy0322/items/036d92dc2b4776bc7c0b)

## Chrome Dev Tools でブレークポイント設置

Chrome Dev Tools はより手軽で複雑なデバッグが行なえます。

まずは **Sources** タブで表示される開発環境のソースコードが下記のディレクトリにあるので確認します。

<img width="374" alt="webpack_dir.png" src="https://qiita-image-store.s3.amazonaws.com/0/36122/09bbd5eb-7697-2587-e3bc-34f207fcb647.png">

ブレークポイントとして、`pages/queries/view.js` の `$scope.executeQuery` 内にブレークポイントを置きます。

画面からクエリ実行を行うと該当のブレークポイントで処理が止まるので、その状況での変数や呼び出し元などが確認できます。
<img width="699" alt="chrome_break.png" src="https://qiita-image-store.s3.amazonaws.com/0/36122/57a58f31-5257-3ac8-6668-acccebc4ef8b.png">

### ブレークポイントを置いてのに処理が止まらない場合

開発用のURL（ポート番号）にアクセスしているかを確認します。デフォルトでは本番用は localhost:5000、開発用は localhost:8080 になります。

開発用の URL にアクセス出来ない場合は開発用ポートが空いているかを確認します。

次は開発用ポート番号が8080で空いている場合の出力例です。

```
netstat -an | grep 8080
tcp4       0      0  127.0.0.1.8080         *.*                    LISTEN
```

空いていない（上記のような出力が行われない場合）は起動します。

```
npm run start
```