狛ログ

ラベル Python の投稿を表示しています。 すべての投稿を表示
ラベル Python の投稿を表示しています。 すべての投稿を表示

2022年10月3日月曜日

【Python/Flask】AWSのALB(プロキシ)経由でWebシステムにアクセスしたらHTTPSがHTTPに書き換わって盛大にハマった話。

10月 03, 2022
技術部のyuckieee(ゆっきー)です。
今回は、PythonのFlaskフレームワークを使用し、Webシステム構築をした際にハマった事象について、解決策と合わせて、ご紹介しようと思います。

■Webシステム概要

発生事象の説明をする前に、まずは今回開発を行ったWebシステムの概要について共有しておきます。超ザックリとした概要ではありますが、以下のような構成・仕様となっていました。

【システム構成】
・ALB(ロードバランサー)
・EC2(Web/APサーバ)
 - OS:RedHatLinux8.x(EC2)
 - Web/AP:Apache 2.4.xx(mod_wsgiでFlaskと連携)
 - 言語:Python 3.8
 - フレームワーク:Flask
・通信プロトコル
 - クライアント⇔ALB:HTTPS(TCP/443※)
  ※HTTPで接続された場合でもALB側でHTTPSに変換して、リクエスト自体は受け付ける
 - ALB⇔EC2:HTTP(TCP/80)

(構成イメージ)

【Webシステムの仕様】
 ・BASIC認証を使用して、ログイン認証を行う
 ・ログイン認証後、トップページでユーザ情報をセッションに格納して他ページで使用する
 ・他ページはユーザ情報必須のため、トップページ以外へのダイレクトアクセス※は非許可
  ※ブラウザにURLを直接入力したり、お気に入りからアクセスした場合など
 ・ダイレクトアクセス検知時は、トップページに強制遷移させ、必ずトップページ経由とさせる

(画面遷移イメージ)

■発生した事象

Webシステム開発が完了し、システム構成で説明した通りの通信経路となるよう、Webシステムにアクセスする際のURLを以下のように変更しました。(URLはイメージです)

【開発時】http://websystem.com/
※Webシステムのあるサーバに直接アクセスするために設定されたWebシステムのURL
  ↓
【開発完了後】https://alb.websystem.com/
※AWSのALBを介してアクセスするために設定されたWebシステムのURL

そして、動作確認をしようと【開発完了後】のURLにアクセスしたのですが、通常アクセス時のとおりトップページから他ページに遷移しようとしても、トップページへの強制遷移が発生し、他ページに遷移ができない状態に陥りました。
明日からユーザ側で試験利用と言っているのに、軽くパニックです(笑)

(画面遷移イメージ)

■直接原因

Webシステムの仕様から考えると、ダイレクトアクセス検知によってトップページに強制転送されているのだろうと感じていました。 そして、その直感は当たっており、この仕様に絡んで以下2つの仕組みにより起こった問題であることが分かりました。

① 相対URLでの画面遷移

Webシステムのページ遷移に使用するURLは、Flaskのurl_forというメソッドを使用しており、このメソッドで生成されるURLは相対URLがデフォルトとなっており、このWebシステムでもデフォルト指定にて使用していました。
今回の場合、直前のアクセス元であるALBがhttps → httpに書き換えてリクエストを投げてきているため、受け取ったhttp://~から始まる絶対パスを元に、相対指定でURLが作成されて画面遷移されることになりました。

② HTTPSサイトからHTTPサイト遷移によるリファラ削除

突然何だ?!と思うかもしれませんが、このWebシステムではダイレクトアクセスの検知を、リクエストヘッダ内にあるリファラ(遷移元URL情報)の存在チェックで行っていました。
想定では、ダイレクトアクセスの場合、リファラには遷移元URLが入っていないため、ここをチェックすることでダイレクトアクセスの判定が可能と考えていたためです。
ですが、①の画面遷移を受け付けたブラウザは「HTTPSサイト(安全)」から「HTTPサイト(非安全)」への遷移が発生したと検知し、セキュリティリスク回避のためリファラの内容を削除してリクエストしていました。

その結果、リクエストを受け取ったWebシステムは、リファラなし(=ダイレクトアクセス)と判断し、トップページに強制転送していた訳ですね。

