ほりひログ

所属組織の製品 (Azure とか) に関連する内容が多めだけど、個人の見解であって、所属組織を代表する公式情報ではないです。

Visual Studio Code で Azure Functions のデバッグができなくなった(けど直った)話

あまり需要はなさそうだけど記録用に*1

はじめに

タイトルの通り、ふと気づいたら Visual Studio Code 上で開発する Azure Functions のプロジェクトで、デバッグができなくなっていました。
症状としては、Node.js の関数プロジェクトを作りデバッグを開始すると、func コマンドは起動するものの、少したつと以下のダイアログが出て、デバッガの起動に失敗する、という感じです。

f:id:horihiro:20210823074408p:plain

曰く、「localhost の 9229 ポート (Node.js の inspector のポート ) につながらない」と。

Visual Studio Code 上での Node.js の Azure Functions のデバッグは、inspector を有効にした状態で Node.js の Worker (JavaScript の関数コードをロードして実行するプロセス) を 起動し、その Worker に Visual Studio Code からアタッチする形で行います。
なので、Worker の 9229 ポートにアタッチができず、デバッグが開始できない、と見てよさそうです。

対処方法

トラブル シューティングの過程は長くなったので、さっさと直したい人向けに先に結論を。

この現象の原因は Logic App 用の Visual Studio Code 拡張機能 Azure Logic Apps (Standard) が有効になっていることでした。

marketplace.visualstudio.com

この拡張機能を無効化すると、無事 Azure Functions のデバッグが可能になりました。

似た症状に遭遇した場合、Azure Logic Apps (Standard) が入っているか・有効になっているかを確認して、少なくとも Workspace レベルで無効にした方がよさそうです。

f:id:horihiro:20210823083834p:plain

原因についての考察はこちら

トラブルシューティング

ここからは、紆余曲折のトラブルシューティングの記録です。
結果としてあまり意味のないこともやっていました。

状況確認

まずは 9229 ポートにアタッチができない、という状況が何なのか確認です。

1. 9229 ポートは正しく使われているか?

netstat を使って、デバッグ開始前後の 9229 ポートの利用状況を見てみます。
netstat -nao でプロセス ID まで追えるので、9229 ポートが使われていれば、func から起動された Worker プロセスが正しく使っているのか、他のプロセスに占拠されているのかわかるはずです。

結果はこちら。

f:id:horihiro:20210823075621p:plain

デバッグ開始前と開始直後で確認しても、9229 ポート使っているプロセスは見つかりませんでした。
だれも使ってないのに Worker が 9229 ポートを使おうとしていません。

2. inspector は正常に起動しているのか?

次に Worker で inspector を有効にしようとしているのか確認してみます。
そもそも inpector を有効にしていなければ、アタッチできるはずがありません。

起動オプションは、タスク マネージャーで コマンド ライン 列を表示することで確認ができます。

inspector を有効にする場合は、--inspect=9229 が Node.js プロセスの起動オプションについているはずですが、結果はこの通り、--inspect オプションがありません。

f:id:horihiro:20210823075043p:plain

inspector を有効するオプションがないので、9229 ポートが使われるはずがありませんね。

# 正しくはこうです。

f:id:horihiro:20210823075005p:plain

Azure Functions 拡張機能デバッグ時に何をしているのか?

では Azure Functions 用拡張機能は、どのように --inspect オプションを付けているのでしょうか?

拡張機能のソース コードで、Node.js 用のデバッガ起動の処理、NodeDebugProvider.ts の 29 行目に --inspect オプションが書いてあります。

f:id:horihiro:20210823084753p:plain

github.com

この関数は、FuncTaskProvider.ts の以下の 箇所から呼ばれ、env というオブジェクトにセットされています。
環境変数っぽいですね。

github.com f:id:horihiro:20210823083502p:plain

環境変数名になる debugProvider.workerArgKey() は、上の NodeDebugProvider.ts に戻って 22 行目で languageWorkers__node__arguments と定義されています。

github.com

つまり、デバッグ用の func コマンドを起動する時、環境変数 languageWorkers__node__arguments の値として --inspect=9229 がセットして、func コマンドがその環境変数の値 --inspect=9229 を Worker である Node.js プロセスの起動オプションに渡す、というのが正しい動作です。

