tech.guitarrapc.cóm

Technical updates

CircleCI 上で dotnet test の verbosity がオーバーライドできない問題とその対処

CircleCI で dotnet test、妙な挙動をすることは前回一つ紹介しました。

tech.guitarrapc.com

が、まさかまた一つネタが見つかるとは思わなかったです。

今回は dotnet test がこけた時の出力について。

更新

2020/6/17 本件の修正がマージされて修正されました。やったね。

github.com

目次

TL;DR

  • dotnet test< /dev/null を付けると出力も正常になる

まさかのこれと同じ対策で解消します。

tech.guitarrapc.com

問題

問題は2つあります。

  • CircleCI 上で dotnet test をしたときに、verbosity が quiet として実行される。(dotnet test のデフォルトverbosity は minimal)
  • CircleCI 上で dotnet test のConsole Logger の verbosity をオーバーライド指定して実行しても quiet から変わらない。

dotnet test のおさらい

問題を把握するためには、dotnet test の基本的な挙動を把握しておく必要があります。 ざっくり説明します。

ローカルで適当に xUnit のプロジェクトを作って、適当に失敗する Factを作りdotnet test で実行すると、テストの失敗個所が表示されます。 このテストの失敗個所が表示されるのは、verbosity レベルが minimal 以上の時で、dotnet test はデフォルトで minimal に設定されています。

$ dotnet test

Test run for C:\git\guitarrapc\dotnet-test-lab\tests\XUnitTestProject1\bin\Debug\netcoreapp3.1\XUnitTestProject1.dll(.NETCoreApp,Version=v3.1)
Microsoft (R) Test Execution Command Line Tool Version 16.3.0
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...

A total of 1 test files matched the specified pattern.
[xUnit.net 00:00:01.61]     XUnitTestProject1.UnitTest1.BoolFailTest [FAIL]
  X XUnitTestProject1.UnitTest1.BoolFailTest [7ms]
  Error Message:
   Assert.False() Failure
Expected: False
Actual:   True
  Stack Trace:
     at XUnitTestProject1.UnitTest1.BoolFailTest() in C:\git\guitarrapc\dotnet-test-lab\tests\XUnitTestProject1\UnitTest1.cs:line 33

Test Run Failed.
Total tests: 4
     Passed: 3
     Failed: 1
 Total time: 2.9317 Seconds

この結果の解像度をオーバーライドすることは、dotnet test 自体、あるいは Test Loggerごとに設定可能です。

  • dotnet test 自体のverbosity をオーバーライドするなら--verbosity 引数を使って dotnet test --verbosity [quiet|minimal|normal|detailed] を指定します。
  • dotnet test の特定のテストロガーをオーバーライドするなら --logger:ロガー名;verbosity=[quiet|minimal|normal|detailed] を指定します。

dotnet test 自体のverbosity を上げると、ビルドログなど見たくないログも増えてしまうのであまり好まれないと思います。 そのため通常は、Consoleロガーのverbosity だけ挙げて対処するでしょう。

たとえばConsoleLoggerのverbosity を normal にするならこのように指定します。 normal にしてお手元で実行すると、今まで dotnet test で出力されていなかった一つ一つのテストが成功、失敗にかかわらず出力されるはずです。

dotnet test "--logger:Console;verbosity=normal"

このことから、押さえておくべきは2つです。

  • dotnet test をverbosity 指定なしに実行したときは minimal を期待している
  • もし verbosity がちがった場合でも、--logger:console;verbosity=minimal などでオバーライドできることを期待している

何が問題なのか

CircleCI 上でローカルと同じように dotnet test を実行すると、失敗したテストの詳細が表示されないことに気がつきます。 これは verbosity が quiet の時の表示と合致し、ローカルでも dotnet test --verbosity quiet とすると再現します。 つまり、指定していないのになぜか verbosity がminimal ではなく quiet になっています。

$ dotnet test -c Debug

Test run for /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll(.NETCoreApp,Version=v3.1)
VSTest: Starting vstest.console...
VSTest: Arguments: dotnet exec /usr/share/dotnet/sdk/3.1.100/vstest.console.dll --testAdapterPath:/root/.nuget/packages/coverlet.collector/1.2.0/build/netstandard1.0/ --framework:.NETCoreApp,Version=v3.1 --logger:Console;verbosity=minimal --Diag:/root/project/bin/default/log.txt /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll
Microsoft (R) Test Execution Command Line Tool Version 16.3.0
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...

A total of 1 test files matched the specified pattern.
[xUnit.net 00:00:00.49]     XUnitTestProject1.UnitTest1.BoolFailTest [FAIL]
Test run in progress.VSTest: Exit code: 1

Exited with code exit status 1

また、このverbosityをオーバーライドしようとしても minimal から変更されず quiet 時の出力のままです。

#!/bin/bash -eo pipefail
dotnet test -c Debug "--logger:Console;verbosity=minimal"