リファラという用語がピンとこない方は、公式ページを参照してみてください。
Referer - HTTP - MDN Web Docs

■根本原因

ここまで、実際に事象を引き起こした仕組みについて説明してきました。
ですが、そもそもAWSのALBを経由しなければ、正常に動作していたわけです。なのに、なぜこの事象が発生したのでしょうか?

それは、AWSのALBを経由したことでリクエスト情報が書き換わったためです。

今回でいうと、ALBからEC2(Web/APサーバ)への転送時に通信プロトコルをhttps → httpに書き換えており、転送リクエストを受け取ったEC2(Web/APサーバ)から見るとリクエスト元はALBなので何も間違ってはいませんし、そういう仕様なのです。
そのため、開発者は、プロキシ経由が発生すると分かった時点で、クライアントのリクエスト情報を正確に取得できるよう設計考慮が必要でした。

■解決方法

それでは、実際に根本原因に対処していきましょう。
今回は、クライアントの情報をちゃんと取得できれば解決するわけです。
でも、リクエスト情報が書き換えられてるのにどうすれば?

ご安心ください!

今回使用したALBの場合、経由前のリクエスト情報が別のヘッダーに退避されています。
それが「X-Forwarded-xxx」ヘッダーです。
「X-Forwarded-xxx」ヘッダーには、いくつか種類があり、通信プロトコルが格納されているヘッダーは「X-Fowarded-Proto」となります。

ヘッダー名 説明
X-Forwarded-For プロキシ経由時、クライアントのIPアドレスが格納されます。複数プロキシ経由時はカンマ区切りで表記され、プロキシ経由ごとに右端にIPアドレスが追加されていきます。
X-Forwarded-Host リクエストヘッダー内でクライアントから要求された元のホストを特定するための事実上の標準となっているヘッダーです。
X-Forwarded-Proto プロキシまたはロードバランサーへ接続するのに使っていたクライアントの通信プロトコル (HTTP または HTTPS) を特定するために事実上の標準となっているヘッダーです。

ただし、これらのヘッダーは標準化されたものでなく、書き換え容易且つ、経由するプロキシ(今回はALB)によって挙動が異なる可能性もあるので、ご注意ください。ALBの仕様については以下に記載がありました。
HTTP ヘッダーと Application Load Balancer

なお、「X-Forwarded-xxx」ヘッダーに関する詳細は以下を参照して確認してみてください。
※「X-Fowarded-xxx」は、現状「X-Forwarded」ヘッダに移行されるようなので「X-Fowarded」ヘッダーに関するリンクも張っておきます。
X-Forwarded-Proto - HTTP - MDN Web Docs
Forwarded - HTTP - MDN Web Docs - Mozilla
RFC 7239 Forwarded HTTP Extension

ここまでの説明から、この事象を解決するには「X-Fowarded-xxx」ヘッダーにあるプロトコル情報を使えば良い。というのが、ふんわり頭に浮かんだのではないかと思います。
それでは、このWebシステムでは、どのように「X-Forwarded-Proto」ヘッダーの値で書き換えればよいのでしょうか?
自分でゴリゴリ実装することも可能ですが、今回使用したPythonのフレームワークであるFlaskでは、既に対応するミドルウェアが提供されていました。
それが「X-Forwarded-For Proxy Fix」というミドルウェアです。

X-Forwarded-For Proxy Fix - Werkzeug

このミドルウェアを使用することで、経由(信頼)するプロキシ数に応じてリクエスト元情報の補正を行うことが可能です。 使用方法などの詳細は、上記公式ページを参照して、確認してみてください。
具体的な実装例は以下となります。

from werkzeug.middleware.proxy_fix import ProxyFix

def app():
~略~
    app = Flask(__name__)
    app.wsgi_app = ProxyFix(app.wsgi_app, x_proto=1)
~略~

インスタンス作成時に今回問題となった「X-Forwareded-Proto」ヘッダの値を使用して、通信プロトコル情報が補正されるように設定します。 公式を参照すると、「X-Fowareded-Proto」ヘッダーを補正したい場合は、引数にx_proto=(信頼する)プロキシ経由数の形式で指定すれば良いようです。
ヘッダーごとに引数が異なるようなので、詳細は公式参照ください。

