畑の土作りのための石の除去について

家の敷地などで初めて畑を作って家庭菜園的なことをしようとした場合、まず初めに問題になるのが、土。

それまで畑として使っていなかった土地だった場合、通常、畑として使えるような土の状態ではないはずなので、肥料が足りないとかそういうレベルの話ではなく、石やら何やら、土壌に含まれる土以外のものをまず除去する必要がある。

注意しなければいけないのが、土の上に転がっている、見える部分の石を除いたぐらいじゃあまり意味がないこと。対象のエリアの土が深さ 3, 40 cm ぐらいまでどのような物で構成されてるのか、少なくとも確認ぐらいは必要。

自分の場合

自分の場合、家の敷地に建っていた物置を 40 年ぶりぐらいに壊して、その跡地を畑として使うことになった。

一応、物置を業者の人に解体してもらった時に、跡地の土についても機械で掘り起こしてもらってカチカチの状態からそれなりに耕して柔らかくしてもらったはずなのだが、結果から言うとこれだけじゃ全く駄目だった。

なお、自分は土いじりは素人なので、以下もそれを前提に読んでもらう必要がある。

一番最初に(何も考えずに)やったこと

最初、パット見の印象は、「石が多いな」と言うこと。なので、表面に転がってた石を手で拾って除去した。

この時の装備は、汚れても良いスニーカー+素手と言う今から考えるとアホみたいな組み合わせ。手を真っ黒にしつつ、2 日ほどかけて一応表面上の石は除去したのだが、ほとんど意味がなかった作業だったことに気づくのは半年ほど後の話。

最初に石を除去した後に気づいたこと

表面の石の除去から半年ほど経った後、今後のことを考えて耕運機を買った。で、耕運機で畑を耕そうとしたのだが、刃がめちゃくちゃ跳ねて、まともにかけられない箇所が結構あった。

少し深いところに残ってる石に耕運機の刃がぶつかってたのは分かったが、今後のことを考えると、一度ある程度の深さまで石を全部除去する必要があるなと思ったのが地獄の始まり。

深さ 50 cm ぐらいまでの畑の状況

実際にシャベルで深さ 50 cm ぐらいまで掘ったところ、石が出てくるどころの騒ぎではなく、想定外のものが大量に出てきた。代表例としては、以下。

  • 数十センチの岩盤みたいな石
  • 木の根っこや幼虫、動物の糞など
  • 数十センチのアスファルトの塊
  • ガラス瓶や皿(?)など陶器の破片

掘って出てきたものの一例
f:id:poke_dev:20200202024331p:plain

でかい石や動物の糞ぐらいは想像できたんだけど、後は正直想定外。今まで物置が建っていた場所とは言え、土の中にアスファルトの塊やガラスや陶器が埋まってるとか、当初の想定が甘すぎた。 土の表面の石を除いた作業は、ホントに無駄だった。

本題 (実際の作業編)

深さ 50 cm ぐらいまでの不要物を除去するにあたって使用した道具・装備

  • シャベル
  • ふるい (とフルイ台)
  • 軽作業用手袋
  • 農作業用長靴

f:id:poke_dev:20200202230610p:plain f:id:poke_dev:20200202230722p:plain

それぞれ詳細に説明する。

  • シャベル

    土を掘る、掘った土を移動する、土の中の石を砕く、など諸々の作業に必須。硬めの土を掘ったり石を砕く必要があるので、先は平らじゃないタイプが使いやすいと思われる。

    自分が使ったのは何十年も前のやつなので上のとはもちろん違うけど、たぶんオーソドックスなやつ買っておけば何も問題ないはず。

  • ふるい (とフルイ台)

    掘り返した土は石などの異物を除いて、土のみの状態にする必要があるが、この作業にふるいが必須となる。 また、ふるいは土を入れて振る必要があるが、振る回数が多くなると自分の手で持って作業するのは体がヤバいことになるので、置いたまま振るえるフルイ台も必須になる(数百回以上フルイをかける状況を想像してもらいたい)。

    また、フルイの大きさも振る総回数に直結するので、かなり重要。自分は上のフルイの 30 cm 版を買ったが、正直、小さかった。 同じフルイで 37 cm のタイプもあるので、今買うなら絶対にそっちを買う。

    アミは上記のフルイだと細かさによって 3 種類のアミが付いてくるが、今回の作業には荒目のアミしか使わない(荒目でもまだ細かいぐらい)。

  • 軽作業用手袋

    手袋は色々なタイプがあるので、何もないと軍手でも良いかと思ってしまうかもしれないが、お勧めできない。

    前述したように、土の中にはただの石ころだけではなく、ガラスや陶器の破片や動物の糞などが含まれる可能性があり、これらから手を完全に守れる、且つ、作業の妨げにならない付け心地の手袋が必要になる。 軍手の場合、ガラスなどからはギリギリ守れるかもしれないが、掘った土は基本的に湿っていて、これに対して長時間作業を行うと、軍手のように水分が通る手袋だと最終的に手が土だらけになる可能性がある。

    また、薄いビニール手袋などもガラスの破片などが心配なので、水分やガラス片などを通さず、それでいて作業がしやすい軽作業用手袋の使用を推奨する。

    上の軽作業用手袋は実際に今回使ったが、ちゃんと手を保護してくれて作業もしやすかったので、お勧めできる。 ただ、サイズ等も含めて、出来るならホームセンターなどで実際につけて自分に合うやつを買うのが良いと思う。

  • 農作業用長靴

    f:id:poke_dev:20200202230722p:plain

    手袋よりもハードル上がるが、今回のような畑作業をするには、農作業用の長靴を買うのをお勧めする。 ふかふかの土に足が沈もうが、土が湿り気帯びてようが、全く気にせず作業を行うことが出来る。

    一点注意が必要な点としては、この長靴については、必ずホームセンターなどで色々と試し履きをしてから購入することを強くお勧めする。 一口に長靴と言っても、素材の硬さ・伸縮性や、靴底の頑丈具合など、普通の靴以上に色々な要素があり、単純にサイズだけでは絶対に決められない。

実際の作業の注意点

作業は、大きく分けて以下の流れになる。

  1. 土を掘る
  2. 掘った土をフルイにかけ、異物を除去した土を掘った場所に戻す