ちなみに languageWorkers__node__arguments についてググってみると、ここに書いてありました。

docs.microsoft.com

環境変数は設定されているのか?

環境変数 languageWorkers__node__arguments がカギになるので、デバッグに失敗した時の func コマンドの環境変数を確認したいところ。
でもタスク マネージャーでの確認方法がわからなかったので、Process Explorer で確認してみます*2

L または l から始まる環境変数で、それらしきものはありません。

f:id:horihiro:20210823095207p:plain

func プロセスに環境変数が設定されていないので、何らかの原因で上のデバッガ起動処理を通っていないようです。

# こちらも、こうなるのが正解です。

f:id:horihiro:20210823095339p:plain

拡張機能が動いていない???

デバッグ起動処理を通らない、となると、Visual Studio Code 自体のコードを追わないといけなく、正直やってられないので、ここは初心に戻って、一度 Azure Functions 拡張機能だけで試してみます。

と言っても、他の拡張機能をアンインストールして、、、とやると復元するのもつらくなるので、以下のように適当な空っぽのフォルダーを拡張機能用フォルダーとして起動します。

code --extensions-dir=C:\extensions_debug

すると、拡張機能がまっさらな状態の Visual Studio Code が起動するので、Azure Functions 拡張機能だけ入れます (といっても、いくつかの依存モジュールが自動で入ります)。

f:id:horihiro:20210823101316p:plain

このシンプルな状態で対象のフォルダーを開いて、デバッグを開始してみると、、、

f:id:horihiro:20210823101915p:plain

Debugger attached. できてますね。。。

Azure Functions 拡張機能と最低限の依存モジュールだけだと、正常にデバッガが起動します。
ということは、何か他の拡張機能を入れた時にこの現象が発生するっぽいので、ここからは元の環境に入れていた拡張機能一つ一つを、入れてはデバッガ起動、入れてはデバッガ起動、、、と繰り返してみます。

すると、Azure Logic Apps (Standard) を入れた時点でデバッガの起動に失敗することがわかりました。
こいつが犯人です。

考察編

Visual Studio Code の Azure Functions 拡張機能は、package.json で以下のように宣言して、特定の task をハンドルするよう要求しています。

        "taskDefinitions": [
            {
                "type": "func",
                "required": [
                    "command"
                ],
                "properties": {
                    "command": {
                        "type": "string"
                    }
                }
            }
        ],

github.com

この宣言により、その拡張機能がどのような type の task をハンドルするかを指定することができます。
上記の宣言の場合、以下のような typefunc の task が対象になります。

  {
    "type": "func",
    "command": "host start",
      :
  }

一方で、Logic Apps 用の拡張機能を見てみると (ソースコードリポジトリーが公開されていないので、インストールされた拡張機能を直接確認) 、package.json で全く同じ宣言、typefunc の task をハンドルすることを要求しています。

つまり Azure Functions 拡張機能と Logic Apps 拡張機能、2 つの拡張機能が同じ task をハンドルする宣言をしている状態です。

ここからは推測になりますが*3、Logic Apps 拡張機能を入れた時点からデバッガが正常に起動できなくなったことから考えると、何故か必ず先に Logic Apps 拡張機能の方で func の task が処理されてしまい、Azure Functions 拡張機能の方で --inspect=9229 を付与する処理まで到達してない、という流れのようです。

なので、Azure Functions 開発を進めるにあたっては、現時点では Logic Apps 拡張機能*4を無効にしておく方がよさそうです。

ちなみに、Logic Apps 拡張機能には Azure の古いロゴ f:id:horihiro:20210824090203p:plainも同梱されているので、この拡張機能を入れると activity bar のアイコンも古くなります。

*1:Twitter 等でも日本語で類似の現象を見つけられなかったので、特殊な状況かもしれない。

*2:ここで Process Explorer を使うなら、起動オプション確認もタスク マネージャーじゃなくてよかった、と後悔

*3:Visual Studio Code 自体と Logic Apps 拡張のソースコードを確認していないので。

*4:同じ task 処理を要求する拡張機能も同じ対応が必要