emahiro/b.log

Drastically Repeat Yourself !!!!

GoogleCloudSDK アップデート後に aetest でインスタンスの起動失敗時の対処

2019/10/09 Google Cloud SDK を v266.0.0 に更新すると aetestの更新せずとも直ります。 2019/10/08 google.golang.org/appengine を最新版にすると本問題は解決します。
※詳しくは下部の追記参照

Google Cloud SDK を最新版にアップデートした際に aetest を使っていた appengine のテストが unable to find admin server URL と言われて落ちる(= 動かなくなってしまった)ようになってしまったので、その対処方法について記載しいます。
※ 最新版は Google Cloud SDK 265.0.0 です。

gcloud version
Google Cloud SDK 265.0.0

結論から先に言うと、最新の Google Cloud SDK のアップデートによって goapp コマンドが SDK から削除された(= Go1.9 のランタイムのローカルでの非サポートになった)ことにより、 appengine/aetest が壊れたことが原因です。

このエントリでは一時的な対処法と調査方法について記載します。

対処法

先に対処法について記載します。 aetest が起動しなくなったのは Google Cloud SDK が更新されたことによって、ローカルでも第一世代の appengine が起動しなくなったことが原因です。

そのため対処法は以下の2点のどちらかになると思います。

  • aetest のappengine の設定ファイルを Go1.11 の設定に合わせる
  • dev_appserver.py コマンドの内部で goroot-1.9 を使っている箇所にパッチを当てる。

aetest のappengine の設定ファイルを Go1.11 の設定に合わせる

なぜ appengine が起動しなくなったかは aetest 内の以下の設定を見ればわかります。

const appYAMLTemplate = `
application: %s
version: 1
runtime: go
api_version: go1
handlers:
- url: /.*
  script: _go_app
`

ref: https://github.com/golang/appengine/blob/5f2a59506353b8d5ba8cbbcd9f3c1f41f1eaf079/aetest/instance_vm.go#L278-L287

ここを以下のように Go1.11 に合わせた形式で修正します。

runtime: go111

dev_appserver.py コマンドの内部で goroot-1.9 を使っている箇所にパッチを当てる

※ この方法をとるに至った経緯については後述の調査方法に記載します。

Google Cloud SDKをアップデートしたことにより dev_appserver.py ないの goroot-1.9 を参照してる箇所が壊れてる(参照先のディレクトリが削除されている) ので aetest を走らせた時に appengine が起動する前に aetest が落ちてしまう、と言うのが原因だったので dev_appserver.py に置いて goroot-1.9 を参照してる箇所を変更します。

具体的には ~/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/go/application.py 内の以下の2箇所です。

@staticmethod
def _get_architecture(goroot):
    # 略
    for platform in os.listdir(os.path.join(goroot, 'pkg', 'tool')): # ← ここの goroot に 1.9 が存在しないのでエラーが発生して appengine が起動しない。
        # Look for 'linux_amd64', 'windows_386', etc.
        if '_' not in platform:
        continue
        architecture = platform.split('_', 1)[1]
        if architecture in architecture_map:
        return architecture_map[architecture]
    raise go_errors.BuildError(
        'No known compiler found in goroot (%s)' % goroot)

なのでこのループに入る前に darwin_amd64 を return 指定しまいます。(Macの場合)
Look for ... のコメントにどんな値が変えるのか記載してあったので多分わかるはず。

もう1箇所に多様な処理をしてる箇所がどうファイル内の def _get_pkg_path(goroot) の内部にもあるので、同様にパス検査のループに入る前に darwin_amd64_appengine で return してしまいます。

上記のパッチを dev_appserver コマンドに適用することで aetest のライブラリを修正しなくてもローカルで aetest の中で dev_appserver のインスタンスが起動するようになります。

調査方法

今回の対処を適用するに当たっての調査方法を記載します。

ここから先は個人の調査記録なので、興味のある方は読んでみてください。
内容はほぼ自分の脳内のダンプです。

ログをみる

まず調べるに当たって、エラーメッセージを見ました。

unable to find admin server URL と言うエラーが発生して appengine が起動しておらずこのエラー自体は以前も見かけたことがあって、素の dev_appsever が起動するかを確認するために普通に dev_appserver.py を叩いて appengine が起動するかチェックします。

これは起動したので、aetest を起動させた時のログをチェックすることにします。

aetest には SuppressDevAppServerLog があり、これは testerator がデフォルトで on にしているので aetest を起動した時に、素の dev_appserver を起動したときのようなログは出てきません。

