GAE Go1.11 の dev_appserver.py でホットリロードが効かないなーというとき、dev_appserver.py実行時に以下のメッセージが出力されてました。最後の1行が出力されているとホットリロードが効きません。

$ dev_appserver.py dev.yaml
INFO     2019-09-22 10:30:40,611 api_server.py:275] Starting API server at: http://localhost:51877
INFO     2019-09-22 10:30:40,613 instance_factory.py:170] Building with dependencies from GOPATH.
INFO     2019-09-22 10:30:40,618 dispatcher.py:256] Starting module "sample" running at: http://localhost:8080
INFO     2019-09-22 10:30:40,621 admin_server.py:150] Starting admin server at: http://localhost:8000
WARNING  2019-09-22 10:30:40,621 devappserver2.py:373] No default module found. Ignoring.
/Users/hoge/local/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/mtime_file_watcher.py:182: UserWarning: There are too many files in your application for changes in all of them to be monitored. You may have to restart the development server to see some changes to your files.

監視ファイル対象が多すぎるのが原因らしい。node_modulesとかホットリロードの対象にしなくて良いファイル/ディレクトリ除外して対応したいです。

結果

以下のように実行すればOKでした。

$ GO111MODULE=on dev_appserver.py dev.yaml --watcher_ignore_re ".*/node_modules/.*"

--watcher_ignore_re オプションで正規表現を使ってプロジェクト内で監視対象が除きたいものを指定できます
GO111MODULE=on を明示的に指定してないとdev_appserver.pyでは $GOPATH/src 配下のファイルたちも監視対象としてしまうようです（ GO111MODULE=auto もダメ）

けど、公式ドキュメントを読むとGo1.11からはローカルで動かすときにdev_appserver.pyの話は出てこなく go run と書いてあるからホットリロードは別の方法を検討しすべきなのかなぁ。

cloud.google.com

結果に行き着くまでの流れ

--watcher_ignore_re

無視するオプションないかなぁと思って確認すると --watcher_ignore_re というオプションがあるようだ。

$ dev_appserver.py --help
...
  --watcher_ignore_re WATCHER_IGNORE_RE
                        Regex string to specify files to be ignored by the
                        filewatcher. (default: None)
...

実行コマンドを以下のようにしてみた。

$ dev_appserver.py --watcher_ignore_re ".*/node_modules/.*"
...
/Users/hoge/local/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/mtime_file_watcher.py:182: UserWarning: There are too many files in your application for changes in all of them to be monitored. You may have to restart the development server to see some changes to your files.

まだダメだ...。

GO111MODULE=on

なぜだろうと dev_appserver.py のコードを読み始める。Printデバッグしながら頑張る。

まず、dev_appserver.pyからは <gcloudをインストールしたディレクトリ>/platform/google_appengine/google/appengine/tools/devappserver2/devappserver.py を実行してる。

ここからはdevappserver.py と同じディレクトリのファイルを見ていく。

devappserver.py => dispatcher.py (Dispatcherをインスタンス化) => dispatcher.py (startメソッド)という流れで処理が行われる。

dispatcher.py

dispatcher.pyの252行目。このメッセージは見たことがある。dev_appserver.pyを実行した時に3行目に出力されていたログメッセージだ。

log_message = 'Starting module "%s" running at: http://%s' % (
          module_configuration.module_name, _service.balanced_address)