これだけだと簡単なように見えるが、これを合わせて 20 時間 30 時間やる必要がある場合、極力作業を最小化させないと、体と精神が保たない。

上記の工程をもう少し細かくすると、以下になる。

  • 土を掘る
    1. 土を掘る
    2. 掘った土をどこか空いている場所に移動する
  • 掘った土をフルイにかけ、異物を除去した土を掘った場所に戻す
    1. ある程度のエリアの土掘りが完了したら、掘った場所にフルイをセットする
    2. 掘り出して山になった土をフルイに移し、フルイをかける
    3. フルイに残った石などを、畑以外の空き場所に移動する

各工程ごとの注意点を以下に説明する。

土を掘る

言葉通り、土をスコップで掘るだけなのだが、土の状況によってはこの作業が一番力と体力を使うことになる。

土だけだったら恐らくそこまでではないのだが、上述したように、数十センチの岩盤やガラスや陶器などが土中に存在する場合、一気にハードルが高くなる。 岩盤の場合、場合によっては砕く必要があるし、ガラスや陶器の場合は、下手に砕くと細かい破片が散らばってその後の作業が大変になる。

一番の問題は、土の上からだと、どこにどの程度の大きさの物体が存在するのか把握できないことにある。

石ころぐらいであれば何も気にする必要ないが、例えば硬い物体にぶつかってスコップが入らなくなった場合、この物体を除去するには、力で割るか、もしくは丸ごと取り出す必要があるが、大きさや硬度によっては割るのが困難なこともあるし、丸ごと取り出すにしても上に土が被ってる状態だと、大きさの判断が出来ないのでこれも厳しい。

この状況に対処するためお勧めしたい方法が、上から面単位で掘っていく方法ではなく、一度一番深いところまで土を掘り出した後、横から土を切り崩していく方法。

f:id:poke_dev:20200203001631p:plain

上の写真だと、ちょっと分かりづらいが、赤の掘ったエリアの側面を拡張する形で、青のラインを上から掘って、赤の方に土を切り崩すようにする。
こうすると、仮に青のエリアで大きな岩や陶器などが出てきた場合、それらを無理やり割ったりせず、既に掘ってある赤側の側面から取り出して除去できるようになる。

もしかしたらもっと良い方法あるのかもしれないが、上からがむしゃらに掘るよりは、こちらの方が凄い効率が良かった。

掘った土をどこか空いている場所に移動する

これも言葉通りの作業だが、注意が必要な作業。

「掘った土を移動する」と書いたが、掘った分だけこの移動作業が発生し、且つ、この後逆に戻す作業での移動も発生することを考えると、可能な限り移動距離が短い場所に土を盛れるのが良い。

理想としてはゼロ距離の場所が良いが、現実には難しいと思うので、掘った場所から二歩、出来れば一歩圏内に土の移動先を確保したい。三歩以上必要な場所になると、恐らく体が死ぬと思われる(人によるとは思うけど)。

この移動先に関しては一時的に盛っておければ良いので、例えば作業予定のエリアを縦に二分割して、片方ずつ作業を行い、片方の作業時はもう片方のエリアを移動先にするなどして、要件を満たすことも出来ると思われる。

ある程度のエリアの土掘りが完了したら、掘った場所にフルイをセットする

特記事項なし。

掘り出して山になった土をフルイに移し、フルイをかける

土の移動に関しては掘った時の懸念点と同様。土をフルイに盛った後は振るうだけだが、注意点がある。

これも、対象の土がどのような構成となっているかにもよるが、基本的には、「瓦礫や陶器など、菜園の土の要素として絶対に不要な物体のみ除去する」のが目的となる。 当たり前のようにも聞こえるが、フルイにかけて残った物体の中には、「粘土質の土の塊」や、「非常に硬い土の塊」が結構存在し、それらも単純にフルイで残った物体として除去してしまうと、最終的に畑に残る土が非常に減ってしまう恐れがある(自分の場合は最終的に 2 割前後減った)。大量に減った場合、恐らく最終的に土の補充などが必要になると思われる。

これを出来るだけ防ぐには、「土の塊」は除去しないで畑に戻す必要があるのだが、石と土の塊の判別がなかなかに難しい。 また、小さい塊も含めていちいち個別に確認するといくら時間があっても足りないので、自分の場合は、ある程度フルイに塊が残ったら、上から手のひらで押しつぶすように力を加えて、土の場合は潰す作業を行った。 石のように硬い土の場合はこれでも潰れずに残ってしまうが、この辺りは妥協が必要。 ある程度の大きさの塊については、除去する前に両手で折れるか試すぐらいはした方が良い。要は、労力と時間と残る土を天秤にかけて、作業を行う。

フルイに残った石などを、畑以外の空き場所に移動する

この作業については土の移動同様、移動先の距離が重要になるが、それ以上に問題になるのが、「除去した異物を置く場所の確保」。 掘った土の一時的な移動と異なり、この異物の山に関しては一定期間(もしくはずっと)そのままになる可能性が高い(すぐに捨てる算段がついてるとかだったら別だけど)。

畑以外である程度の量を置けるスペース、且つ、畑との距離が離れていない場所が良いが、こればっかりは畑の配置などにもよるので、それ次第だとしか言えない。 土の状況にもよるが、スペースとしては掘る土の量の 2 割前後は置ける場所を確保したい。

上記作業方法でかかった時間

対象の畑の広さ: 1.6 m x 4.6 m

これを 4 分割して、それぞれ 50 cm ほどまで掘り返す作業を行った。1 エリアの作業にかかった時間は、およそ以下。

作業 時間
1 土を掘る 2-3 時間
2 掘った土をフルイにかけ、異物を除去した土を掘った場所に戻す 4-5 時間

作業時間だけ見ると一日で出来そうな気もするが、1 は非常に重労働なので、よっぽど体力に自信がない限り、1 で一日終わる。 2 は 1 ほど力作業ではないが、こちらは逆に時間がかかるので、二日ぐらいかかる。

結局 3 日ぐらいかかる感じなので、それが 4 エリアで、合計 12 日ぐらいはかかったと思う(ちゃんと数えてはいないけど)。