Test run for /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll(.NETCoreApp,Version=v3.1)
VSTest: Starting vstest.console...
VSTest: Arguments: dotnet exec /usr/share/dotnet/sdk/3.1.100/vstest.console.dll --testAdapterPath:/root/.nuget/packages/coverlet.collector/1.2.0/build/netstandard1.0/ --framework:.NETCoreApp,Version=v3.1 --logger:Console;verbosity=minimal --Diag:/root/project/bin/default/log.txt /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll
Microsoft (R) Test Execution Command Line Tool Version 16.3.0
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...

A total of 1 test files matched the specified pattern.
[xUnit.net 00:00:00.49]     XUnitTestProject1.UnitTest1.BoolFailTest [FAIL]
Test run in progress.VSTest: Exit code: 1

Exited with code exit status 1

これはもちろん、dotnet test -c Debug --verbosity=minimal でも変わらず quiet のままです。

再現リポジトリ

再現リポジトリを組んであります。

github.com

ワークアラウンド

dotnet test< /dev/null を付けると、dotnet test のデフォルトverbosityが minimal に正常化されます。

また、verbosity のオーバーライドも正常に機能するようになります。

進捗

microsoft/vstest に報告してあるので、根本対処されるかはIssueの結果次第です。

github.com

まとめ

知らないとこれはまるのでは。

英語含めて記事が全然ないところみると、.NET で CircleCI やはり利用少ない気配があります。 知ってたけど。

前なら Azure Pipeline、今なら GitHub Actions を使う人が多くなっていくんだろうなぁと感じます。 これは Microsoft のdocs などでの露出に誘導されてるのも多分にあるんですかね? と思ったり思わなかったり。

余談: 調査する

当初、CircleCI ではなく ubuntu か何か環境問題か? と思ったのですが、ローカルで dotnet test したり、Docker 上でCircleCI と同じ dotnet-sdk:3.1 イメージを使ってテストを実行しても再現せず正常に指定した verbosity でオーバーライドができます。 この時点で環境問題の可能性は消えます。Dockerさいこー。

コードを確認すると、--Logger:"Console;verbosity=minimal" を渡せば解釈されることがわかります。

            var verbosityExists = parameters.TryGetValue(ConsoleLogger.VerbosityParam, out string verbosity);
            if (verbosityExists && Enum.TryParse(verbosity, true, out Verbosity verbosityLevel))
            {
                this.verbosityLevel = verbosityLevel;
            }

vstest/ConsoleLogger.cs at 5ef1f3b60404588b91fabb4fab22304ac88b108a · microsoft/vstest

他に何か原因があるのかといろいろ調べたけど、ことごとく該当せず....

そういえば自分のプロジェクトで、この問題が出ず正常にできているものがあるのでなぜかを見てみると、まさかの < /dev/null をしていて前のIssueと同じ対処で解決できています。

tech.guitarrapc.com

ということで、原因はよくわからないけど < /dev/null で出力まで改善されるという謎結果に....

なお、Diagnostics Logを --diag:diag.txt で出してみてみると、<dev/null を指定しなくてもちゃんと verbosity が設定した値になっているので、 < /dev/null で治るのは make sense といえばそうですが、謎い。

しかし、なんで /dev/null で出力というか挙動が変わるんだ.... stdin なんて何か色ない限りhandleしないと思うんだけど....?

pulumi でstateが事故ったときに過去のバージョンのstateを当てなおす

terraform もそうですが、Infrastructure as Code とかやってるとstate が壊れる日が来て軽く絶望します。

Pulumi で、誤った操作から state からリソースが200あまり消えたときにどのように復旧したのかをメモしておきます。

目次

TL;DR

  • アンドキュメントな REST API api.pulumi.com を使うことで指定したバージョンのstate がダウンロードできる
  • pulumi state import は神
  • pulumi refresh はpreview と違って認証さえ通れば実行されてしまうので注意
  • なお、terraform では同じことは起こらない.... Pulumi 独特の仕様に起因する...

状況

  • pulumi を CircleCI で実行中に、AWSアカウント情報の入れ替え中にビルドが実行される。
  • pulumi refresh が実行されたため、State がなにもリソースがないAWSアカウントと同期されて過半数が消える。
  • pulumi preview で大量の差分が出てup実行前に停止

この状況は、本来管理している AWS アカウント (Aとします) と同期していた Pulumi コードが、そのコードで管理していないAWSアカウント (Bとします) とrefresh で状態を同期しようとして、Bには何も管理しているリソースがないためにstate ファイルからリソース情報が消えました。

refresh であるため、実際のAWSアカウントにはA/Bともに影響が出ないのですが、state ファイルがコードと大幅に変わってしまっています。

復旧目標

pulumi refresh 前のState 状態に戻す。

前提情報

pulumi の state について知らないと何がどういうことかわからないまま取り組んでしまうのでおさらいです。

State とは

Pulumi のstate は、コードなどで表現されたあるべき状態がJSONとしてシリアライズされた状態です。 terraform でいうところの tfstate に相当します。

state ファイルは Pulumi の各種言語ホスト (Language Host) から生成され、クラウドやk8s プロバイダーに対してその状態になっているかチェック、適用を行います。