上記を設定することで、無事問題は解決することが出来ました。

<おまけ>
対処方法を色々と探していたのですが、他の方法もあるようでした。
プロキシによっては「X-Forwarded-xxx」ヘッダーが設定されていないなどもあると思うので、参考までに紹介しておきます。 ただし、ヘッダーが取得可能な時は、わざわざ手間を増やしたり、セキュリティリスク高める必要はないと思うので、推奨は致しません。

・直接原因① Flaskが認識するリクエスト元プロトコルを"HTTPS"固定に変更する
Flaskのインスタンス生成時、リクエスト元のプロトコル情報を直接"HTTPS"(固定)に書き換えることで対処する方法です。以下、実装例です。
def create_app():
...省略...
    class SchemeFix:
        def __init__(self, app):
            self.app = app

        def __call__(self, environ, start_response):
            environ['wsgi.url_scheme'] = 'https'
            return self.app(environ, start_response)

    app = Flask(__name__)
    app.wsgi_app = SchemeFix(app.wsgi_app)
    
    return app

・直接原因② リファラが削除されないように設定を変更する
直接原因②はリファラが削除されるのが問題なので、削除されないようにすればいいじゃん!という対策です。対象のWebページ(HTML)に対して、以下のようなメタ情報を定義してリファラの送信制限を緩和させます。
<meta name="referrer" content="origin-when-crossorigin">

上記content="origin-when-crossorigin"の記載が該当箇所になります。
この設定の場合、同一のプロトコル水準 (HTTP→HTTP, HTTPS→HTTPS) で同一オリジンのリクエストを行う場合はオリジン、パス、クエリー文字列が送信され、オリジン間リクエストや安全性の低下する移動先 (HTTPS→HTTP) ではオリジンのみを送信します。
今回のダイレクトアクセスチェックでは、リファラの値有無を確認しているため、オリジンのみでも値があれば事象は解消可能となります。
全ての情報が必要な場合はcontent="unsafe-url"を設定することでリファラを取得可能ですが、安全性の面から非推奨となっているため、使用は回避するべきだと思います。

Referrer-Policy - HTTP - MDN Web Docs

■まとめ

Webシステムだけでなく、インフラも含めた全体的な視点でシステム構築をすることの難しさと面白さを知りました。
徐々に仕組みを理解し、謎が解けた時は本当に楽しいですね。
今後も幅広い領域の経験を積みながら、レベルアップしていければと思います。

2021年12月27日月曜日

【Python】loggingでログをカスタマイズする【Flask】

12月 27, 2021

狛ログをご覧のみなさん、はじめまして。
2021年にオフィス狛に入社いたしました、nago(なご)です。
技術に関するブログ記事を書くのは初めてですが、有益な情報を投稿できるように頑張ります。
よろしくおねがいします☺

さて、今回はPython(Flask)で、お試し開発をしていた時に苦戦したログ出力についてまとめたいと思います。

作ろうとしていたのは、外部のREST APIにリクエストを投げて、何かしらの結果を受け取り、画面に表示させる機能です。
まず、先輩社員が投稿してくださっていたこちらの記事を参考にして、AWS API GatewayでAPIのMockを作成しました。

正しい合言葉をidに設定してリクエストすると、ステータスコードが200となり、とってもタメになる情報を受け取れるAPIにしました。
合言葉を間違えていたらステータスコードが401となりエラーが返ってきます。

  

  
↓ ↓ ↓
合言葉を間違えると401エラーとなり、以下のメッセージが返ってきます。
  
アプリケーションは以下のような構成で作成しました。
 	 
     api-test/
         ├ static/
         │ └ styles.css
         ├ templates/
         │ └ api_test.html
         ├ views/
         │ ├ __init__.py
         │ └ api_test.py
         ├ __init__.py
         ├ app.py
         ├ get-pip.py
         ├ Pipfile
         └ Pipfile.lock
   	 
  	

