DEVGRU

プログラミングと競馬予想について書きます

pytest と unittest.mock を使って標準出力のテストを書けなかった話

今回は、標準出力に文字列を出力する実装に対して pytest でテストを書く必要があり、 unittest.mock と Python のライブラリリファレンスにかかれていた方法を組み合わせたら見事にハマったお話です。

広告

シンプルにするとこんな感じに、標準出力への文字列が唯一の副作用となる関数があります。

def hello(name=None):
    if name:
        print(f"Hello, {name}")
    else:
        print("Hello")

if __name__ == "__main__":
    import sys
    
    if len(sys.argv) >= 2:
       name = sys.argv[1]
       hello(name)
    else:
       hello()

コマンドラインから実行するとこのように引数の有無で出力が異なる内容になります。

$ python hello.py
Hello

$ python hello.py John
Hello, John

テストのお作法としては、文字列と出力を分けることでテストしやすくするのが筋ですが、それができないこともたまにあります 1

def generate_message(name=None):
    if name:
        return f"Hello, {name}"
    else:
        return "Hello"

def hello(name):
      print(generate_message(name))

また、上記の例なら単純に doctest で良いのですが、もう少し複雑だったりするとそうも言っていられません。

Python のリファレンスマニュアルに標準出力のモック方法が書いてあったので、それにならって pytest でテストを書いてみました。

from hello import hello
import pytest
from unittest.mock import patch
from io import StringIO

@pytest.fixture()
def mock_stdout():
    with patch("sys.stdout", new_callable=StringIO) as m:
        yield m

def test_hello_without_name(mock_stdout):
    hello()
    assert mock_stdout.getvalue() == "Hello\n"

def test_hello_with_name(mock_stdout):
    hello("John")
    assert mock_stdout.getvalue()  == "Hello, John\n"

テストのデバッグをするためにいつもの -s をつけて実行してみると、きちんと通ります。

$ pytest -s test_hello.py
=========================================================================================================== test session starts ===========================================================================================================
platform darwin -- Python 3.8.3, pytest-6.2.4, py-1.10.0, pluggy-0.13.1
rootdir: /Users/devgru/work/blog-sandbox/2021-05-05T21:20:52
collected 2 items

test_hello.py ..

============================================================================================================ 2 passed in 0.10s ============================================================================================================

しかし、 PR を作って CI でも動作することを確認したら、何故か落ちます。

$ pytest test_hello.py
=========================================================================================================== test session starts ===========================================================================================================
platform darwin -- Python 3.8.3, pytest-6.2.4, py-1.10.0, pluggy-0.13.1
rootdir: /Users/devgru/work/blog-sandbox/2021-05-05T21:20:52
collected 2 items

test_hello.py FF                                                                                                                                                                                                                    [100%]

================================================================================================================ FAILURES =================================================================================================================
_________________________________________________________________________________________________________ test_hello_without_name _________________________________________________________________________________________________________

mock_stdout = <_io.StringIO object at 0x11104f9d0>

    def test_hello_without_name(mock_stdout):
        hello()
>       assert mock_stdout.getvalue() == "Hello\n"
E       AssertionError: assert '' == 'Hello\n'
E         - Hello

test_hello.py:13: AssertionError
---------------------------------------------------------------------------------------------------------- Captured stdout call -----------------------------------------------------------------------------------------------------------
Hello
__________________________________________________________________________________________________________ test_hello_with_name ___________________________________________________________________________________________________________

mock_stdout = <_io.StringIO object at 0x110b205e0>

    def test_hello_with_name(mock_stdout):
        hello("John")
>       assert mock_stdout.getvalue()  == "Hello, John\n"
E       AssertionError: assert '' == 'Hello, John\n'
E         - Hello, John

test_hello.py:17: AssertionError
---------------------------------------------------------------------------------------------------------- Captured stdout call -----------------------------------------------------------------------------------------------------------
Hello, John
========================================================================================================= short test summary info =========================================================================================================
FAILED test_hello.py::test_hello_without_name - AssertionError: assert '' == 'Hello\n'
FAILED test_hello.py::test_hello_with_name - AssertionError: assert '' == 'Hello, John\n'
============================================================================================================ 2 failed in 0.16s ============================================================================================================