最後に

当初は全エリアで 2, 3 日ぐらいあれば終わるかなと思っていたが、途中から、業者にでも頼んで土を全入れ替えしてもらった方が金かかったとしても良かったのではと思うぐらいには、大変だった。

自分は 12 月と 1 月にやったので寒かったが、これが夏場だと、もっと体力保たなくて、地獄だったと思われる。 とにかく重労働且つ時間かかる作業なので、作業しやすい時期に作業するのも重要。 それと、土を掘ったりフルイにかけたりするということもあって、作業は晴天の日が続いて、土が乾いてる時にした方が良い。

Azure サービスプリンシパルを使用した Az モジュールでの操作

Azure サービスプリンシパルを使用した Az モジュール認証から、実際のリソース操作まで順を追って説明。

単純な Az モジュールを使用したリソース操作については以下を参照。

前提条件

認証に使用するサービスプリンシパルは作成済みであること。

サービスプリンシパルの作成方法は以下を参照。

今回は以下のように、TestSP3 と言う名称で作成済みのサービスプリンシパルを使用する。

f:id:poke_dev:20200126181127p:plain

操作対象のリソースは、こちらもあらかじめ作成済みの下記 Web App とする。

f:id:poke_dev:20200126181509p:plain

基本情報
種別
サブスクリプション BizSpark
リソースグループ名 TestRg
Web App 名 NetWebAppTest111
操作対象リソースのロール割当状況

認証に使用したサービスプリンシパルアカウントが、操作対象リソースのロールに割り当てられていること。ここでは「共同作成者」としてロール割り当て済み。

f:id:poke_dev:20200126181833p:plain

サブスクリプション自体にロールが割り当てられたサービスプリンシパルの場合、当該サブスクリプション配下の各リソースも自動的に継承するようだが、基本的には最小限の権限設定となるように、対象リソースにのみロールを割り当てるのが良いと思われる。

上述したイメージでは、サブスクリプションにのみロールを割り当てた TestSP1 と TestSP2 も、当該 Web App のロール一覧に表示されている (なので、TestSP1, TestSP2 を使用しての操作ももちろん可能)。

リソースへのロール割り当て方法については以下も参照。

実行するコマンドレット
> $appId = "1ebxxx"
> $secret = "yyy"
> $tenantId = "dcfzzz"
> $securedSecret = ConvertTo-SecureString $secret -AsPlainText -Force
> $creds = New-Object System.Management.Automation.PSCredential($appId, $securedSecret)
> Connect-AzAccount -ServicePrincipal -Tenant $tenantId -Credential $creds

> Get-AzWebApp -ResourceGroupName "TestRg" -Name "NetWebAppTest111"
> Stop-AzWebApp -ResourceGroupName "TestRg" -Name "NetWebAppTest111"

Connect-AzAccount の実行までが、サービスプリンシパルを利用した Azure ログイン、その後は、通常の Az モジュールによる操作と同じになる。 ここでは、稼働中 Web App の情報を取得し、停止させることにする。

サービスプリンシパルを利用した認証については、下記ドキュメントも参照。

実行結果

f:id:poke_dev:20200126183021p:plain

f:id:poke_dev:20200126183147p:plain

停止コマンドが成功すると、State が Running から Stopped に変わったことが確認できる。

更新結果は Azure ポータルでも確認できるが、Azure ポータルサイトがキャッシュ(?)しているのか、F5 で画面リフレッシュしないとポータル上の状態表示が変わらないことがあるっぽいので、注意。

f:id:poke_dev:20200126183352p:plain

Az コマンド実行時に発生する可能性があるエラーについて

ログインに使用したサービスプリンシパルがどのリソースにもロール割り当てされていない場合、ログイン後に表示されるサブスクリプション名が空になっていて、もちろんリソースの操作もできない。

f:id:poke_dev:20200126184917p:plain

サブスクリプションの他のリソースにロールが割り当てられていて、操作したいリソースに割り当てられていない場合も、以下のようにエラーが発生してリソース操作できない。

f:id:poke_dev:20200126185509p:plain

なおこの際、「does not have authorization to perform action 'Microsoft.Web/sites/read' over scope 'xxx...」と言うように当該コマンドレット実行に必要な権限情報が表示されるので、最小限の権限はこの権限となる。例えば、「閲覧者(=Reader 組み込みロール)」だと Get-AzWebApp コマンドレットは実行出来るが、Start-AzWebApp コマンドレットは実行出来なかったりする。

Azure リソースの組み込みロール | Microsoft Docs

Az モジュールを使ったコマンドでの Azure 操作

Azure リソースの操作は Azure ポータルから可能だが、Azure PowerShell Az モジュール (旧 AzureRM) を使用することで、コマンドでも操作が可能となる。

Introducing the Azure PowerShell Az module | Microsoft Docs

なお、PowerShell のコマンドが実行できればプログラムからの実行も可能ではあるが、プログラムから Azure リソースの操作を行いたい場合は、プログラムからの呼び出し用に用意されている Azure REST API (もしくはライブラリ) の使用を推奨。

Az モジュールも内部では結局 Azure REST API を使用しているようなので、使えるのであれば REST API を直接使った方が想定外の問題も起きにくい。

Azure REST API Reference | Microsoft Docs

ただし、Azure ポータル、Az モジュール、REST API、ライブラリそれぞれについて、全て同じ操作が可能というわけではない点には、注意。自分がやりたい操作が用意されてるかは、ドキュメント等で事前に確認しておくこと。

Az モジュールのインストール

Az モジュールは別途インストールが必要。と言っても、PowerShell でインストールのコマンドレットを叩くだけ。

> Install-Module -Name Az -AllowClobber -Scope CurrentUser

Install Azure PowerShell with PowerShellGet | Microsoft Docs

Azure への接続

Connect-AzAccount コマンドレットを実行することで、Azure ポータルを開く時みたいにアカウント情報入力用のダイアログが表示されるので、そこでアカウント情報を入力することで Azure にログインして接続できる。

なお、オプションなしだと対話形式になるが、オプション指定することで非対話形式によるログイン・接続も可能。

Azure PowerShell を使用してサインインする | Microsoft Docs