コードはこちら。
・api_test.html
    
      <!doctype html>
      <html lang="ja">

        <head>
            <meta charset="utf-8">
            <title>APIテスト</title>
            <link rel="stylesheet" href="{{ url_for('static', filename='css/styles.css') }}">
        </head>

        <body>
            <form action="{{ url_for('api_test.call') }}" method="POST">
                <input type="text" name="id">
                <input type="submit" value="API CALL">
            </form>
            <input type="button" onclick="location.href=&#39;{{ url_for('api_test.show_api_test') }}&#39;" value="RESET">
            <p>{{ message }}</p>
        </body>
     
  

・views/app.py
    
        from flask import Flask, redirect, url_for
        from views.api_test import api_test

        app = Flask(__name__)

        app.register_blueprint(api_test)
			
        # 最初の画面へリダイレクト
        @app.route("/")
        def redirect_to_api_test():
            return redirect(url_for("api_test.show_api_test"))

        if __name__ == "__main__":
            app.run(host="0.0.0.0", port=8080)
    
  

・api_test.py
 	 
      import requests, json

      from flask import Blueprint
      from flask import render_template, request

      api_test = Blueprint("api_test", __name__)

      # 画面表示(初期 & リセット時)
      @api_test.route("/")
      def show_api_test():
          message = ""
          return render_template(
              "api_test.html",
              message=message
          )

      # APIリクエスト & レスポンス受け取り & 画面表示
      @api_test.route("/call", methods=["POST"])
      def call():

          # APIGatewayでMock作成時に設定されたURL
          url = "https://xxxx.amazonaws.com/api-test/my/info"
          # クエリ文字列を作成
          payload = { "id": request.form.get("id") }
          # リクエストヘッダを作成
          headers = { "Content-Type": "application/json" }
          
        # リクエスト & レスポンス受け取り
        response = requests.post(url, data=json.dumps(payload), headers=headers)
        # レスポンスからメッセージを取り出す
         message = response.json()["message"]

          # 画面遷移 & メッセージ表示
          return render_template(
              "api_test.html",
              message=message
          )
	 
  

これで、APIから返ってきたメッセージをそのまま画面に表示することができました。
次に、APIがコールされるたびに、そのリクエスト内容と結果のログを出力する仕組みを作ろうと思います。

Pythonでログを出力するには、Pythonで用意されているloggingというモジュールを使います。
今回は設定ファイルを既存のファイルとは別に作成して、ログの設定をしてみます。
私はプロジェクトルートに「config」という名前のディレクトリを作り、その中にログの設定ファイルを作りました。
また、ログファイルを出力したかったので、ログファイルを置くための「log」ディレクトリも作成しました。

以下が作成したディレクトリと設定ファイルです。

 	 
     api-test/
         ├ config/
         │ ├ __init__.py
         │ └ logging_config.py
         ├ log/
         ├ static/
         │ └ styles.css
         ├ templates/
         │ └ api_test.html
         ├ views/
         │ ├ __init__.py
         │ └ api_test.py
         ├ __init__.py
         ├ app.py
         ├ get-pip.py
         ├ Pipfile
         └ Pipfile.lock
   	 
  	
※赤字が追加分

・config/logging_config.py
    
    from logging import DEBUG, INFO, config
    import datetime

    # ファイル名に入れる日付フォーマット
    today = datetime.date.today().strftime("%Y-%m-%d");

    config.dictConfig(
        {
            "version": 1,
            # ログフォーマット設定
            "formatters": {
                "formatter": {
                    "format": "%(levelname)s  %(asctime)s [%(module)s] %(message)s"
                }
            },
            # ハンドラー設定
            "handlers": {
                # 標準出力ハンドラー
                "streamHandler": {
                    "class": "logging.StreamHandler",
                    "formatter": "formatter",
                    "level": INFO
                },
                # ファイル出力ハンドラー
                "fileHandler": {
                    "class": "logging.FileHandler",
                    "formatter": "formatter",
                    "level": INFO,
                    # ログファイルを出力したい場所のパスとファイル名を指定
                    "filename":f"xxxx/api-test/log/{today}_api-test.log",
                    "encoding": "utf-8"
                }
            },
            # ロガー設定
            "loggers": {
                "basicLogger": {
                    "handlers": [
                        "streamHandler",
                        "fileHandler"
                    ],
                    "level": INFO,
                    "propagate": 0
                }
            }
        }
    )
    
  