どうやら、unittest.mock.patch() で差し替えた StringIO() に値が書き込まれていないようです。

-s オプションの有無で挙動が変わるということは、おそらく pytest 自体がモックをしているために、その後に patch しても届かないと予想されます。

散々悩んだ挙げ句、 python pytest mock stdout でググったところ、テックブログ界の雄こと Developers IO 2記事が見つかりました。

曰く、 capfd を用いるのが良いとのこと。

from hello import hello

def test_hello_without_name(capfd):
    hello()
    captured = capfd.readouterr()
    assert captured.out == "Hello\n"

def test_hello_with_name(capfd):
    hello("John")
    captured = capfd.readouterr()
    assert captured.out == "Hello, John\n"  
pytest test_hello2.py
=========================================================================================================== test session starts ===========================================================================================================
platform darwin -- Python 3.8.3, pytest-6.2.4, py-1.10.0, pluggy-0.13.1
rootdir: /Users/devgru/work/blog-sandbox/2021-05-05T21:20:52
collected 2 items

test_hello2.py ..                                                                                                                                                                                                                   [100%]

============================================================================================================ 2 passed in 0.03s ============================================================================================================

今度は無事通りました。

テスト駆動Python

テスト駆動Python

  • 作者:BrianOkken
  • 発売日: 2018/08/29
  • メディア: Kindle版

テスト駆動開発

テスト駆動開発


  1. 納期とか、他人の書いたコードだったりとか。

  2. 最近は何を検索してもこのブログの記事が出てくるような気がしている。

JavaScript の正規表現リテラルの評価タイミングとパフォーマンス

正規表現リテラルと正規表現オブジェクトの評価について、誤解していたのでメモ。

広告

以下の2つのJavaScriptコードを実行した際のパフォーマンスを考える。

regexp-literal.js

for (let i = 0; i < 1000000; i++) {
        /^(3|5|9)/.test(i);
}

regexp-object.js

for (let i = 0; i < 1000000; i++) {
        new RegExp("^(3|5|9)").test(i);
}

手元のV8で実行するとこうなる。正規表現リテラルのほうが正規表現オブジェクトより2倍速い。

time d8 regexp-literal.js
d8 regexp-literal.js  0.10s user 0.03s system 98% cpu 0.135 total
time d8 regexp-object.js
d8 regexp-object.js  0.20s user 0.03s system 97% cpu 0.236 total

しかし、この差がどこから来るのかという点を完全に誤解していた。

最初は正規表現リテラルはコンパイル時に一度作られたっきりで以降は再利用されると思っていたが、どうやら違うようだ。

つまり、このようなコードに近いと思っていた。

regexp-literal-optimized.js

const r = /^(3|5|9)/.test(i);
for (let i = 0; i < 1000000; i++) {
        r.test(i);
}

しかし、それが違うということはバイトコードを出力するとわかる。