f:id:guitarrapc_tech:20200115181646p:plain
Pulumi state

www.pulumi.com

ポイントとなるのは、「コードと state 」及び「state とプロバイダー」がどのように一致をみているかです。 図の通り、プロバイダーはawsやk8s などの適用対象となります。

コードとstateのマッチング

urn によって一致をみています。 その言語上でどのような書き方をしようと、コードからキーとなるurnを state に拾いに行ってマッチングします。

  • コードのurn がstate にあれば、コードとstateで求める状態に変更がないかチェック (up-to-date / change)
  • コードのurn がstate になければ、新規で追加 (create)
  • コードのurn が消えて、state にだけあれば削除 (delete)

state とプロバイダーのマッチング

state に含まれる、そのリソースがプロバイダーで一意に特定されるid を見て合致を見ます。 ただし、state とプロバイダーの同期を refresh を使って明示的に行った時だけです。

state には必ず、対象のプロバイダーでリソースを一意に絞れるキーが含まれれます。 AWS であれば、多くの場合は arn であったり id や name がそれに相当します。

さて、Pulumi が terraform と違ってやりにくいのが、Pulumi は コードと state を見るというフローであることです。 terraform は、state と プロバイダーが自動的に同期をしていましたが、Pulumi では明示的に同期 (refresh) 操作を行わない限り state とプロバイダーの一致は取りません。

この辺りは以前書いた通りで、同じような動作が欲しければ pulumi refreshpulumi preview --refrepshpulumi up --refresh を行うことになります。

tech.guitarrapc.com

State が変化するタイミング

「state と コード」、「stateとプロバイダー」それぞれについてどのようにマッチングしているのかは確認できました。 では、どのような操作をすると State が変化するのでしょうか?

terraform なら tfstate が変化するのは apply や destroy、refresh のタイミングです。

Pulumi は、state とコード、stateとプロバイダーのそれぞれのタイミングで変化します。

  • state とコード: pulumi uppulumi destroy でstateに変化が適用される
  • state とプロバイダー: pulumi refreshpulumi xxxx --refresh でstateに変化が適用される

State を誤って更新しかねないタイミング

CI/CD をしていると、refresh や up は動作する環境で実行されるはずなので通常は事故が起こりにくいといえます。 多くの場合は、クラウド上のリソース同期を維持すため refresh を挟んで操作するのではないでしょうか?

  • pulumi refresh
  • pulumi preview
  • approve
  • pulumi refresh
  • pulumi up

このフローで事故が起こるとすると、例えばプロバイダーの認証が切り替わって別のプロバイダーときにCIが走って refresh が走ると、stateが吹き飛びます。 preview の時点で差分が莫大な数が出るので気づくでしょうが、refresh しているので state は後の祭りです。

例えばAWS アカウント A から アカウントB に認証が変わってしまったなど、発生する状況はいくつもあるでしょう。

あまりやることはないでしょうが、ローカルで実行しているときとはこういったアカウントの事故はよりカジュアルに起こりかねません。

過去バージョンの State を何とかして得る

refresh 前のstateにすればいいので、Pulumi Web でバージョンがとられているログから戻すべきバージョンはわかっています。

ドキュメントを見ると「現在のバージョンのState に関する記述」はあるものの、「過去バージョンのState に関して記述」がありません。 ではどうやってとるのか調べましょう。

NO: Pulumi Stack の State からは過去バージョンが export できない

pulumi は、pulumi stack export をするとstate が丸ごとエキスポートできます。 ということは、以前書いた通り stack 経由で state の Export > Import を行えば state は戻るはずです。

tech.guitarrapc.com

やった!セーフ! と思いきや、こういった事故の時に pulumi stack export が使えないことにすぐに気づきます。 過去バージョンを Export できないのです。

pulumi stack export なんて使えない子。

NO: Pulumi Web の Activityの過去実行履歴からState はダウンロードできない

Pulumi Web には Activity 画面があり、過去の実行ログが見えます。 Terraform Cloud の感覚だと、こういったところから state がダウンロードできそうですが、残念ながら Pulumi の実行ログ画面からは state をダウンロードできません。

f:id:guitarrapc_tech:20200115184310p:plain
CHANGESのログ右上のメニューはログの表示のみ

f:id:guitarrapc_tech:20200115184333p:plain
TIMELINEはログのみ

f:id:guitarrapc_tech:20200115184424p:plain
CONFIGURATIONは実行時のコンフィグを表示するだけ

まさかの過去バージョンの実行ログがあっても Stateが取れない

NOT YET: pulumi stack に 過去バージョンの stack export機能が追加されるかも

こういうリクエストは当然すぐ出てくるもので、現在 Issue にあります。

pulumi stack export で過去バージョンを指定できるようにできないかというものです。 最新バージョンの Stack だけ Export できても、いざというときには何の役にも立たないですからね。

github.com

CLIでオプションでもいいけど、Pulumi Web からダウンロードしたくないですか? Terraform Cloud のように。

OK: REST API を使って過去バージョンのstate をダウンロードする

