2020年10月30日金曜日

flask のロギング機構について調べてみた

概要

flask のロギングをいろいろと試してみました
基本は python の標準の logging を使っているようです

環境

  • macOS 10.15.7
  • Python 3.8.5
    • flask 1.1.2

準備

  • pipenv install flask

とりあえず標準のログを確認してみる

  • vim app.py
from flask import Flask

app = Flask(__name__)

@app.route('/')
def hello_world():
    return 'Hello, World!'
  • FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000

これで確認すると以下のようなログが表示されるのが確認できると思います

127.0.0.1 - - [30/Oct/2020 09:17:47] "GET / HTTP/1.1" 200 -

app.logger を使う

特にフォーマットをしてせずにログ出力してみます
flask では logging モジュールを使っているのでそれに対してログレベルの調整などをします
デフォルトだと warn になっている info にしてから出力してみます

  • vim app.py
import logging
from flask import Flask

app = Flask(__name__)
logging.basicConfig(level=logging.INFO)

@app.route('/')
def hello_world():
    app.logger.info('called hello world')
    return 'Hello, World!'
  • FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000
INFO:app:called hello world INFO:werkzeug:127.0.0.1 - - [30/Oct/2020 09:27:37] "GET / HTTP/1.1" 200 -

こんな感じで表示されます
前半にログレベルとパッケージ名が付与されているのが確認できます

フォーマットを変更する

次にフォーマットを変更してみます
logging.config に dictConfig というメソッドがあるのでこれにログの設定を与えることで変更することができます

  • vim app.py
from logging.config import dictConfig
from flask import Flask

dictConfig({
    'version': 1,
    'formatters': {'default': {
        'format': '[%(asctime)s] %(levelname)s in %(module)s: %(message)s',
    }},
    'handlers': {'wsgi': {
        'class': 'logging.StreamHandler',
        'stream': 'ext://flask.logging.wsgi_errors_stream',
        'formatter': 'default'
    }},
    'root': {
        'level': 'INFO',
        'handlers': ['wsgi']
    }
})

app = Flask(__name__)

@app.route('/')
def hello_world():
    app.logger.info('called hello world')
    return 'Hello, World!'

formatters, handlers を使って定義します
Python の logging モジュールで使用できるハンドラの一覧はこちらが参考になります
今回使用している StreamHandler は標準出力と標準エラーに出力するためのハンドラになります
ファイルに出力したい場合は FileHandler を使います
handler 内でログのフォーマットを指定します
またログレベルも dictConfig で指定できます

これで実行すると以下のように出力されます

  • FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000
[2020-10-30 09:34:08,250] INFO in app: called hello world [2020-10-30 09:34:08,251] INFO in _internal: 127.0.0.1 - - [30/Oct/2020 09:34:08] "GET / HTTP/1.1" 200 -

ちなみに flask のデフォルトハンドラはすべて標準エラーに出力しています

メールの送信

エラーロギングなどをメールで飛ばすこともできます
その場合は SMTPHandler を使います
先程は dictConfig を使って dictionary 形式でロガーを設定しましたがハンドラを生成してアプリに設定することもできます
ちなみに Gmail を使う場合は以下のように設定します

  • vim app.py
import logging
from logging.handlers import SMTPHandler
from flask import Flask

mail_handler = SMTPHandler(
    mailhost=('smtp.gmail.com', 587),
    credentials=('your-google-account@gmail.com', 'app-password'),
    fromaddr='your-google-account@gmail.com',
    toaddrs=['your-google-account@gmail.com'],
    subject='Application Error',
    secure=()
)
mail_handler.setLevel(logging.ERROR)
mail_handler.setFormatter(logging.Formatter(
    '[%(asctime)s] %(levelname)s in %(module)s: %(message)s'
))

app = Flask(__name__)
app.logger.addHandler(mail_handler)

@app.route('/')
def hello_world():
    app.logger.error('An error has occurred')
    return 'Hello, World!'

これでアクセスすると標準エラーに出力されるのと同時にメールが届くのも確認できると思います
メール送信時に若干ネットワークのラグが発生するのでレスポンスが遅くなります

  • FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000
[2020-10-30 10:03:51,142] ERROR in app: An error has occurred

request の情報をログに入れる