ログの設定は、logging.config.dictConfigに辞書(Dictionary型の設定値)を渡すか、
logging.config.fileConfigにconfigparser形式ファイルを渡すかで設定できますが、
私は今回はdictConfigで設定してみました。

ログを出力するには、まずLogger(ロガー)の取得が必要なのですが、そこにHandler(ハンドラー)を指定することで出力形式の指定をプラスできるようになっています。
また、出力フォーマットも設定したい場合は、ハンドラーに対してFormatter(フォーマッター)を指定します。

ロガー、ハンドラー、フォーマッターの名前は自由につけることが出来ます。
私はロガーは「basicLogger」を作り、そこに標準出力ハンドラーの「streamHandler」と、ファイル出力の「fileHandler」をくっつけました。フォーマッターは「formatter」にしました(そのまんま)

"varsion" : 1 ってなんぞやと思い調べてみたのですが、辞書スキーマのバージョンのことでした。
現在は1しかないので、1を入れておけばいいそうです。こちらはdictConfigに辞書を渡す場合は必須のため、入れないと怒られます。

さて、ようやくapi_test.pyで設定ファイルを読み込んで、ログ出力してみます。

・views/api_test.py
    
    import requests, json
    from logging import getLogger

    from flask import Blueprint
    from flask import render_template, request

    from config import logging_config

    api_test = Blueprint("api_test", __name__)

    # ログ設定ファイル読込
    logging_config
    # ロガー取得
    logger = getLogger("basicLogger")

    # 画面初期表示
    @api_test.route("/")
    def show_api_test():
        message = ""
        return render_template(
            "api_test.html",
            message=message
        )

    # APIリクエスト & レスポンス受け取り & 画面表示
    @api_test.route("/call", methods=["POST"])
    def call():

        # APIGatewayでMock作成時に設定されたURL
        url = "https://xxxx.amazonaws.com/api-test/my/info"
        # クエリ文字列を作成
        payload = { "id": request.form.get("id") }
        # リクエストヘッダを作成
        headers = { "Content-Type": "application/json" }

        # リクエストログ出力
        logger.info("request : url = " + url + ", payload = " + str(payload))

        # リクエスト & レスポンス受け取り
         response = requests.post(url, data=json.dumps(payload), headers=headers)
        # レスポンスからステータスコードとメッセージを取り出す
         status_code = response.status_code
         message = response.json()["message"]

        # レスポンスログ出力
        if status_code == 200:
            logger.info("response : status_code = " + str(status_code) + ", message = " + message)
        else:
            logger.error("response : status_code = " + str(status_code) + ", message = " + message)

        # 画面遷移 & メッセージ表示
        return render_template(
            "api_test.html",
            message=message
        )
    
  
※赤字は追加分

・log/2021-12-15_api-test.log (2021/12/15にログが作成された場合のファイル名)
    
      INFO  2021-12-15 14:23:53,701 [api_test] request : url = https://xxxx.amazonaws.com/api-test/my/info, payload = {'id': 'sushi'}
      INFO  2021-12-15 14:23:53,778 [api_test] response : status_code = 200, message = お寿司はおいしい。猫はかわいい。ポメラニアンもかわいい。
      INFO  2021-12-15 14:24:46,184 [api_test] request : url = https://xxxx.amazonaws.com/api-test/my/info, payload = {'id': ''}
      ERROR  2021-12-15 14:24:46,254 [api_test] response : status_code = 401, message = 合言葉が違うようです・・・
    
  
正常パターンとエラーパターンを実行してみました。
フォーマッターで設定した「%(levelname)s %(asctime)s [%(module)s] %(message)s」の通りに表示されています。
出力時にapi_test.pyで設定したメッセージが「%(message)s」に代入されている形です。

調べてみると、loggingは思ったより奥が深くびっくりしました。
覚えておくと出したいログを見やすく出すことができて便利だと思います。

今回はこれでおしまいです。
ここまでお読みいただきありがとうございました。

参考リファレンス:
・Logging HOWTO
・logging.config --- ロギングの環境設定