Stack Exchange や Issue でも質問がなく、困ってしまったので Stack Exchange に投げたところ中の人から回答がありました。

stackoverflow.com

Pulumi には アンドキュメントながら REST API があります。 これを使うことで過去バージョンの Stack が exportできます。

現在ドキュメントにしようIssue が立っています。

github.com

以下のようなフォーマットでエキスポートできます。

curl -H "Authorization: token $PULUMI_TOKEN" https://api.pulumi.com/api/stacks/<org>/<project>/<stack>/export/<version>

PULUMI_TOKEN はいいとして、URL のパスは https://app.pulumi.com/ で ACTIVITY から該当処理の履歴を見ているときのURL からわかります。

例えば、Pulumi Web でその実行履歴が[https://app.pulumi.com/hoge/aws-sandbox/master/updates/352]というURL なら、API は [https://api.pulumi.com/api/stacks/hoge/aws-sandbox/master/export/352] となります。

Export したstate から復旧する

過去バージョンのstate が REST API からダウンロードできたら、話は簡単です。

  • pulumi stack import < downloadしたstate.json でインポート
  • pulumi refresh で state と プロバイダーの同期
  • pulumi preview でコードとstateに差分が出ないことを確認

お疲れさまでした。

まとめ

同じようなstate事故は、terraform だとあっという間に解決だけど、Pulumi 厳しい....です。 過去バージョンのstate の取り扱いは楽になる動きはあるので期待。

そもそも pulumi の state と プロバイダーの同期が一段介していて、terraform に比べても事故りやすい..... ので、いい加減 refresh の仕組み、もうちょっとなんとかならないですか (terraform だと発生しないだけどなぁ)

おまけ

State ファイルを解析するのに使っていた State ファイルの構造です。

gist.github.com

terraform for_each で data をいい感じで渡す

Terraform のfor_each は data でも使えます。 だから何だって感じですが、data でよく aws_iam_policy を拾うことがあるかと思いますが、for_each が使えれば 複数のpolicy を aws_iam_groupaws_iam_useraws_iam_role といったリソースに紐づけるあるあるがシンプルに定義できそうです。(できます)

一個一個書いてもいいんですけど、attach 程度は for_each でまとめてしまいたいですよね。

for_each くせ強くてうっかり忘れがちなのでメモしておきます。

目次

TL;DR

単純に書くか、あるいは型をうまく使えるか、どっちらか書きやすい方で書けばいいでしょう。

  • おとなしく [*] 経由でアクセスして primitive な list として認識させる
  • for_each の中の型を for を介することで認識させる

環境

  • terraform: 0.12.19
  • aws provider: 2.43.0

やりたいこと

IAM GroupにPolicy をアタッチすることを考えます。 aws_iam_group_policy_attachment を使うと複数のポリシーをいい感じに Group にアタッチできるのでこれを使うのが鉄板かと思います。

では Groupに data から取得した policy arnをいい感じに当てられてないか考えましょう。

事前定義

group と policy を次のように定義しておきます。

resource "aws_iam_group" "Administrators" {
  name = "Administrators"
  path = "/"
  lifecycle {
    prevent_destroy = true
  }
}

data "aws_iam_policy" "AdministratorAccess" {
  arn = "arn:aws:iam::aws:policy/AdministratorAccess"
}
data "aws_iam_policy" "ReadonlyAccess" {
  arn = "arn:aws:iam::aws:policy/ReadonlyAccess"
}

この group と policy のアタッチをどう書くといいでしょうか。

うまくいく方法

うまくいく方法から、2つほど思いつきます。

[*] 経由で指定する

シンプルに [*].arn を使って、複数リソースからのarnプロパティを指定します。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each   = toset(data.aws_iam_policy.AdministratorAccess[*].arn)
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}

複数の data リソースを取得するなら concat()すればできます。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each   = toset(concat(data.aws_iam_policy.AdministratorAccess[*].arn, data.aws_iam_policy.ReadonlyAccess[*].arn))
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}

[*] 外して toset([data.aws_iam_policy.AdministratorAccess.arn, data.aws_iam_policy.ReadonlyAccess.arn]) ではだめなのがムズカシイ

The given "for_each" argument value is unsuitable: "for_each" supports maps and sets of strings, but you have provided a set containing type dynamic.

for で型を指定する

arn は 型が stringと決まり切っているけど terraform 的には dyanmic になるので困ります。 GitHubに似たようなことで困っている人がいます。

github.com

ここで示されているように、setmap でdynamic として認識されているときに、型を明示するために一度 for を回しています。 この方法をつかうのは、次のようなエラーの場合です。

Error: The given "for_each" argument value is unsuitable: "for_each" supports maps and sets of strings, but you have provided a set containing type dynamic.

示されている方法は今回のケースでもうまくいきます。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each = {
    for k in [
      data.aws_iam_policy.AdministratorAccess.arn,
    ] : k => k
  }
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}

記述が冗長なのがいやですが、for を介することで型が明確に決まるので、単純に for_each にプロパティを充てただけだと dynamic などと言われてエラーの時はこの方法で突破できます。