その前の357行目。

    module_instance = module_class(

この部分でGAEのmodule（現在はserviceと呼ばれる）を表すオブジェクトを生成しているようだ。Printデバッグしたところ module_class は module.AutoScalingModule だったのでコードを読み進める。

module.py

module.py の1251行目。 Module クラスを継承してる。

class AutoScalingModule(Module):

1309行目。 __init__ の中。

    super(AutoScalingModule, self).__init__(**kwargs)

親クラスを見る。フィールドを初期化してるだけのコンストラクタだった。

dispatcher.pyに戻る。

      _service = self._create_module(module_configuration, service_port,
                                     ssl_port)
      _service.start()

インスタンスを生成して start メソッドを呼んでるので AutScalingModuleの start を確認。

  def start(self):
    """Start background management of the Module."""
    self._balanced_module.start()
    self._port_registry.add(self.balanced_port, self, None)
    if self._ssl_port:
      self._port_registry.add(self._ssl_port, self, None)
    if self._watcher:
      self._watcher.start()
    self.report_start_metrics()
    self._instance_adjustment_thread.start()

self._balanced_module.start() を呼んでる。あと self._watcher.start() も呼んでる。

ファイルが多すぎるとメッセージを出力していたのは mtime_file_watcher.py だった。 self._watcher は怪しい。self._watcher はなんだったか。

再びmodule.pyへ。

module.pyの600行目。ここで self._watcher をセットしてる。

    if self._automatic_restarts:
      self._watcher = file_watcher.get_file_watcher(
          [self._module_configuration.application_root] +
          self._instance_factory.get_restart_directories(),
          self._use_mtime_file_watcher)
      if hasattr(self._watcher, 'set_watcher_ignore_re'):
        self._watcher.set_watcher_ignore_re(self._watcher_ignore_re)
      if hasattr(self._watcher, 'set_skip_files_re'):
        self._watcher.set_skip_files_re(self._module_configuration.skip_files)
    else:
      self._watcher = None

file_watcher.get_file_watcher( ここだ！

file_watcher.py

file_watcher.pyの151行目

def get_file_watcher(directories, use_mtime_file_watcher):

この directories をprintしてみると

['/Users/hoge/work/sample-app', '/Users/hoge/go/src']

むむ、思ってるのと違うディレクトリが混ざっている。 /Users/hoge/go/src ...。これは GOPATH/src だな。これが監視対象ならそりゃ監視対象となるファイル数が多くなってしまう。どこで紛れ込んだのだろう。

またまたmodule.pyへ

さっきのmodule.pyに戻る。 get_file_watcher の direcotories 引数を指定している部分を見てみる。

[self._module_configuration.application_root] + self._instance_factory.get_restart_directories()

1つ目のリストが '/Users/hoge/work/sample-app' だから、おそらく self._instance_factory.get_restart_directories() これが怪しい。これが '/Users/hoge/go/src' を生成してるのではないか。

self._instance_factory は何か。 get_file_watcher を呼び出し箇所のすぐ上、597行目。

    self._instance_factory = self._create_instance_factory(
        self._module_configuration)

_create_instance_factory をチェック。193行目。

  def _create_instance_factory(self,
                               module_configuration):

追っていくと、runtime_factories.goの FACTORIES という辞書でruntimeごとに定義されている！

FACTORIES = {
    'go': go_factory.GoRuntimeInstanceFactory,
    'go111': go_factory.GoRuntimeInstanceFactory,
    'php55': php_factory.PHPRuntimeInstanceFactory,
    'php72': php_factory.PHPRuntimeInstanceFactory,
    'python': python_factory.PythonRuntimeInstanceFactory,
    'python37': python_factory.PythonRuntimeInstanceFactory,
    'python27': python_factory.PythonRuntimeInstanceFactory,
    'python-compat': python_factory.PythonRuntimeInstanceFactory,
    'custom': custom_factory.CustomRuntimeInstanceFactory,
}

go/instance_factory.py

今回のruntimeはgo111なので、 go_factory.GoRuntimeInstanceFactory が _instance_factory の実体だ。知りたかったのは self._instance_factory.get_restart_directories() なので確認。

...devappserver2/go/instance_factory.pyに get_restart_directories() を発見。

    # Go < 1.11 should always watch GOPATH
    # Go == 1.11 should only watch GOPATH if GO111MODULE != on
    # Go > 1.11 should only watch go.mod dir
    go_mod_dir = self._find_go_mod_dir(
        self._module_configuration.application_root)
    if os.getenv('GO111MODULE', '').lower() == 'on' and go_mod_dir:
      logging.info('Building with dependencies from go.mod.')
      return [go_mod_dir]
    logging.info('Building with dependencies from GOPATH.')

あー、この 'Building with dependencies from GOPATH.' というログもdev_appserver.pyを起動する時に見るやつ。

ん、ということはGO111MODULE=autoに対応してないのでは？とよく読むとコメントに書いてるー！

# Go == 1.11 should only watch GOPATH if GO111MODULE != on

ということで、以下のようなコマンドでdev_appserver.pyを実行する。

$ GO111MODULE=on dev_appserver.py local.yaml --watcher_ignore_re ".*/node_modules/.*"
INFO     2019-09-22 11:08:14,068 api_server.py:275] Starting API server at: http://localhost:52385
INFO     2019-09-22 11:08:14,070 instance_factory.py:168] Building with dependencies from go.mod.
INFO     2019-09-22 11:08:14,075 dispatcher.py:256] Starting module "sample" running at: http://localhost:8080
INFO     2019-09-22 11:08:14,079 admin_server.py:150] Starting admin server at: http://localhost:8000
WARNING  2019-09-22 11:08:14,079 devappserver2.py:373] No default module found. Ignoring.

キター！ホットリロードもできました！

おしまい

ちなみに、GO111MODULE=on だけでもいけるんじゃないかと思って試しましたが、今回は --watcher_ignore_re ".*/node_modules/.*" も必要でした。

bati11 の日記

GAE Go1.11 のdev_appserver.pyでホットリロードが効かないとき

結果