サービスプリンシパルを使用した非対話ログインについては、以下も参照。

サービスプリンシパルを使用した Az モジュールでの操作 - poke_dev’s blog

ログイン情報自動保存機能の無効化の勧め

Azure への接続について説明したが、一点注意すべき点がある。

Connect-AzAccount によるログインは毎回 PowerShell 起動後に行う必要がありそうに見えるが、ログインした状態で PowerShell を終了した場合、当該ログイン情報を自動的に保存して、次回 PowerShell 起動時に自動的に再接続する機能が存在し、既定でこの機能が有効となっている。

2 回目以降はログイン操作が不要になるので便利ではあるが、状況によっては混乱を生む原因にもなるので、取り敢えず最初は無効にしておいた方が良いかと思われる。

> Disable-AzContextAutosave

Az モジュールを用いて Azure にサインインする際、前回のセッション情報を保持しない (無効化する) 方法について | 焦げlog

Azure リソース操作例

Azure に接続した後は必要な操作を行うだけだが、ここでは例として、稼働中の Application Gateway を停止してみる。

なお、Application Gateway の停止は Azure ポータルでは機能が提供されていないので、停止したい場合は以下のように Az モジュールなどコマンドによる操作が必要になる。

> Stop-AzApplicationGateway

Stop-AzApplicationGateway (Az.Network) | Microsoft Docs

Azure ログインしてから対象サブスクリプションを選択し、対象 Application Gateway を停止するまでの流れは、例えば以下。

基本情報
種別
サブスクリプション BizSpark
リソースグループ名 TestRg
アプリケーションゲートウェイ testappgw
実行するコマンドレット
> Connect-AzAccount
> Get-AzSubscription
> Set-AzContext -SubscriptionName "BizSpark"
> $AppGW = Get-AzApplicationGateway -Name "testappgw" -ResourceGroupName "TestRg"
> Stop-AzApplicationGateway -ApplicationGateway $AppGW
実行結果

f:id:poke_dev:20200123001403p:plain

f:id:poke_dev:20200123001651p:plain

停止コマンドが成功すると、OperationalState が Running から Stopped に変わったことが確認できる。

なお、Application Gateway の場合、更新中は Azure ポータルでもリアルタイムでその旨の表示が行われる(全てのリソースで同様のリアルタイム表示が行われるわけではないので、注意)。

f:id:poke_dev:20200123001834p:plain

Application Gateway の場合は Azure ポータルで停止が出来ないこともあり、現在の実行ステータスがポータル上では簡単に確認できなかったりするので、その辺りは注意。

Azure App Service のスロットのアプリ設定について

Web Apps や Functions ではスロット機能を利用することができるが、スロットでのアプリ設定周りで注意が必要そうな点について確認する。

スロット新規作成時の初期設定について

  • Web Apps
    • 初期設定としてコピーしたいアプリ設定のスロットを選択できる。未選択も可
  • Functions
    • Prd (運用) スロットのアプリ設定が常にコピーされる

スロット作成後のアプリ操作について (Web Apps, Functions 共通)

  • 新規アプリ設定追加 / 既存アプリ設定削除 / 既存アプリ設定の値変更
    • 当該スロットのアプリ設定としてのみ、追加 / 削除 / 値変更 される
    • ワーカープロセスは再起動する
  • 既存アプリ設定の「デプロイ スロットの設定」値変更 (「デプロイ スロットの設定」値変更のみ)
    • 同名のアプリ設定が存在する全スロットに対して、「デプロイ スロットの設定」値変更が行われる
    • ワーカープロセスは再起動しない

スロット作成後のアプリ操作については、「デプロイ スロットの設定」のみ、他の操作と異なる動きをする。

f:id:poke_dev:20200121004245p:plain

検証した限り、「デプロイ スロットの設定」は全スロット共通の設定として管理されているような動きだった。
また、アプリ設定の値とは直接関係ないため、「デプロイ スロットの設定」のみ変更された場合は、既存のワーカープロセス再起動は発生しない(新しい設定値を読み込む必要がないので、当たり前かもしれないけど)。

「デプロイ スロットの設定」値変更時の挙動だけ特殊なので、以下に検証結果を記載する。
ここでは Functions の HTTP トリガーに対してリクエストし続けた状態でアプリ設定を変更し、状況を観察する。

基本環境

対象 設定
プラットフォーム Function v3 (.NET Core)
OS Windows
プラン App Service プラン (S1)
インスタンス 1
常時接続 オン

※ Functions HTTP トリガーのソースと、呼び出し側の PowerShell のソースは、以下で使用しているものと基本的に同じ。

設定値変更時の呼び出し結果

(FixAppSetting アプリ設定の値を、fixPrdxxx -> fixPrd に変更)

(1) [01/20 23:51:13] requesting...
Param: 1, AppVer: 2.0, FixAppSetting: fixPrdxxx, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 5360
(1) [01/20 23:51:15] response time: 2.32 (s)

(2) [01/20 23:51:15] requesting...
Param: 2, AppVer: 2.0, FixAppSetting: fixPrdxxx, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 5360
(2) [01/20 23:51:17] response time: 2.19 (s)

(3) [01/20 23:51:17] requesting...
Param: 3, AppVer: 2.0, FixAppSetting: fixPrdxxx, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 5360
(3) [01/20 23:51:19] response time: 2.18 (s)

(4) [01/20 23:51:19] requesting...
Param: 4, AppVer: 2.0, FixAppSetting: fixPrdxxx, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 5360
(4) [01/20 23:51:21] response time: 2.27 (s)

(5) [01/20 23:51:21] requesting...
The service is unavailable.
    + CategoryInfo          : InvalidOperation: (System.Net.HttpWebRequest:HttpWebRequest) [Invoke-RestMethod]、WebException
    + FullyQualifiedErrorId : WebCmdletWebResponseException,Microsoft.PowerShell.Commands.InvokeRestMethodCommand
    + PSComputerName        : localhost
(5) [01/20 23:51:21] response time: 0.26 (s)