複数の data を並べるのも問題ありません。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each = {
    for k in [
      data.aws_iam_policy.AdministratorAccess.arn,
      data.aws_iam_policy.ReadonlyAccess.arn,
    ] : k => k
  }
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}

ダメな方法

幾つか思いつく方法がやってみるとだめなことありませんか? ちょっと直感と反しててむむっとなります。

data.aws_iam_policy.AdministratorAccess

安直にやるとだめ。まぁそれはそうです。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each   = data.aws_iam_policy.AdministratorAccess
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value.arn
}
Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "AdministratorAccess"

This value does not have any attributes.


Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "{\n  \"Version\": \"2012-10-17\",\n  \"Statement\": [\n    {\n      \"Effect\": \"Allow\",\n      \"Action\": \"*\",\n      \"Resource\": \"*\"\n    }\n  ]\n}"   

This value does not have any attributes.


Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "/"

This value does not have any attributes.


Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "arn:aws:iam::aws:policy/AdministratorAccess"

This value does not have any attributes.


Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "Provides full access to AWS services and resources."

This value does not have any attributes.


Error: Unsupported attribute

  on modules/iam/group.tf line 27, in resource "aws_iam_group_policy_attachment" "Administrators":
  27:   policy_arn = each.value.arn
    |----------------
    | each.value is "arn:aws:iam::aws:policy/AdministratorAccess"

This value does not have any attributes.

arn を指定してみる

複数の property が入ってくるなら arn を指定すればよさそうと思うと、string なのでダメです。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each   = toset(data.aws_iam_policy.AdministratorAccess.arn)
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}
Error: Invalid function argument

  on modules/iam/group.tf line 25, in resource "aws_iam_group_policy_attachment" "Administrators":
  25:   for_each   = toset(data.aws_iam_policy.AdministratorAccess.arn)
    |----------------
    | data.aws_iam_policy.AdministratorAccess.arn is "arn:aws:iam::aws:policy/AdministratorAccess"

Invalid value for "v" parameter: cannot convert string to set of any single
type.

setかmapでないとダメなのでそれはそうです。 toset([]) を使って指定してもダメなのが、はじめにむむっと思うのではないでしょうか。

resource "aws_iam_group_policy_attachment" "Administrators" {
  for_each   = toset([data.aws_iam_policy.AdministratorAccess.arn])
  group      = aws_iam_group.Administrators.name
  policy_arn = each.value
}
Error: Invalid for_each set argument

  on modules/iam/group.tf line 10, in resource "aws_iam_group_policy_attachment" "Administrators":
  10:   for_each   = toset([data.aws_iam_policy.AdministratorAccess.arn])

The given "for_each" argument value is unsuitable: "for_each" supports maps
and sets of strings, but you have provided a set containing type dynamic.

PowerShell の -PipelineVariable を使おう

PowerShell v5 で追加された PipelineVariable に関して、本では説明していたのですがブログに書いていませんでした。 いい感じの例があったので、説明しておこうと思います

目次

TL;DR

  • PipelineVariable を使うと、パイプラインの中で一度 $x = $_ と書いて変数を保持していた処理が不要になります
  • Sort-Object のような集計系のCmdlet を使うとパイプラインの後続にわたる値の挙動が変わるので注意しましょう
  • Az モジュール使いにくい

対象のPowerShellコード

いい感じの Pipeline Variable の例があります。

この例を通して PipelineVariable を見てみましょう。

PipelineVariable とは

このコードの | % -pv vnet { $_ } は Pipeline Variable を使っています。

Pipeline Variable というのは、パイプラインからオブジェクトを次のパイプラインに送出するときに、そのオブジェクトを指定した変数に保持する機能です。

公式ではこう言っています。

新しい共通パラメーター PipelineVariable が追加されました。 PipelineVariable を使用すると、パイプされたコマンド (またはパイプされたコマンドの一部) の結果を変数として保存し、パイプラインの残りの部分に引き渡すことができます。

docs.microsoft.com

そのパイプライン時点のオブジェクトを変数に保持して何が嬉しいかというと、パイプラインがつながっている限り、直後ではない後続のパイプラインでもそのオブジェクトを変数経由で利用できます。 どういうことでしょうか?

PowerShellでは、通常パイプライン直後のスクリプトブロックでは流れてきたオブジェクトを 自動変数$_ 経由で読めます。

PS > ps | %{$_} | Get-Member


   TypeName: System.Diagnostics.Process

しかし、その次のパイプラインのスクリプトブロックでは、$_ の中身は前のパイプラインの中身に変わります。 例えば次のように、%{$_.Name} とProcess型のName プロパティ出力すると、後続のパイプライン | %{$_} では Process型ではなく String型に 変わります。

PS> ps | %{$_.Name} | %{$_} | Get-Member

   TypeName: System.String

PipelineVariable を使わないと、一連のPipelineの中であるパイプラインにおける変数を保持して後続に渡すときにハッシュテーブルや適当な入れ物に入れて渡すなど手間がかかります。