自作でフォーマッタを用意すれば request の内容を常にログに入れることもできます
default_hander に対して設定していますが独自のハンドラに設定することもできます
また default_handler の出力を表示するために development モードで起動しましょう

  • vim app.py
import logging
from flask import has_request_context, request
from flask.logging import default_handler
from flask import Flask

app = Flask(__name__)

class RequestFormatter(logging.Formatter):
    def format(self, record):
        if has_request_context():
            record.url = request.url
            record.remote_addr = request.remote_addr
        else:
            record.url = None
            record.remote_addr = None

        return super().format(record)

formatter = RequestFormatter(
    '[%(asctime)s] %(remote_addr)s requested %(url)s '
    '%(levelname)s in %(module)s: %(message)s'
)

default_handler.setFormatter(formatter)
default_handler.setLevel(logging.INFO)

@app.route('/')
def hello_world():
    app.logger.info('called hello world')
    return 'Hello, World!'

確認すると以下のようなログが追加で表示されるのが確認できると思います

  • FLASK_ENV=development FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000
[2020-10-30 11:09:58,170] 127.0.0.1 requested http://localhost:5000/ INFO in app: called hello world

デフォルトの werkzeug ロガーのフォーマットを変更する

デフォルトで表示されているリクエストログは werkzeug というモジュールのロガーになります
これにハンドラを追加すればフォーマットを変更できます
例えば先程の RequestFormatter にする場合は以下のようにします

import logging
from flask import has_request_context, request
from flask.logging import default_handler
from flask import Flask

app = Flask(__name__)

class RequestFormatter(logging.Formatter):
    def format(self, record):
        if has_request_context():
            record.url = request.url
            record.remote_addr = request.remote_addr
        else:
            record.url = None
            record.remote_addr = None

        return super().format(record)

formatter = RequestFormatter(
    '[%(asctime)s] %(remote_addr)s requested %(url)s '
    '%(levelname)s in %(module)s: %(message)s'
)

default_handler.setFormatter(formatter)
default_handler.setLevel(logging.INFO)

werkzeug_logger = logging.getLogger('werkzeug')
werkzeug_logger.addHandler(default_handler)

@app.route('/')
def hello_world():
    app.logger.info('called hello world')
    return 'Hello, World!'
  • FLASK_ENV=development FLASK_APP=app.py pipenv run flask run
  • curl localhost:5000
[2020-10-30 11:16:14,753] 127.0.0.1 requested http://localhost:5000/ INFO in app: called hello world [2020-10-30 11:16:14,754] None requested None INFO in _internal: 127.0.0.1 - - [30/Oct/2020 11:16:14] "GET / HTTP/1.1" 200 -

最後に

flask のロギング機構について調べてみました
基本はハンドラを作成してそのハンドラに対してログレベルやフォーマットを設定し作成したハンドラをアプリのロガーに設定するという流れになります
ハンドラは自分で作成もできますし Python にいくつか標準で準備されているハンドラがあるので自分のやりたいことにあったハンドラを使えば OK です

参考サイト

2020年10月29日木曜日

Celery の concurrency について試してみた

概要

Celery のワーカの並列数を指定するにはワーカを起動する際に --concurrency オプションを指定します
今回は --concurrenty の使い方とポイントを紹介します

環境

  • macOS 10.15.7
  • Python 3.8.5
    • celery 4.4.7

とりあえず concurrency を使ってみる

とりあえずワーカ 1 つで concurrency を使ってみます
ワーカは簡単なワーカを使います
効果を確認するために sleep を入れています

  • vim sub_tasks.py
import time
from celery import Celery

app = Celery('sub_tasks', backend='redis://localhost', broker='redis://localhost')

@app.task
def add(x, y):
    time.sleep(10)
    return x + y

メインは以下の通りです

  • vim main.py
from sub_tasks import add

for i in range(10):
    ret = add.delay(100, i)
    print(ret)

ワーカを起動します
--concurrency=10 で起動してみます

  • pipenv run celery -A sub_tasks worker --loglevel=info --concurrency=10

これでメインを起動してみます

  • pipenv run python main.py

main.py は非同期で実行されたジョブの ID が表示されてすぐに終了します
ワーカ側の処理を見ると 10 個のジョブがすべて同時に実行されているのが確認できると思います

タスクごとに concurrency を変更したい場合には