(6) [01/20 23:51:23] requesting...
The service is unavailable.
    + CategoryInfo          : InvalidOperation: (System.Net.HttpWebRequest:HttpWebRequest) [Invoke-RestMethod]、WebException
    + FullyQualifiedErrorId : WebCmdletWebResponseException,Microsoft.PowerShell.Commands.InvokeRestMethodCommand
    + PSComputerName        : localhost
(6) [01/20 23:51:23] response time: 0.20 (s)

(7) [01/20 23:51:25] requesting...
Param: 7, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(7) [01/20 23:51:50] response time: 24.93 (s)

(8) [01/20 23:51:27] requesting...
Param: 8, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(8) [01/20 23:51:50] response time: 22.84 (s)

(9) [01/20 23:51:29] requesting...
Param: 9, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(9) [01/20 23:51:50] response time: 20.74 (s)

(10) [01/20 23:51:32] requesting...
Param: 10, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(10) [01/20 23:51:50] response time: 18.65 (s)

(11) [01/20 23:51:34] requesting...
Param: 11, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(11) [01/20 23:51:50] response time: 16.56 (s)

(12) [01/20 23:51:36] requesting...
Param: 12, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(12) [01/20 23:51:50] response time: 14.47 (s)

(13) [01/20 23:51:38] requesting...
Param: 13, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(13) [01/20 23:51:50] response time: 12.37 (s)

(14) [01/20 23:51:40] requesting...
Param: 14, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(14) [01/20 23:51:50] response time: 10.28 (s)

(15) [01/20 23:51:42] requesting...
Param: 15, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(15) [01/20 23:51:50] response time: 8.19 (s)

(16) [01/20 23:51:44] requesting...
Param: 16, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(16) [01/20 23:51:50] response time: 6.10 (s)

(17) [01/20 23:51:46] requesting...
Param: 17, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(17) [01/20 23:51:50] response time: 4.26 (s)

(18) [01/20 23:51:48] requesting...
Param: 18, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(18) [01/20 23:51:50] response time: 2.17 (s)

(19) [01/20 23:51:50] requesting...
Param: 19, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(19) [01/20 23:51:53] response time: 2.19 (s)

(20) [01/20 23:51:52] requesting...
Param: 20, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(20) [01/20 23:51:55] response time: 2.19 (s)
上記結果からわかること
  • 変更時にダウンタイムと遅延が発生している
  • 新しいアプリ設定を読み込むため、ワーカープロセスの再起動が発生している

「デプロイ スロット設定」値のみ変更時の呼び出し結果

(1) [01/21 00:38:07] requesting...
Param: 1, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(1) [01/21 00:38:09] response time: 2.46 (s)

(2) [01/21 00:38:09] requesting...
Param: 2, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(2) [01/21 00:38:11] response time: 2.19 (s)

(3) [01/21 00:38:11] requesting...
Param: 3, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(3) [01/21 00:38:14] response time: 2.92 (s)

(4) [01/21 00:38:13] requesting...
Param: 4, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(4) [01/21 00:38:16] response time: 2.81 (s)

(5) [01/21 00:38:15] requesting...
Param: 5, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(5) [01/21 00:38:17] response time: 2.18 (s)

(6) [01/21 00:38:17] requesting...
Param: 6, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(6) [01/21 00:38:19] response time: 2.19 (s)

(7) [01/21 00:38:19] requesting...
Param: 7, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(7) [01/21 00:38:22] response time: 2.18 (s)

(8) [01/21 00:38:21] requesting...
Param: 8, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(8) [01/21 00:38:24] response time: 2.20 (s)

(9) [01/21 00:38:24] requesting...
Param: 9, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(9) [01/21 00:38:26] response time: 2.19 (s)

(10) [01/21 00:38:26] requesting...
Param: 10, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 4057cf, ProcessId: 4684
(10) [01/21 00:38:28] response time: 2.18 (s)
上記結果からわかること
  • 変更時にダウンタイムと遅延が発生していない(変更されたかの判定も出来ないけど・・・)

Azure Functions HTTP トリガー呼び出し時のエラーリスト

レスポンスステータスコード メッセージ例 想定される Function の状態
401 "Unauthorized" 指定された関数認証用のキーが異なる
403 "This web app is stopped." ・Function 停止中
・IP 制限
404 "Not Found" Function は稼働中だが URL 指定した関数が存在しない
502 "Web server received an invalid response while acting as a gateway or proxy server." ・Graceful Shutdown 時に 30 秒超過して強制終了
・リクエストから 4 分 (ドキュメント的には 2.5 分) 超過 (Function 自体は動いていることに注意)
503 "The service is unavailable."
"Function host is not running."
プロセス再起動中 (Function 再開、アプリ設定変更、デプロイ)

Azure App Service のスロットスワップ時の挙動について

Web Apps や Functions の本番運用では、リリース作業時に本番環境のダウンタイム、レスポンス遅延などを最小限に抑えるため、スロットのスワップ機能が利用できる。

スワップ機能を一言で説明すると、「prd スロットをあらかじめ最新化しておいた stg スロットと交換することで、ダウンタイムなしで最新環境にする」となるが、裏ではその実現のために結構色々行われており、その内容を多少は理解してないと、スワップ時に問題が発生する可能性がある。

スワップ時の流れとしては以下となる。

  1. Azure ポータルでスワップ開始
  2. ソーススロット (stg) のアプリ設定を、ターゲットスロット (prd) のアプリ設定に変更する。またこの際、「デプロイスロット設定」も考慮される
  3. stg スロットのアプリ設定変更により、stg のワーカープロセス再起動が発生する。新しいアプリ設定で stg スロットが使用可能になるまで、数十秒かかる
  4. stg スロットが prd アプリ設定として完全に使用可能になったら、prd と stgFQDNスワップを行う
  5. この時点では、クライアントからのリクエストは、prd URL へのリクエスト、stg URL へのリクエスト共に、prd, stg のどちらのスロットにも転送される可能性がある (スロット上はどちらも prd アプリ設定の状態)
  6. FQDN 付け替えも数十秒ほど経つと完全に切り替え完了し、prd URL へのリクエストは旧 stg スロット、stg URL へのリクエストは旧 prd スロットにのみ転送されるようになる。この時点で、本番環境としては完全にスワップ完了し、最新バージョンのアプリで稼働している状態となる
  7. stg スロットのアプリ設定を、stg のアプリ設定に変更する
  8. stg スロットのアプリ設定変更により、stg のワーカープロセス再起動が発生する。新しいアプリ設定で stg スロットが使用可能になるまで、数十秒かかる
  9. stg スロットが、stg アプリ設定及び旧 prd 上で稼働していたアプリのバージョンが稼働している状態となる
  10. 全てのスワップ作業完了