# こんなことはしたくない!
PS> ps | %{@{ps=$_;name=$_.Name}} | %{$_.ps} | Get-Member

PipelineVariables を使う例

↑の例以外にも、パイプラインの中でさらにパイプラインを書く時に、一番初めにパイプラインに入った$_ を思うように取れなくて一瞬引っ掛かったという人は多いのではないでしょうか?

何もしない無駄にそれっぽいのを例にします。 末尾の %{$_} では Process型が欲しいのですが、当然 String が来ます。

PS> ps | %{$_ | Where Name -eq "pwsh" | %{$_.Name.Replace("sh","hs")} | %{$_}}
pwhs
pwhs

この時にPipelineVariable を使わない場合、一時変数に入れてからやることが多いと思います。

PS> ps | %{$ps=$_; $_ | Where Name -eq "pwsh" | %{$_.Name.Replace("sh","hs")} | %{$ps}}

 NPM(K)    PM(M)      WS(M)     CPU(s)      Id  SI ProcessName
 ------    -----      -----     ------      --  -- -----------
    149   404.51     462.63      54.20    6820   1 pwsh
     71    55.12      96.09       1.95   13816   1 pwsh

PipelineVarible はこういった「パイプラインの後続で今のコンテキスト ($_) を使いたい」というシーンで機能します。 PipelineVarible に置き換えてみましょう。

PS> ps -pv ps | %{$_ | Where Name -eq "pwsh" | %{$_.Name.Replace("sh","hs")} | %{$ps}}

 NPM(K)    PM(M)      WS(M)     CPU(s)      Id  SI ProcessName
 ------    -----      -----     ------      --  -- -----------
    149   404.51     462.63      54.20    6820   1 pwsh
     71    55.12      96.09       1.95   13816   1 pwsh

%{$ps=$_;} と書いていた処理を、パイプラインを開始する前の ps コマンド時点に -pv ps と持ってきました。 このように、「パイプラインの中で $_ をいちいち変数に受け取っていた」という人は結構楽に書けるようになるはずです。

Aggregateする処理ではPipelineVariables の利用を気を付ける

Sort-Object のようにパイプラインをせき止める Aggregation 系の処理では、後段のパイプラインの結果は前段と変わります。 例えば先ほどのコードに意図的に Sort-Object を入れるとわかります。

PS> ps -pv ps | sort | %{$_ | Where Name -eq "pwsh" | %{$_.Name.Replace("sh","hs")} | %{$ps}}

 NPM(K)    PM(M)      WS(M)     CPU(s)      Id  SI ProcessName
 ------    -----      -----     ------      --  -- -----------
     31    29.86       9.57       0.42    9476   1 YourPhone
     31    29.86       9.57       0.42    9476   1 YourPhone

pwsh を拾っているはずなのに、YourPhone というプロセスに変わってしまいました。 YourPhone Sort-Object から渡った最後のオブジェクトに相当します。

PS> ps | sort | select -Last 1

 NPM(K)    PM(M)      WS(M)     CPU(s)      Id  SI ProcessName
 ------    -----      -----     ------      --  -- -----------
     31    29.86       9.57       0.42    9476   1 YourPhone

では、Sort-Object のようなパイプラインを一度せき止めるCmdletを挟みたい場合、どうすればいいのでしょうか? 簡単です、Sort-Object で PipelineVariable に割り当ててください。

PS> ps | sort -pv ps | %{$_ | Where Name -eq "pwsh" | %{$_.Name.Replace("sh","hs")} | %{$ps}}

 NPM(K)    PM(M)      WS(M)     CPU(s)      Id  SI ProcessName
 ------    -----      -----     ------      --  -- -----------
    148   403.27     461.28      59.45    6820   1 pwsh
     71    55.39      96.36       2.00   13816   1 pwsh

元コードからみる PipelineVariable

さぁ、PipelineVariable については概ね理解できたと思います。 元のコードを再度提示してみてみましょう。

AzVirtualNetwork | % -pv vnet { $_ } | % { $_.subnets } | select @{l="vnet";e={$vnet.name}},@{l="snet";e={$_.name}},addressprefix | sort vnet, snet

このコードの PipelineVariable は、先ほどの ps と違って一度 %{$_} を介しているように見えます。 どういうことか見てみましょう。

-pv vnet は早められる

もし、PipelineVariables を使うときに自分が % -pv vnet {$_} のように、ただ後続に $_ を流すだけの処理で PipelineVariablesを使うように書いていたら、その-pv、前段のコマンド時点に持っていくことができます。

AzVirtualNetwork -pv vnet | % { $_.subnets } | select @{l="vnet";e={$vnet.name}},@{l="snet";e={$_.name}},addressprefix | sort vnet, snet

元コードでは %{$_} でパイプラインを通るたびに新しく $vnet$_ を割り当てているのですが、それは AzVirtualNetwork | 時点でやっています。 ps の例で見せたように一番初めの Cmdletを実行した結果はパイプラインを通るのですが、その時点で PipelineVariable としてキャプチャできます。