ワーカごとに concurrency を変更したい場合は単純に起動するワーカごとに concurrency 引数の値を変更すれば OK です
Celery でタスクごとに concurrency を変更できるのかというと結論としてはバージョン 4 系ではできません (参考)
なのでタスクごとに concurrency を変更したい場合はワーカに分割しかつキューも専用のキューを指定する必要があります

sub_tasks2.py を作成して動作確認してみます
task_routes でワーカが処理対象とするキューを指定できます

  • vim sub_tasks2.py
import time
from celery import Celery

app = Celery('sub_tasks', backend='redis://localhost', broker='redis://localhost')
app.conf.task_routes = {'sub_tasks2.multi': {'queue': 'multi'}}

@app.task
def multi(x, y):
    time.sleep(10)
    return x * y

そして既存の sub_tasks.py も修正します
こちらも処理対象のキューを指定しましょう

  • vim sub_tasks.py
import time
from celery import Celery

app = Celery('sub_tasks', backend='redis://localhost', broker='redis://localhost')
app.conf.task_routes = {'sub_tasks.add': {'queue': 'add'}}

@app.task
def add(x, y):
    time.sleep(10)
    return x + y

メインのスクリプトは上記 2 つのワーカを呼び出すように変更します

  • vim main.py
from sub_tasks import add
from sub_tasks2 import multi

for i in range(10):
    ret = add.delay(100, i)
    print(ret)
    ret = multi.delay(100, i)
    print(ret)

あとはワーカをそれぞれ起動するだけですがこのときも、どのキューに対して処理するのかを指定します
また今回は動作確認として sub_tasks2 側のワーカを --concurrency=1 で起動して並列数が 1 で実行されるか確認します

  • pipenv run celery -A sub_tasks worker --loglevel=info --concurrency=10 -Q add
  • pipenv run celery -A sub_tasks2 worker --loglevel=info --concurrency=1 -Q multi

これで準備 OK です
あとはメインを実行します

  • pipenv run python main.py

メインはこれまで通りすぐに結果が返ってくるのが確認できると思います
そしてワーカは sub_tasks 側は 10 個のジョブがすべて並列で終了するのに対して sub_tasks2 側はジョブは 1 つずつ終了するのが確認できると思います

気になったこと

sub_taksk2 側のワーカがジョブを受け取る際に一気に 5 個のジョブを受け取ってそれぞれ 1 つずつ処理し 1 つ処理が終わるとまた 1 つジョブを受け取る感じでした
sub_tasks 側はジョブの受け取りも実行も同時に 10 個ずつ行っていました

もしかするとワーカのジョブの受け取り方も concurrency が影響しているのかもしれません

最後に

Celery のワーカの並列数について挙動を確認してみました
タスクごとに並列数を変更したい場合はワーカにしてかつキューも指定する必要があることがわかりました

もしかするとバージョンが上がればタスクごとに並列数を指定することができるオプションが追加されるかもしれません

参考サイト

2020年10月28日水曜日

envoy 超入門

概要

モダンプロキシサーバの envoy を試してみました
イメージとしては nginx や HAProxy などの代替になるツールという印象です
とりあえずデモにあるプロキシを経由するとすべてのアクセスが特定のサイトのコンテンツを表示するサンプルを試してみました

環境

  • macOS 10.15.7
  • envoy 1.16.0

インストール

Mac の場合は Homebrew でインストールすることが可能です

  • brew install envoy

--version オプションでバージョンが確認できます

  • envoy --version

Getting Started

とりあえず試してみましょう
まずは起動します

  • wget https://www.envoyproxy.io/docs/envoy/latest/_downloads/f6e613dcd48bb592b753313e7cfb1b28/envoy-demo.yaml
  • envoy -c envoy-demo.yaml

localhost:10000 で envoy が起動しています

  • curl localhost:10000

アクセスすると www.envoyproxy.io の画面が表示されると思います
これは envoy-demo.yaml を見るとわかりますがすべてのアクセスを www.envoyproxy.io に流すように定義されているためです

filter_chains:
- filters:
  - name: envoy.filters.network.http_connection_manager
    typed_config:
      "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager
      stat_prefix: ingress_http
      http_filters:
      - name: envoy.filters.http.router
      route_config:
        name: local_route
        virtual_hosts:
        - name: local_service
          domains: ["*"]
          routes:
          - match:
              prefix: "/"
            route:
              host_rewrite_literal: www.envoyproxy.io
              cluster: service_envoyproxy_io