ここでは実際に両方の環境へ HTTP リクエストし続けた状態でスワップを行い、状況を観察する。検証環境は Function App (App Service プラン) だが、Web Apps でも基本は同じかと思われる。

ただ、従量課金プランや複数インスタンス運用時は、細かいところで多少差異があるかもしれない(未確認)。

基本環境

対象 設定
プラットフォーム Function v3 (.NET Core)
OS Windows
プラン App Service プラン (S1)
インスタンス 1
常時接続 オン
アプリ設定のデプロイスロット設定 明記しない限り全てオン

スワップ前の prd 環境

アプリ設定 (Azure ポータル)
名前 デプロイ スロットの設定
FixAppSetting fixPrd オン
SwapAppSetting swap1 オフ
アプリバージョン (プログラム ハードコード)
名前
AppVer 1.0

スワップ前の stg 環境

アプリ設定 (Azure ポータル)
名前 デプロイ スロットの設定
FixAppSetting fixStg オン
SwapAppSetting swap2 オフ
アプリバージョン (プログラム ハードコード)
名前
AppVer 2.0

デプロイする Function コード

呼ばれたら 2 秒待機して、必要な情報を返すだけの HTTP トリガー

public static class Function1
{
    private static IConfigurationRoot Configuration { get; }
    const string APP_VER = "2.0";

    static Function1()
    {
        var builder = new ConfigurationBuilder()
    .AddJsonFile("local.settings.json", true)
    .AddEnvironmentVariables();

        Configuration = builder.Build();
    }

    [FunctionName("Function1")]
    public static async Task<IActionResult> Run(
        [HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)] HttpRequest req,
        ILogger log)
    {
        string fixAppSetting = Configuration["FixAppSetting"];
        string swapAppSetting = Configuration["SwapAppSetting"];
        string slotName = Configuration["WEBSITE_SLOT_NAME"];
        string instanceId = Configuration["WEBSITE_INSTANCE_ID"];
        var processId = System.Diagnostics.Process.GetCurrentProcess().Id;

        string param = req.Query["param"];

        await Task.Delay(2 * 1000);

        return (ActionResult)new OkObjectResult(string.Format("Param: {0}, AppVer: {1}, FixAppSetting: {2}, SwapAppSetting: {3}, SlotName: {4}, ShortInstanceId: {5}, ProcessId: {6}",
            param, APP_VER, fixAppSetting, swapAppSetting, slotName, instanceId.Substring(0, 6), processId));
    }
}

HTTP リクエストを行うコード (PowerShell)

PowerShell を使って、3 秒間隔で 35 回リクエストを行う。
2 window 使って prd と stg 向けに同時実行するが、実行コードの差異はリクエスト URL 情報のみ。

参考: PowerShell で連続的な HTTP リクエストを送る - poke_dev’s blog

$maxCount = 35
$waitSeconds = 3

for ($i = 1; $i -le $maxCount; $i++){
    Write-Output($i.ToString() + "/" + $maxCount.ToString())

    Start-Job -ScriptBlock{
        param(
            [string] $param
        )

        $startTime = [DateTime]::Now

        Write-Output("(" + $param + ") " + $startTime.ToString("[MM/dd HH:mm:ss]") + " requesting...")

        $url = "https://functestcore31std.azurewebsites.net/api/Function1?param=prd_" + $param

        Invoke-RestMethod -Method Get -Uri $url

        $endTime = [DateTime]::Now
        $duration = $endTime - $startTime
        Write-Output("(" + $param + ") " + $endTime.ToString("[MM/dd HH:mm:ss]") + " response time: " + $duration.TotalSeconds.ToString("N2") + " (s)")
    } -ArgumentList $i

    Start-Sleep $waitSeconds
}

While ($runningJobs = Get-Job -State "Running"){
    Write-Output("Still running... (" + $runningJobs.ChildJobs.Count + " jobs)")
    Start-Sleep 5
}

Write-Output "`r`nAll request completed.`r`n"

foreach ($job in Get-Job){
    Receive-Job -Job $job
    Remove-Job -Job $job
    Write-Output ""
}

スワップ時の呼び出し結果

作業タイムライン

時間 内容
21:25:05 ソースを stg、ターゲットを prd にしてスワップ開始
21:26:18 スワップ終了 (Azure ポータル上は)

スワップ時のアプリ設定状況

f:id:poke_dev:20200119010722p:plain

prd URL 呼び出し

(1) [01/18 21:24:54] requesting...
Param: prd_1, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(1) [01/18 21:24:57] response time: 2.31 (s)

(2) [01/18 21:24:57] requesting...
Param: prd_2, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(2) [01/18 21:25:00] response time: 2.18 (s)

(3) [01/18 21:25:01] requesting...
Param: prd_3, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(3) [01/18 21:25:03] response time: 2.22 (s)

(4) [01/18 21:25:04] requesting...
Param: prd_4, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(4) [01/18 21:25:06] response time: 2.19 (s)

(5) [01/18 21:25:07] requesting...
Param: prd_5, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(5) [01/18 21:25:09] response time: 2.23 (s)

(6) [01/18 21:25:10] requesting...
Param: prd_6, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(6) [01/18 21:25:12] response time: 2.26 (s)

(7) [01/18 21:25:13] requesting...
Param: prd_7, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(7) [01/18 21:25:16] response time: 2.61 (s)

(8) [01/18 21:25:16] requesting...
Param: prd_8, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(8) [01/18 21:25:18] response time: 2.23 (s)

(9) [01/18 21:25:19] requesting...
Param: prd_9, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(9) [01/18 21:25:21] response time: 2.25 (s)

(10) [01/18 21:25:22] requesting...
Param: prd_10, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(10) [01/18 21:25:24] response time: 2.19 (s)