単純な % {$_} をやるようなパイプラインが減るのは可読性、速度面の両面から嬉しいので検討するといいでしょう。

Select @{l={};v={}} をやめる

PipelineVariable とは関係ありませんが、Select @{l={};v={}} を使って PSObjectを生成している部分があります。

PSObject の生成方法としては、Select @{l={};v={}} 以外にも [PSCustomObject]@{} があります。1

Select-Object を使ったPSObject生成のメリットは、「プロパティの合成ができる」ことです。プロパティの合成は、ハッシュテーブルの後に書かれている addressprefix がそれにあたります。

select @{l="vnet";e={$vnet.name}},@{l="snet";e={$_.name}},addressprefix

一方で、[PSCustomObject]@{} を使うとハッシュテーブルから直接PSObjectに型変換します。 このやり方ではプロパティの合成はできず、自分で全プロパティに関してハッシュテーブルを定義しないといけません。 とはいえ、le のようなマジックキーに比べるとシンプルで速度も速く、可読性は高いでしょう。

% {[PSCustomObject]@{vnet=$vnet.name;snet=$_.name;addressprefix=$_.addressprefix}}

初めのコードをPSCustomObject に切り替えるとこうなります。

AzVirtualNetwork | % -pv vnet { $_ } | % { $_.subnets } | % {[PSCustomObject]@{vnet=$vnet.name;snet=$_.name;addr=$_.addressprefix}} | sort vnet, snet

まとめる

「-pv を早める」、「PSCustomObject に切り替える」の2つを組み合わせてみましょう。

AzVirtualNetwork -pv vnet | % { $_.subnets } | % {[PSCustomObject]@{vnet=$vnet.name;snet=$_.name;addr=$_.addressprefix}} | sort vnet, snet

幾分ワンライナー長い!読みたくない!感は減りました。

Azure環境の事前準備

もしコードを試す場合、Azureに VNet と Subnet が必要です。 せっかくなので、Az モジュールでサクッと組んでみましょう。

VNet作るだけなら料金かからないですしね。

AzureRm をアンインストールする

おわこん!それなのに Visual Studio で勝手に入る。

foreach ($module in (Get-Module -ListAvailable AzureRM*).Name |Get-Unique) {
   write-host "Removing Module $module"
   Uninstall-module $module
}

docs.microsoft.com

Az のインストール

代わりに Az モジュールを入れます。

Install-Module -Name Az -AllowClobber -Scope CurrentUser

docs.microsoft.com

vnet とかの準備

あとは Azure環境に ReousrceGroup、VirtualNetwork、Subnetを作ります。

$location = 'Japan East'
$rg = New-AzResourceGroup -Name test -Location 'Japan East'
$vnet = New-AzVirtualNetwork -Name test -ResourceGroupName $rg.ResourceGroupName -Location 'Japan East'  -AddressPrefix 10.0.0.0/16
$subnet = Add-AzVirtualNetworkSubnetConfig -Name a -VirtualNetwork $vnet -AddressPrefix 10.0.0.0/24
$vnet | Set-AzVirtualNetwork

これでコードを試せます。

AzVirtualNetwork | % -pv vnet { $_ } | % { $_.subnets } | select @{l="vnet";e={$vnet.name}},@{l="snet";e={$_.name}},addressprefix | sort vnet, snet

後片付け

リソースグループごとさくっと消せば全部消えます。

Remove-AzVirtualNetwork -Name $rg.Name

蛇足

Add-AzVirtualNetworkSubnetConfig で$vnet のプロパティを変更して (out相当の処理!?)、$vnet | Set-AzVirtualNetwork でVirtualNetwork に変更を適用しているの、とても書きにくいやり方ですね。

PowerShell っぽくないというか Azure に見られる特有に感じるのですが... 気のせいでしょうか。 Az モジュール、コマンドも探しにくく、Cmdletから使い方が予想できない使い方になってて、PowerShell の書く経験としては最悪に感じます。すごい、悲しい。

PowerShell 的には Addを使うと対象のオブジェクトに追加されることが多いので、それを期待している人は多いでしょう。Add-Content とか。

今回の場合、Add-AzVirtualNetworkSubnetConfig というCmdlet実行時点で $vnet に割り当てがされるのを期待するような気がほんわりします。(しない感じもある)

Add-AzVirtualNetworkSubnetConfig -Name a -VirtualNetwork $vnet -AddressPrefix 10.0.0.0/24

あるいは、VirtualNetworkSubnetConfig を作って、VirtualNetworkにAddするとか。(こっちのほうが納得感とCmdletからの予測ができそう)

$subnet = New-AzVirtualNetworkSubnetConfig  -Name a -VirtualNetwork $vnet -AddressPrefix 10.0.0.0/24 #実際には-VirttualNetwork パラメーターはない
Set-AzVirutalNetwork -SubnetConfig $subnet # こんなCmdlet もない

リソースを逐次分離したくてこうなったと思うのですが使い勝手が悪いのは Az Module でも改善されてないのでした。 az cli のほうが使いやすいので、私はもっぱら az cli です。