$ d8 --print-bytecode regexp-literal.js
[generated bytecode for function:  (0x3b600821248d <SharedFunctionInfo>)]
Parameter count 1
Register count 5
Frame size 40
         0x3b6008212512 @    0 : 0b                LdaZero
         0x3b6008212513 @    1 : 26 f9             Star r1
         0x3b6008212515 @    3 : 0d                LdaUndefined
         0x3b6008212516 @    4 : 26 fa             Star r0
         0x3b6008212518 @    6 : 01 0c 40 42 0f 00 LdaSmi.ExtraWide [1000000]
         0x3b600821251e @   12 : 6a f9 00          TestLessThan r1, [0]
         0x3b6008212521 @   15 : 9b 29             JumpIfFalse [41] (0x3b600821254a @ 56)
         0x3b6008212523 @   17 : 7a 00 01 00       CreateRegExpLiteral [0], [1], #0
         0x3b6008212527 @   21 : 26 f7             Star r3
         0x3b6008212529 @   23 : 28 f7 01 02       LdaNamedProperty r3, [1], [2]
         0x3b600821252d @   27 : 26 f8             Star r2
         0x3b600821252f @   29 : 12 02             LdaConstant [2]
         0x3b6008212531 @   31 : 26 f6             Star r4
         0x3b6008212533 @   33 : 25 f9             Ldar r1
         0x3b6008212535 @   35 : 35 f6 04          Add r4, [4]
         0x3b6008212538 @   38 : 26 f6             Star r4
         0x3b600821253a @   40 : 5a f8 f7 f6 05    CallProperty1 r2, r3, r4, [5]
         0x3b600821253f @   45 : 26 fa             Star r0
         0x3b6008212541 @   47 : 25 f9             Ldar r1
         0x3b6008212543 @   49 : 4d 07             Inc [7]
         0x3b6008212545 @   51 : 26 f9             Star r1
         0x3b6008212547 @   53 : 8b 2f 00          JumpLoop [47], [0] (0x3b6008212518 @ 6)
         0x3b600821254a @   56 : 25 fa             Ldar r0
         0x3b600821254c @   58 : ab                Return
Constant pool (size = 3)
Handler Table (size = 0)
Source Position Table (size = 0)

CreateRegExpLiteralTestLessThanJumpIfFalse の内側にあることから、ループ内で正規表現リテラルの評価が行われている事がわかる。

評価タイミングが予想していたのと全く異なるのだ 1

ちなみに正規表現オブジェクトの場合はこのようになる。

$ d8 --print-bytecode regexp-object.js
[generated bytecode for function:  (0x16e00821248d <SharedFunctionInfo>)]
Parameter count 1
Register count 5
Frame size 40
         0x16e008212516 @    0 : 0b                LdaZero
         0x16e008212517 @    1 : 26 f9             Star r1
         0x16e008212519 @    3 : 0d                LdaUndefined
         0x16e00821251a @    4 : 26 fa             Star r0
         0x16e00821251c @    6 : 01 0c 40 42 0f 00 LdaSmi.ExtraWide [1000000]
         0x16e008212522 @   12 : 6a f9 00          TestLessThan r1, [0]
         0x16e008212525 @   15 : 9b 35             JumpIfFalse [53] (0x16e00821255a @ 68)
         0x16e008212527 @   17 : 13 00 01          LdaGlobal [0], [1]
         0x16e00821252a @   20 : 26 f7             Star r3
         0x16e00821252c @   22 : 12 01             LdaConstant [1]
         0x16e00821252e @   24 : 26 f6             Star r4
         0x16e008212530 @   26 : 25 f7             Ldar r3
         0x16e008212532 @   28 : 66 f7 f6 01 03    Construct r3, r4-r4, [3]
         0x16e008212537 @   33 : 26 f7             Star r3
         0x16e008212539 @   35 : 28 f7 02 05       LdaNamedProperty r3, [2], [5]
         0x16e00821253d @   39 : 26 f8             Star r2
         0x16e00821253f @   41 : 12 03             LdaConstant [3]
         0x16e008212541 @   43 : 26 f6             Star r4
         0x16e008212543 @   45 : 25 f9             Ldar r1
         0x16e008212545 @   47 : 35 f6 07          Add r4, [7]
         0x16e008212548 @   50 : 26 f6             Star r4
         0x16e00821254a @   52 : 5a f8 f7 f6 08    CallProperty1 r2, r3, r4, [8]
         0x16e00821254f @   57 : 26 fa             Star r0
         0x16e008212551 @   59 : 25 f9             Ldar r1
         0x16e008212553 @   61 : 4d 0a             Inc [10]
         0x16e008212555 @   63 : 26 f9             Star r1
         0x16e008212557 @   65 : 8b 3b 00          JumpLoop [59], [0] (0x16e00821251c @ 6)
         0x16e00821255a @   68 : 25 fa             Ldar r0
         0x16e00821255c @   70 : ab                Return