(11) [01/18 21:25:25] requesting...
Param: prd_11, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(11) [01/18 21:25:28] response time: 2.25 (s)

(12) [01/18 21:25:28] requesting...
Param: prd_12, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(12) [01/18 21:25:31] response time: 2.46 (s)

(13) [01/18 21:25:32] requesting...
Param: prd_13, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(13) [01/18 21:25:34] response time: 2.90 (s)

(14) [01/18 21:25:35] requesting...
Param: prd_14, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(14) [01/18 21:25:37] response time: 2.81 (s)

(15) [01/18 21:25:38] requesting...
Param: prd_15, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(15) [01/18 21:25:40] response time: 2.70 (s)

(16) [01/18 21:25:41] requesting...
Param: prd_16, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(16) [01/18 21:25:43] response time: 2.21 (s)

(17) [01/18 21:25:44] requesting...
Param: prd_17, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(17) [01/18 21:25:46] response time: 2.19 (s)

(18) [01/18 21:25:47] requesting...
Param: prd_18, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(18) [01/18 21:25:49] response time: 2.19 (s)

(19) [01/18 21:25:50] requesting...
Param: prd_19, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(19) [01/18 21:25:52] response time: 2.18 (s)

(20) [01/18 21:25:53] requesting...
Param: prd_20, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(20) [01/18 21:25:55] response time: 2.20 (s)

(21) [01/18 21:25:56] requesting...
Param: prd_21, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(21) [01/18 21:25:59] response time: 2.21 (s)

(22) [01/18 21:25:59] requesting...
Param: prd_22, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(22) [01/18 21:26:02] response time: 2.20 (s)

(以降も 22 と同じレスポンスとなるため、割愛)
prd URL リクエスト結果からわかること
  • ダウンタイム、遅延ともになし
  • 17 回目のリクエスト時に stg スロット上のアプリへリクエストが転送され始めたことが分かるが、21 回目までは prd, stg スロット共に prd URL へのリクエストが転送されていることが分かる

stg URL 呼び出し

(1) [01/18 21:24:54] requesting...
Param: stg_1, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(1) [01/18 21:24:56] response time: 2.31 (s)

(2) [01/18 21:24:57] requesting...
Param: stg_2, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(2) [01/18 21:24:59] response time: 2.18 (s)

(3) [01/18 21:25:00] requesting...
Param: stg_3, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(3) [01/18 21:25:02] response time: 2.28 (s)

(4) [01/18 21:25:03] requesting...
Param: stg_4, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(4) [01/18 21:25:05] response time: 2.19 (s)

(5) [01/18 21:25:06] requesting...
Param: stg_5, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(5) [01/18 21:25:08] response time: 2.29 (s)

(6) [01/18 21:25:09] requesting...
Param: stg_6, AppVer: 2.0, FixAppSetting: fixStg, SwapAppSetting: swap2, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4204
(6) [01/18 21:25:12] response time: 2.66 (s)

(7) [01/18 21:25:12] requesting...
The service is unavailable.
    + CategoryInfo          : InvalidOperation: (System.Net.HttpWebRequest:HttpWebRequest) [Invoke-RestMethod]、WebException
    + FullyQualifiedErrorId : WebCmdletWebResponseException,Microsoft.PowerShell.Commands.InvokeRestMethodCommand
    + PSComputerName        : localhost
(7) [01/18 21:25:13] response time: 0.27 (s)

(8) [01/18 21:25:15] requesting...
Param: stg_8, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(8) [01/18 21:25:42] response time: 26.68 (s)

(9) [01/18 21:25:19] requesting...
Param: stg_9, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(9) [01/18 21:25:42] response time: 23.58 (s)

(10) [01/18 21:25:22] requesting...
Param: stg_10, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(10) [01/18 21:25:42] response time: 20.48 (s)

(11) [01/18 21:25:25] requesting...
Param: stg_11, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(11) [01/18 21:25:42] response time: 17.39 (s)

(12) [01/18 21:25:28] requesting...
Param: stg_12, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(12) [01/18 21:25:42] response time: 14.30 (s)

(13) [01/18 21:25:33] requesting...
Param: stg_13, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(13) [01/18 21:25:42] response time: 9.35 (s)

(14) [01/18 21:25:36] requesting...
Param: stg_14, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(14) [01/18 21:25:42] response time: 6.36 (s)

(15) [01/18 21:25:37] requesting...
Param: stg_15, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(15) [01/18 21:25:42] response time: 5.12 (s)

(16) [01/18 21:25:40] requesting...
Param: stg_16, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(16) [01/18 21:25:42] response time: 2.26 (s)

(17) [01/18 21:25:43] requesting...
Param: stg_17, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(17) [01/18 21:25:45] response time: 2.18 (s)

(18) [01/18 21:25:46] requesting...
Param: stg_18, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(18) [01/18 21:25:49] response time: 2.21 (s)

(19) [01/18 21:25:50] requesting...
Param: stg_19, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(19) [01/18 21:25:52] response time: 2.18 (s)

(20) [01/18 21:25:53] requesting...
Param: stg_20, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(20) [01/18 21:25:55] response time: 2.20 (s)

(21) [01/18 21:25:56] requesting...
Param: stg_21, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(21) [01/18 21:25:58] response time: 2.27 (s)

(22) [01/18 21:25:59] requesting...
Param: stg_22, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(22) [01/18 21:26:01] response time: 2.20 (s)

(23) [01/18 21:26:02] requesting...
Param: stg_23, AppVer: 2.0, FixAppSetting: fixPrd, SwapAppSetting: swap2, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 668
(23) [01/18 21:26:04] response time: 2.30 (s)

(24) [01/18 21:26:05] requesting...
Param: stg_24, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(24) [01/18 21:26:07] response time: 2.18 (s)

(25) [01/18 21:26:08] requesting...
Param: stg_25, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(25) [01/18 21:26:10] response time: 2.19 (s)

(26) [01/18 21:26:11] requesting...
Param: stg_26, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(26) [01/18 21:26:13] response time: 2.20 (s)

(27) [01/18 21:26:14] requesting...
Param: stg_27, AppVer: 1.0, FixAppSetting: fixPrd, SwapAppSetting: swap1, 
SlotName: Production, ShortInstanceId: 388ca9, ProcessId: 1896
(27) [01/18 21:26:17] response time: 2.24 (s)