なお、AWS の Cmdlet 設計は秀逸で、どのCmdlet も aws cli と比較してもわかりやすい印象があります。 ただ、やはり型の扱いは若干めんどうさが表に出ていますが。


  1. ほかにもAdd-Member などいくつか方法がありますが本題ではないので省略します。

Datadog Log Management で Kubernetes の external-dns やkube2iam のログレベルを適切に扱いたい

Kubernetes のログを見るといえば、Datadog Log Mangement が楽なのですが時々ログメッセージが適切なレベルで扱われません。

そんなときによくやる「ログメッセージからレベルになるフィールドを取り出して Log Status として認識させる」ことを見てみましょう。

f:id:guitarrapc_tech:20200108100711p:plain
Before

f:id:guitarrapc_tech:20200108100721p:plain
After

目次

TL;DR

  • Custom Pipeline を使って、ログメッセージを構造化とLog Status の変更を行えばok。
  • ログメッセージがkey=value で構造化されているとさくさく構築できるので神

問題

Kubernetes に限らず、Log Management でログを取り込んだ時に意図と違ったログレベルとして認識されることがあります。

たとえば Kubernetes で external-dns を使っているとき、実行するものがないときは All records are already up to date というメッセージ出力されるのですが、Datadog Log Management では Status が Error となっています。

level=info msg="All records are already up to date"

しかしこのログは、Message に level=info とある通りエラーログではありません。 これをInfoとして扱いたいのでさくっと対処しましょう。

ログを見てみる

まずはログがどう認識されているのか見てみましょう。

f:id:guitarrapc_tech:20200108100351p:plain
何も実行するものがないときのログ

対象のログを見てみると、Log Status が Error となっていることがわかります。

f:id:guitarrapc_tech:20200108100325p:plain
Log Status が Error

また、ログも構造化されていません。

f:id:guitarrapc_tech:20200108100217p:plain
ログが構造化されていない

対処方針

external-dns のログは、level key でログレベルを表現しています。 こういったログへの追加対応は、Log Management のPipeline に追加のカスタムパイプラインを追加することでできます。 パイプラインには様々な処理(Processor)を設定できます。 今回はデフォルトのパイプラインで設定されたログレベルを書き換えたいので、Log Status Remapper を用いることでログに含まれる level キーの値を Log Status として認識させることができます。

Use this Processor if you want to assign some attributes as the official status. For example, it can transform this log:

f:id:guitarrapc_tech:20200108094843p:plain
before

f:id:guitarrapc_tech:20200108094853p:plain
after

docs.datadoghq.com

対応方針は次の通りです。

  • 新規パイプランを作る
  • ログメッセージがただの文字列として扱われているのでJSON として認識されるように構造化
  • 構造化したデータから対象の level key を拾ってLog Status を書き換える

パイプライン対応

Custom Pipeline を追加して、2つProcessorを追加していきます。

Custom Pipeline の追加

Datadog Agent のPipeline の後ろに新規Pipeline を追加します。

パイプラインを作成するときに、対象となるログを絞り込みます。 今回は All records are already up to date となっているログを絞りたいので、Source とメッセージで指定してみましょう。

source:external-dns message:"*All records are already up to date"

Processor の追加: Grok Parserで構造化する

パイプラインができたら、具体的な処理単位であるProcessor を追加します。 まずは、ただの文字列になっているログを構造化 (JSON) 変換するため、Grok Parserを用います。

https://docs.datadoghq.com/logs/processing/processors/?tab=ui#grok-parser

変換方法を考えるため、対象にしたいログメッセージを見てみましょう。

time="2020-01-07T09:49:07Z" level=info msg="All records are already up to date"

今回のログは 「key=value がスペースで羅列されている構造」とわかります。 こういった、文字列が key{何かの文字}value で構成されている場合、%{data::keyvalue} を使うだけでサクッと構造化できます。

external_dns_rule %{data::keyvalue}

docs.datadoghq.com

これでいい感じのJSON に変換されてました。

{
  "time": "2020-01-07T09:49:07Z",
  "level": "info",
  "msg": "All records are already up to date"
}

f:id:guitarrapc_tech:20200108095407p:plain
Grok Parser で構造化

Processor の追加: Log Status Remapperでログステータスとする

構造化したデータからステータスをとります。 もう一度Processor を追加して、今度は Log Status Remapper を使ってログステータスの差し替えを行います。

https://docs.datadoghq.com/logs/processing/processors/?tab=ui#log-status-remapper

level キーの値を使うので、対象キーに level を指定します。

f:id:guitarrapc_tech:20200108095722p:plain
Log Status Remapper で level キーを用いる

これでおしまいます。

Pipelineの結果を確認

Log Explorer でログの結果を見てみると、いい感じに Status が変わったことが確認できます。

f:id:guitarrapc_tech:20200108100010p:plain

先ほどなにもデータがなかった ATTRIBUTES にも、変換した構造化データがのっていることがわかります。

このパターンはちょくちょく使うので、さくっとできると捗るでしょう。

REF

github.com