ref: https://github.com/golang/appengine/blob/a37df1387b4521194676d88c79230c613610d5f4/aetest/instance.go#L31-L33

まずはこのフラグを off にしてログを出力する状態にして再度 aetest を走らせてみます。

go test ./app
# 略

Traceback (most recent call last):
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/dev_appserver.py", line 96, in <module>
    _run_file(__file__, globals())
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/dev_appserver.py", line 90, in _run_file
    execfile(_PATHS.script_file(script_name), globals_)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/devappserver2.py", line 600, in <module>
    main()
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/devappserver2.py", line 588, in main
    dev_server.start(options)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/devappserver2.py", line 360, in start
    options.api_host, apiserver.port, wsgi_request_info_)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/dispatcher.py", line 248, in start
    ssl_port)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/dispatcher.py", line 384, in _create_module
    ssl_port=ssl_port)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/module.py", line 1309, in __init__
    super(AutoScalingModule, self).__init__(**kwargs)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/module.py", line 598, in __init__
    self._module_configuration)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/module.py", line 231, in _create_instance_factory
    module_configuration=module_configuration)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/go/instance_factory.py", line 137, in __init__
    go_config.enable_debugging)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/go/application.py", line 118, in __init__
    self._arch = self._get_architecture(self._goroot)
  File "{{ $HOME }}/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/go/application.py", line 213, in _get_architecture
    for platform in os.listdir(os.path.join(goroot, 'pkg', 'tool')):
OSError: [Errno 2] No such file or directory: '{{ $HOME }}/google-cloud-sdk/platform/google_appengine/goroot-1.9/pkg/tool'
Exception TypeError: "'NoneType' object is not callable" in <bound method DatastoreEmulator.__del__ of <google.appengine.tools.devappserver2.cloud_emulators.datastore.datastore_emulator.DatastoreEmulator object at 0x10b88d250>> ignored
unable to find admin server URL

dev_appserver.py にパッチを当てる

OSError: [Errno 2] No such file or directory: '{{ $HOME }}/google-cloud-sdk/platform/google_appengine/goroot-1.9/pkg/tool'

ログをみたら一発で今回の課題となっていた箇所の原因らしきものが出てきました。 ここからどうやら Google Clodu SDK を更新したタイミングで goroot-1.9 が消えていたので appengine が起動しないと言うことがわかりました。

ここから 対処法2 の対応が思い浮かびます。

aetest の設定を修正する

対処法2 についてはログからなんとかく類推可能だと思うのですが、では 対処法1 に到るまでの過程ですが、goroot-1.9 でうまくいかないと言うところまでわかったので「もしかして App Engine の設定周りとか関係してる?」というところを仮説立てして aetest の設定ファイルをみに行きました。

その結果、第一世代 App Engine の設定のままだったのでここを Go1.11 の設定に書き直してみるか、という方法を思いつきました。

フォーラムやコミュニティに投稿がないかを見る

今回はエラーメッセージはすぐにわかっても最新のSDKの問題ですぐには検索には出てこない内容でした。
また、issue にもすぐには上がってこない内容でもあったので、検索から問題を特定するのはほぼできませんでした。

こうなった時はフォーラムなどのコミュニティに何かとっかかりになる情報が転がってないか見に行きます。

今回のケースに関してはすでに issuetracker に話題が上がっていました。解決方法までは上がってませんでしたが、、、

ref: https://issuetracker.google.com/issues/142004500

ハマったところ

dev_appserver のログを出すために aetest ないの SuppressDevAppServerLog をオフにするところで、プロジェクト内の vendor 配下のフラグをオフにしてましたが、aetest を走らせる時はローカルのモジュールキャッシュの中の aetest(testerator) を使っており、 $GOPATH/pkg/mod 配下にキャッシュされてるファイルを編集する必要がありました。

僕の個人環境の問題かもしれません...。

追記

Google に早く対応して欲しいところなので、続報はこちらに記載します。

追記1

PR は出ていたので早く merge されて欲しいです...
https://github.com/golang/appengine/pull/214

2019/10/08 追記 mergeされていましたので appengine のパッケージを更新するとて aetest でインスタンスが起動するようになります。

go get google.golang.org/appengine@latest

追記2

ノウハウにも情報上がってましたね。

github.com

追記3

devappserver の patch を gist に上げておきました。

https://gist.github.com/emahiro/d0b78d40475300561ad424b0b3741a1c#file-application-py-L194-L241