Constant pool (size = 4)
Handler Table (size = 0)
Source Position Table (size = 0)

こちらはRegExpがないが、Construct のところで new RegExp() の評価をしていることがわかる。


さて、じゃあどこから実行時間の差が来るのか、というところをバイトコードを踏まえて考察すると、正規表現オブジェクトのコンストラクタ呼び出しにかかるコストの差ではないかと予想される。バイトコードで直に呼び出すのとの少しだけ差が実行時間に現れた、という理解をしている。

さて、ループ外で正規表現リテラルを作ってそれを参照する場合にはどの程度速くなるのだろうか。

time d8 regexp-literal-optimized.js                                                                                                                                                          
d8 regexp-literal-optimized.js  0.10s user 0.03s system 93% cpu 0.135 total

0.10s → 0.10s なので、ほとんど変わらない。

この謎はV8のソースコードの compilation-cache.h30) で解けた。正規表現をキャッシュしているのである。

つまるところ、ループ内外や正規表現リテラルかオブジェクトの違いに関係なく、一番重い処理である正規表現のコンパイルは1度しか行われず、そこに至る道の微妙な違いがパフォーマンスの差として出てくるだけだった。

よくよく考えると、コンパイル時評価はパフォーマンスとメモリフットプリントの観点で問題がある。使わない正規表現がたくさんある場合にコンパイル時評価をするとその分パフォーマンス低下が起きるし、メモリも無駄に消費する。それを考えると、V8 のように on-demand で評価するのが正解なのだ。


  1. この誤解の原因は明白で、コンパイル時に正規表現リテラルを評価する実装を作ったことがあるからだ

Re: 愛すべきAngularとのお別れ。2,3年後を見据えReactにリプレイスする話

note.com

上記の記事について、現職では主に Angular を使っている立場(※ 社内ではReactのプロダクトも複数あります)でこの記事についての感想を述べます。

広告

理由はAngularを書ける(or書きたい)エンジニアを採用することが難しいからです。それにつきます。

はい、特に異論はありません。

実際、現職でもAngular のプロダクトのフロントエンドエンジニアの採用には苦戦しており、採用が難しい点について概ね事実かと思います。

その差が出たのは、元記事で指摘されている通り、 "React & Vue.js" vs "Angular" の勢力の別れ方が大きいかと思います。

Vue.js と Angular を触った経験としては、パラダイムというか宗派が異なる部分は確かにあるという感触です。

一方でこの記事の読者に気をつけていただきたいのは、 Angular と React の技術的な優劣を評価してのことではないことです 1

Angular は良いフレームワークです。

RxJS という強力な非同期実行フレームワークを基礎としており、更に NgRx という Redux 的なフレームワークもあります。 Breaking Change も気を使っていて、削除する機能は必ず2バージョン前から告知されます。 アップグレードする際には非互換なAPIを自動的にマイグレーションしてくれます。 Google が主体となって開発していて、いきなりメンテナンスが無くなる心配もありません。 ビルド周りはwebpackをいい感じにラップしているので、面倒なことは少ないです。 ユーザ会も活発に活動していて、月に1回はYoutubeでの配信がありますし、相談も非常に親身になって乗ってくれます。 なので、エンタープライズでは非常にありがたいです。

しかし求人が少ないのです。

この違いがどこから来るのかは定かではないですが、以下個人の感想です。

まず、Reactのほうが入り口は低いように感じます。 また、Angular はできることが多い分、設計の難易度がやや高い気もします。RxJS や NgRx を用いた設計に迷うことは少しあります。

そして、日本語の情報は圧倒的に React のほうが多いです。そのため、初学者にとってReactのほうがとっつきやすいです。

その結果としての求人の数の差なのかなと思います 2

ですので、採用についての圧倒的なアドバンテージを考えると、元記事は至極まっとうな判断だと思います。

以上、感想でした。


  1. もちろん優劣はあるでしょうが。

  2. もしかしたらもっと別な技術的な差があるかもしれませんが、Reactの学習についてまだ未着手のため評価しきれず。