例えば localhost:10000/try にアクセスすると www.envoyproxy.io/try のページが表示されます

管理画面にアクセスする

また localhost:9901 で管理画面が起動しているのでブラウザでアクセスしてみましょう

こんな感じで envoy の各種設定や動作しているホストの情報を確認することができます

管理画面にアクセスできる定義も envoy-demo.yaml 内で定義されています

admin:
  access_log_path: /dev/null
  address:
    socket_address:
      address: 0.0.0.0
      port_value: 9901

最後に

macOS 上で envoy をとりあえず動かしてみました
k8s 上でサービスメッシュを実現するというコンテキストで使われることが多いようですが単体でも動作することが確認できました

設定ファイルを YAML で定義してプロキシへのアクセスをすべて特定のサイトに移動するようなデモを試してみました
nginx でも同じようなことができるのでイメージしやすいデモだったかなと思います

今回はルーティングルールを静的に記載しましたが envoy はこれを動的に行うこともできるようです (参考: Examples Dynamic)

参考サイト

2020年10月27日火曜日

Ubuntu18.04 で squid をインストールして使ってみる

概要

サクッと Web Proxy がほしい場合には squid が簡単です
今回は Ubuntu で試してみました
squid のバージョンは若干古いです (執筆時の最新版は 4.13)

環境

  • Ubuntu 18.04 (on Vagrant)
  • squid 3.5.12

インストール

  • sudo apt -y update
  • sudo apt -y install squid

すべての http/https サイトにアクセスできるようにする

  • vim /etc/squid/squid.conf
http_access allow all
  • sudo systemctl daemon-reload

起動

  • sudo systemctl restart squid

動作確認

とりあえず curl で確認します

  • http_proxy=192.168.100.10:3128 https_proxy=192.168.100.10:3128 curl https://kaka-request-dumper.herokuapp.com/

Ruby でも確認してみます

  • vim test.rb
require 'net/http'

proxy_addr = '192.168.100.10'
proxy_port = 3128

res = Net::HTTP.new('kaka-request-dumper.herokuapp.com', nil, proxy_addr, proxy_port).start { |http|
  http.get('/')
}

puts res.body
  • ruby test.rb

ちゃんとプロキシを経由してもアクセスできることが確認できると思います

最後に

とりあえず Web プロキシがほしい場合は squid が簡単そうです
バージョンが古かったり詳細なセキュリティ設定はしていないので限られた環境であればこれくらいの設定でも十分機能すると思います

2020年10月26日月曜日

Ruby で i18n をやってみる (with Sinatra)

概要

Ruby の i18n ジェムを使ってみました
単体で使用する方法と Sinatra で使用する方法を紹介します

環境

  • macOS 10.15.7
  • Ruby 2.7.1p83
    • i18n 1.8.5

インストール

  • bundle init
  • vim Gemfile
gem "sinatra"
gem "i18n"
  • bundle install

単体で使用する

まずは単体で使用する方法を紹介します
各言語ごとにプロパティファイルを作成します

  • mkdir config/locales
  • vim config/locales/jp.yml
jp:
  name: "ほーくすのうろぐ"
  age: 20
  • vim config/locales/en.yml
en:
  name: "hawksnowlog"
  age: 10

あとは i18n を使って YAML ファイルの値を参照するだけです
default_locale で言語の出し分けをします

  • vim app.rb
require 'i18n'

I18n.load_path << Dir[File.expand_path("config/locales") + "/*.yml"]
I18n.default_locale = :jp
# I18n.default_locale = :en

puts I18n.t(:name)
puts I18n.t(:age)
  • bundle exec ruby app.rb

単体ではこんな感じで動作させます

Sinatra で使ってみる

configure や before を使っています
helpers を使ってもいいかなと思います
ブラウザは Accept-Language ヘッダを見てロケールを設定するのでそのようにしています
ヘッダは String なので Symbol に変換してから使いましょう

  • vim app.rb
require 'i18n'
require 'sinatra/base'