(28) [01/18 21:26:17] requesting...
The service is unavailable.
    + CategoryInfo          : InvalidOperation: (System.Net.HttpWebRequest:HttpWebRequest) [Invoke-RestMethod]、WebException
    + FullyQualifiedErrorId : WebCmdletWebResponseException,Microsoft.PowerShell.Commands.InvokeRestMethodCommand
    + PSComputerName        : localhost
(28) [01/18 21:26:18] response time: 0.42 (s)

(29) [01/18 21:26:20] requesting...
Param: stg_29, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(29) [01/18 21:26:48] response time: 27.79 (s)

(30) [01/18 21:26:24] requesting...
Param: stg_30, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(30) [01/18 21:26:48] response time: 24.69 (s)

(31) [01/18 21:26:27] requesting...
Param: stg_31, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(31) [01/18 21:26:48] response time: 21.60 (s)

(32) [01/18 21:26:30] requesting...
Param: stg_32, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(32) [01/18 21:26:48] response time: 18.50 (s)

(33) [01/18 21:26:33] requesting...
Param: stg_33, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(33) [01/18 21:26:48] response time: 15.42 (s)

(34) [01/18 21:26:36] requesting...
Param: stg_34, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(34) [01/18 21:26:48] response time: 12.32 (s)

(35) [01/18 21:26:39] requesting...
Param: stg_35, AppVer: 1.0, FixAppSetting: fixStg, SwapAppSetting: swap1, 
SlotName: stg, ShortInstanceId: 388ca9, ProcessId: 4912
(35) [01/18 21:26:48] response time: 9.20 (s)
stg URL リクエスト結果からわかること
  • アプリ設定が変更された、7 回目、及び 28 回目のリクエスト近辺で、ダウンタイムと遅延が発生している
  • prd アプリ設定適用後の 8 回目リクエストからは、stg URL へのリクエストにも関わらず、prd アプリ設定でプログラムが実行されている(=危険)
  • 17 回目のリクエスト時に prd スロット上のアプリへリクエストが転送され始めたことが分かるが、23 回目までは prd, stg スロット共に stg URL へのリクエストが転送されていることが分かる (=危険)
  • stg スロット側では 2 度、アプリ設定の変更が発生する関係で、stg としての完全に稼働状態となるまで、時間がかかる

上記結果のまとめ

時間 内容 stg AppSetting stg AppVer stg ProcID prd AppSetting prd AppVer prd ProcID
21:25:05 ソース (stg)、ターゲット (prd) のスワップ開始 stg 2.0 4204 prd 1.0 1896
21:25:12 stg へ prd アプリ設定適用。プロセス再起動 - 2.0 - prd 1.0 1896
21:25:42 stg プロセス再起動完了 prd 2.0 668 prd 1.0 1896
21:25:43 stg, prd の FQDN スワップ開始 prd 1.0 1896 prd 2.0 668
21:26:05 FQDN スワップ完了 prd 1.0 1896 prd 2.0 668
21:26:17 stgstg アプリ設定適用。プロセス再起動 - 1.0 - prd 2.0 668
21:26:18 (Azure ポータル上はスワップ完了) - 1.0 - prd 2.0 668
21:26:48 stg プロセス再起動完了 stg 1.0 4912 prd 2.0 668

上記結果のまとめからわかること

  • プロセス再起動は stg スロット上でのみ発生する(=ダウンタイム、遅延も stg スロット上でのみ発生する)
  • スワップ中、stg URL へのリクエストが、prd アプリ(=prd アプリ設定)として処理されるタイミングがある。そのため、スワップ中は stg へのリクエストは遮断する必要がある(別途まとめる予定)
  • アプリ設定変更時に、ダウンタイムと遅延が発生する可能性がある。そのため、新しいアプリ設定が追加された場合は本番へのリリース方法を考慮する必要がある(別途まとめる予定)
  • 最終的な結果だけ見ると「入れ替わる」けど、その過程はソースとターゲットで全く異なる。ターゲットがダウンタイムなしで最新に切り替われるのはソースの犠牲の上に成り立ってるので、結局入れ替わるから同じじゃん的な気持ちで、ソースに prd を指定してスワップとかは間違えてもしないこと(明示的にそうスワップ設定しない限り、基本的にはないと思うが)

PowerShell で連続的な HTTP リクエストを送る

一定間隔で HTTP リクエストを投げるサンプル。非同期で投げるので、レスポンスによらず一定間隔で投げ続ける。 大量のバースト的なリクエストには向いてない。 各リクエストの結果とレスポンスタイムは最後にまとめて出力するが、途中で実行中断すると出ないので、リクエスト回数とリクエスト間隔の設定には注意する。

通常の PowerShell でも実行できるが、PowerShell ISE の使用を推奨。

$maxCount = 10
$waitSeconds = 2

for ($i = 1; $i -le $maxCount; $i++){
    Write-Output($i.ToString() + "/" + $maxCount.ToString())

    Start-Job -ScriptBlock{
        param(
            [string] $param
        )

        $startTime = [DateTime]::Now

        Write-Output("(" + $param + ") " + $startTime.ToString("[MM/dd HH:mm:ss]") + " requesting...")

        $url = "https://example.com/Function1?param=" + $param

        Invoke-RestMethod -Method Get -Uri $url

        $endTime = [DateTime]::Now
        $duration = $endTime - $startTime
        Write-Output("(" + $param + ") " + $endTime.ToString("[MM/dd HH:mm:ss]") + " response time: " + $duration.TotalSeconds.ToString("N2") + " (s)")
    } -ArgumentList $i

    Start-Sleep $waitSeconds
}

While ($runningJobs = Get-Job -State "Running"){
    Write-Output("Still running... (" + $runningJobs.ChildJobs.Count + " jobs)")
    Start-Sleep 5
}

Write-Output "`r`nAll request completed.`r`n"

foreach ($job in Get-Job){
    Receive-Job -Job $job
    Remove-Job -Job $job
    Write-Output ""
}

実行結果例

f:id:poke_dev:20200118020605p:plain