class MyApp < Sinatra::Base
  configure do
    I18n.load_path << Dir[File.expand_path("config/locales") + "/*.yml"]
    I18n.config.available_locales = [:en, :jp]
  end

  before do
    unless request.env["HTTP_ACCEPT_LANGUAGE"].nil?
      lang = request.env["HTTP_ACCEPT_LANGUAGE"].to_sym
      I18n.locale = I18n.config.available_locales.include?(lang) ? lang : :en
    end
  end

  get '/' do
    "name => #{I18n.t(:name)}, age => #{I18n.t(:age)}"
  end
end
  • vim config.ru
require './app'
run MyApp
  • bundle exec rackup config.ru

動作確認してみます
Accept-Language ヘッダをいろいろと変更して確認してみると良いと思います

  • curl localhost:9292

=> name => hawksnowlog, age => 10

  • curl -H "Accept-Language: jp" localhost:9292

=> name => ほーくすのうろぐ, age => 20

  • curl -H "Accept-Language: fr" localhost:9292

=> name => hawksnowlog, age => 10

最後に

Ruby の i18n ジェムを使って国際化する簡単なサンプルを紹介してみました
Rails と組み合わせて使う例はたくさんあるのですが Sinatra は少なかったので Sinatra とも組み合わせてみました

YAML ファイルで簡単に切り分けできるのと他の言語に対応する場合は YAML ファイルを新規作成するだけなので便利です

参考サイト

2020年10月24日土曜日

(Ruby) クラス内で定義したインスタンスメソッドやクラスメソッドを CLI からコールする方法

概要

わざわざ実行スクリプトを作らなくても CLI から実行できます

環境

  • macOS 10.15.7
  • Ruby 2.7.1p83

サンプルコード

class MyClass
  def initialize(value)
    @value = value
  end

  def method
    puts @value
  end

  def self.class_method
    puts "class_method"
  end
end

インスタンスメソッドの呼び出し

  • ruby -r './app.rb' -e 'MyClass.new("hello").method'

クラスメソッドの呼び出し

  • ruby -r './app.rb' -e 'MyClass.class_method'

複数行になる場合

素直に irb を使います

irb(main):001:0> require './app.rb' => true irb(main):002:0> mc = MyClass.new('HELLO') irb(main):003:0> mc.method HELLO => nil irb(main):004:0> MyClass.class_method class_method => nil

最後に

-r で require し -e でスクリプトを実行できます
複数行になる場合は irb を使いましょう

参考サイト

2020年10月23日金曜日

shell2http でファイルをアップロードする方法

概要

shell2http でファイルを受け取る方法を紹介します
クライアント側は curl, ruby, python で試してみました

環境

  • macOS 10.15.7
  • shell2http 1.13

準備

過去の記事を参考にインストールしてください

form を使ってファイルを受け取る

--form オプションを使います
受け取ったファイルの情報はリダイレクトすることでファイルとして保存します

  • shell2http --form /upload 'cat $filepath_uploadfile > uploaded_file.dat'

curl で試す

test.dat というファイルを送ってみます

  • curl -X POST -F uploadfile=@./test.dat localhost:8080/upload

サーバ側では uploaded_file.dat という名前で保存されているのが確認できると思います
また uploadfile= の部分がフォームとして送られるファイルの名前になるのでここが uploadfile2 などになるとリクエストは送信できますがサーバ側で指定のファイルがないため uploaded_file.dat が空で生成されます
エラーにならないので注意してください

Ruby で試す

net/http の post_form を使っています

require 'net/http'
require 'uri'

url = URI.parse('http://localhost:8080/upload')
http = Net::HTTP.new(url.host, url.port)

req = Net::HTTP::Post.new(url.path)
filename = 'test.dat'
f = open("./#{filename}")
query = [
  [ 'uploadfile', f, { uploadfile: filename } ]
]
req.set_form(query, "multipart/form-data")

ret = http.request(req)
ret.to_hash

Python で試す

標準ライブラリの urllib を使いたかったのですが情報が少なく requests を使いました

  • pipenv install requests
  • vim upload.py
import requests

url = 'http://localhost:8080/upload'
file = {'uploadfile': open('test.dat', 'rb')}
res = requests.post(url, files=file)
print(res)
  • pipenv run python upload.py

最後に

shell2http で form を使ってファイルを受け取る方法を紹介しました
クライアント側は POST で multipart/form-data でファイルを送信すれば良さそうです