Flask Mega-Tutorial、パート16：デバッグ、テスト、およびプロファイリング

これはシリーズの16番目の記事で、 Flaskマイクロフレームワークを使用してPython Webアプリケーションを作成した経験を説明しています。



このガイドの目的は、かなり機能的なマイクロブログアプリケーションを開発することです。オリジナリティが完全に欠如しているため、マイクロブログアプリケーションと呼ぶことにしました。







私たちの謙虚なアプリはリリースの準備ができている兆候を見せ始めているので、できるだけそれを整理する時が来ました。 少し前まで、このブログの読者の1人（hello George！）が奇妙なデータベースの動作を報告しました。今日はデバッグを試みます。 これにより、コードをどれだけ注意深く作成し、テストする頻度に関係なく、一部のエラーが気付かれないことがあることがわかります。 残念ながら、それらを発見するのは通常エンドユーザーです。



このエラーを修正して次のエラーが検出されるのを待つのではなく、考えられるエラーを検出するための予防策を講じます。



この記事の最初の部分では、 デバッグについて説明し、複雑な問題をデバッグするときに使用するいくつかのトリックとテクニックを紹介します。



後で、テスト戦略の有効性を評価する方法を確認します。 単体テストがカバーするコードの量を測定します。これをテストカバレッジと呼びます 。



結論として、多くのアプリケーションがしばしば遭遇する別のクラスの問題-不十分なパフォーマンスについて考察します。 プロファイリング手法を見て、アプリケーションの遅い部分を見つけます。



いいですね？ それでは始めましょう。

エラー

このブログの読者は、ユーザーが投稿を削除できる新しい機能を実装した後に問題を発見しました。 マイクロブログの公式バージョンにはこの機能が含まれていないので、デバッグできるようにすぐに実装します。

投稿を削除する表示機能（app / views.pyファイル）：

@app.route('/delete/<int:id>') @login_required def delete(id): post = Post.query.get(id) if post == None: flash('Post not found.') return redirect(url_for('index')) if post.author.id != g.user.id: flash('You cannot delete this post.') return redirect(url_for('index')) db.session.delete(post) db.session.commit() flash('Your post has been deleted.') return redirect(url_for('index'))
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

この機能を有効にするには、現在のユーザーに属するすべての投稿に削除リンクを追加します（ファイルapp / templates / post.html）：

 {% if post.author.id == g.user.id %} <div><a href="{{ url_for('delete', id = post.id) }}">{{ _('Delete') }}</a></div> {% endif %}
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

私たちにとって新しいことは何もありません。これは以前にも何度か行ってきました。



デバッグを無効（debug = False）にしてアプリケーションを実行し、ユーザーの目を通して見てみましょう。

LinuxおよびMacユーザーは、コンソールで実行します。

 $ ./runp.py
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

Windowsユーザーは、コマンドシェルで次のコマンドを実行します。

 flask/Scripts/python runp.py
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

ここで、ユーザーとして、投稿を作成してから削除してみます。 そして、削除リンクをクリックするとすぐに...ワム！



エラーが発生したことを示す短いメッセージを受信し、管理者に通知されます。 実際、この投稿は500.htmlテンプレートです。 デバッグをオフにすると、Flaskはリクエスト処理中に発生したすべてのエラーに対してこのテンプレートを返します。 なぜなら 「プロダクション」モードになっているため、実際のエラーメッセージも呼び出しスタックも表示されません。

「現場」問題のデバッグ

単体テストに関する記事を覚えているなら、アプリケーションの「本番」バージョンで実行するためにいくつかのデバッグサービスをアクティブにしました。 次に、アプリケーションの実行中にエラーと診断メッセージをログファイルに書き込むロガーを作成しました。 Flask自体は、発生した例外の呼び出しスタックを記録し、要求が完了するまで処理されませんでした。 さらに、エラーをログに書き込むときに管理者のリストのすべてのメンバーを送信するロガーを設定しました。



したがって、上記のようなエラーが発生した場合、ログファイルと電子メールの2つの場所にその性質に関する情報が一度に表示されます。



呼び出しスタックの内容はエラーを修正するのに十分ではないかもしれませんが、いずれの場合も何もないよりはましです。 既存の問題について何も知らないとします。 そして、今度は、コールスタックの印刷のみに基づいて、何が起こったかを判断する必要があります。 呼び出しスタックは次のとおりです。

 127.0.0.1 - - [03/Mar/2013 23:57:39] "GET /delete/12 HTTP/1.1" 500 - Traceback (most recent call last): File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__ return self.wsgi_app(environ, start_response) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1689, in wsgi_app response = self.make_response(self.handle_exception(e)) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1687, in wsgi_app response = self.full_dispatch_request() File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1360, in full_dispatch_request rv = self.handle_user_exception(e) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1358, in full_dispatch_request rv = self.dispatch_request() File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1344, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/home/microblog/flask/lib/python2.7/site-packages/flask_login.py", line 496, in decorated_view return fn(*args, **kwargs) File "/home/microblog/app/views.py", line 195, in delete db.session.delete(post) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/scoping.py", line 114, in do return getattr(self.registry(), name)(*args, **kwargs) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1400, in delete self._attach(state) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1656, in _attach state.session_id, self.hash_key)) InvalidRequestError: Object '<Post at 0xff35e7ac>' is already attached to session '1' (this is '3')
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

他のプログラミング言語を使用しているときにこのようなエラーメッセージを既に読んでいる場合は、Pythonが呼び出しスタックを逆の順序で表示することに注意してください。つまり、エラーの原因となったフレームは一番下にあります。



今、これにどのように対処しますか？



呼び出しスタックのプリントアウトから判断すると、sqlalchemy / orm / session.pyにあるSQLAlchemyセッション処理コードによって例外がスローされました。



呼び出しスタックを使用する場合、独自のコードから最後に実行された式を見つけることは常に役立ちます。 下から始めて、フレームごとに徐々にトラックを登っていくと、app / views.pyファイル、またはむしろdelete（）ビュー関数のdb.session.delete（post）式で4番目のフレームが見つかります。



これで、SQLAlchemyは現在のデータベースセッションでこの投稿を削除できないことがわかりました。 しかし、まだ理由はわかりません。



下部の例外のテキストを見ると、問題はPostオブジェクトがセッション「1」に属しているため、同じオブジェクトを別のセッション「3」にアタッチしようとしているようです。



Googleに助けを求めると、これらの問題のほとんどは、オブジェクトを2つの異なるセッションに一度に接続しようとする2つの要求を実行するマルチスレッドWebサーバーを使用するときに発生することがわかります。 ただし、シングルスレッドのPythonデバッグサーバーを使用しているため、これは当てはまりません。 そのため、1つではなく2つのアクティブなセッションを作成する他の問題があります。



問題の詳細については、より制御された環境でエラーを繰り返してみてください。 幸いなことに、このエラーはアプリケーションの「開発」バージョンにも表示されます。これは、500.htmlテンプレートではなく、Flask自体が提供するWebバージョンのコールスタックにアクセスできるため、わずかに優れています。



コールスタックのWebバージョンは、コードを表示し、式の実行の結果をすぐにブラウザからすべて見ることができるという点で注目に値します。 コードで何が起こっているのかを十分に理解していないため、何らかの理由で、これを作成したリクエストの最後の通常のセッションのように削除されなかった「1」のセッション（これが作成された最初のセッションであると仮定することができます）があると推測しますセッション。 したがって、問題を解決するために前進するには、誰がこの非公開セッションを作成したかを知るのがいいでしょう。

Pythonデバッガーの使用

オブジェクトの作成者を見つける最も簡単な方法は、オブジェクトのコンストラクターにブレークポイントを設定することです。 ブレークポイントは、特定の条件が満たされたときにプログラムの実行を一時停止するコマンドです。 そして、この時点で、プログラムを調べたり、この特定の実行ポイントでコールスタックを表示したり、変数の内容を表示したり、変更することさえできます 。ブレークポイントは、 デバッガの基本機能の1つです。 今回は、pdbと呼ばれるPythonインタープリターに付属のデバッガーを使用します。



しかし、どのクラスを探していますか？ Webバージョンのトラックに戻って見てみましょう。 トレースの各フレームの下部には、セッションを使用するクラスを見つけるためのコードビューアーとPythonコンソールへのリンクがあります（アイコンは右側にあり、フレームにカーソルを合わせると表示されます）。 コードパネルでは、明らかにSQLAlchemyデータベースセッションの基本クラスであるSessionクラス内にいることがわかります。 スタックの下部フレームのコンテキストはセッションオブジェクト内にあるため、コンソールで実際のセッションクラスを取得できます。

 >>> print self <flask_sqlalchemy._SignallingSession object at 0xff34914c>
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

これで、使用するセッションがFlask-SQLAlchemyで定義されていることがわかりました。これは、この拡張機能がSQLAlchemyパッケージのSessionクラスを継承する独自のセッションクラスを定義しているためです。



これで、ファイルflask / lib / python2.7 / site-packages / flask_sqlalchemy.pyにあるFlask-SQLAlchemy拡張機能のソースコードを調べ、_SignallingSessionクラスの__init __（）コンストラクターを見つけることができます。 これで、デバッグの準備が整いました。



Pythonアプリケーションにブレークポイントを設定するには、いくつかの方法があります。 最も簡単なのは、プログラムを停止する場所に次のコードを追加することです。

 import pdb; pdb.set_trace()
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

_SignallingSessionクラスのコンストラクターに一時的にブレークポイントを追加することで行うこと（ファイルflask / lib / python2.7 / site-packages / flask_sqlalchemy.py）：

 class _SignallingSession(Session): def __init__(self, db, autocommit=False, autoflush=False, **options): import pdb; pdb.set_trace() # <-- this is temporary! self.app = db.get_app() self._model_changes = {} Session.__init__(self, autocommit=autocommit, autoflush=autoflush, extension=db.session_extensions, bind=db.engine, binds=db.get_binds(self.app), **options) # ...
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

それでは、アプリケーションを再度実行して、何が起こるか見てみましょう。

 $ ./run.py > /home/microblog/flask/lib/python2.7/site-packages/flask_sqlalchemy.py(198)__init__() -> self.app = db.get_app() (Pdb)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

なぜなら 「Running on ...」というメッセージは表示されませんでしたが、サーバーがまだ起動していないことがわかります。 コードの一部で誰かが「神秘的な」セッションの作成を要求したため、プログラムの実行が中断されました！



すぐに答えなければならない最も重要な質問は、アプリケーションのどこにいるのかということです。これは、プログラムの途中で取り除くことができないセッション「1」の作成を誰が要求したかを教えてくれるからです。 コールスタックの内容を取得するには、btコマンド（backtraceの略）を使用します。

 (Pdb) bt /home/microblog/run.py(2)<module>() -> from app import app /home/microblog/app/__init__.py(44)<module>() -> from app import views, models /home/microblog/app/views.py(6)<module>() -> from forms import LoginForm, EditForm, PostForm, SearchForm /home/microblog/app/forms.py(4)<module>() -> from app.models import User /home/microblog/app/models.py(92)<module>() -> whooshalchemy.whoosh_index(app, Post) /home/microblog/flask/lib/python2.6/site-packages/flask_whooshalchemy.py(168)whoosh_index() -> _create_index(app, model)) /home/microblog/flask/lib/python2.6/site-packages/flask_whooshalchemy.py(199)_create_index() -> model.query = _QueryProxy(model.query, primary_key, /home/microblog/flask/lib/python2.6/site-packages/flask_sqlalchemy.py(397)__get__() -> return type.query_class(mapper, session=self.sa.session()) /home/microblog/flask/lib/python2.6/site-packages/sqlalchemy/orm/scoping.py(54)__call__() -> return self.registry() /home/microblog/flask/lib/python2.6/site-packages/sqlalchemy/util/_collections.py(852)__call__() -> return self.registry.setdefault(key, self.createfunc()) > /home/microblog/flask/lib/python2.6/site-packages/flask_sqlalchemy.py(198)__init__() -> self.app = db.get_app() (Pdb)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

前と同じように、下から始めて、コードを探して上に移動します。 そして、これは、全文検索が初期化されるmodels.pyモデルファイルの行92になります。

 whooshalchemy.whoosh_index(app, Post)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

変です。 データベースセッションを作成することも、このセッションを作成することも行いませんが、Flask-WhooshAlchemyの初期化自体がセッションを作成するようです。



これは私たちの間違いではなく、SQLAlchemyとWhooshのラッパー拡張の間に何らかの競合があるようです。 ここでやめて、これら2つのすばらしい拡張機能の開発者またはコミュニティに助けを求めることができます。 または、デバッグを続行して、ここで問題を解決できるかどうかを確認できます。 したがって、デバッグを続行します。興味がない場合は、次のセクションに自由に進んでください。



コールスタックをもう一度見てみましょう。 call whoosh_index（）を呼び出し、次に_create_index（）を呼び出します。 特定の行_create_index（）は次のようになります。

 model.query = _QueryProxy(model.query, primary_key, searcher, model)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

このコンテキストのモデル変数はPostクラスを表し、whoosh_index（）関数の引数として渡します。 これを考えると、Flask-WhooshAlchemyは、元のPost.queryを引数に加え、Woosh固有のコンテンツを受け取るPost.queryラッパーを作成するようです。 しかし、これはすでに興味深いです。 上記のトラックから判断すると、キュー内の次の関数は、Python言語記述子メソッドの 1つである__get __（）です。



__get __（）メソッドは、値に加えて特定の動作を持つ属性である記述子を実装するために使用されます。 記述子が言及されるたびに、__ get __（）関数が呼び出されます。 次に、関数は属性値を返す必要があります。 このコード行で言及されている属性はクエリのみであるため、以前はデータベースクエリを生成するために使用していた一見シンプルな属性が実際には記述子であり、属性ではないことがわかりました。 呼び出しスタックの残りは、model.query式の値を計算し、_QueryProxyオブジェクトのコンストラクターを作成する準備をします。



それでは、少し下のスタックを下って、次に何が起こるか見てみましょう。 __get __（）メソッドからの命令を以下に示します。



return type.query_class（マッパー、セッション= self.sa.session（））



そして、これは非常に奇妙なコードです。 たとえば、User.query.get（id）を呼び出すと、間接的に__get __（）メソッドを呼び出してクエリオブジェクトを取得し、それを使用してセッションを取得します。



Flask-WhooshAlchemyがmodel.queryを実行すると、セッションが作成され、クエリオブジェクトにアタッチされます。 しかし、Flask-WhooshAlchemyによってリクエストされたリクエストオブジェクトは、プレゼンテーション関数内で実行するものほど短命ではありません。 Flask-WhooshAlchemyは、このクエリオブジェクトを独自のクエリオブジェクトでラップし、model.queryに保存し直します。 なぜなら __set __（）メソッドが存在しない場合、新しいオブジェクトは属性として保存されます。 Postクラスの場合、これは、Flask-WhooshAlchemyの初期化が完了した後、同じ名前の記述子と属性があることを意味します。 優先順位に従って、この場合、属性が優先されます。そうでない場合、Whooshに基づく検索は機能しません。



これの重要な詳細は、上記のコードが「1」セッション内に含まれる定数属性を設定することです。 アプリケーションによって処理された最初のリクエストがこのセッションを使用し、完了後すぐにそれを忘れるという事実にもかかわらず、Post.query属性がそれを参照し続けるため、セッション自体はどこにも行きません。 これはまさに間違いです！

このエラーは、（私の意見では）記述子の紛らわしい性質が原因です。 それらは普通の属性のように見え、人々はそのように使用します。 Flask-WhooshAlchemyの開発者は、単にリクエストを実行するための有用な情報を保存する拡張リクエストオブジェクトを作成したかったのですが、クエリモデル属性を使用すると、セッションを開く動作が隠されているため、見た目よりも少しだけ多くのことが行われることに気付きませんでしたデータベースで。

回帰テスト

多くの場合、この状況で最も論理的なステップは、Flask-WhooshAlchemyエラーを修正して先に進むようです。 しかし、これを行った場合、将来そのような間違いがないことを保証するものは何ですか？ たとえば、1年でFlask-WhooshAlchemyを新しいバージョンにアップグレードし、編集を忘れた場合はどうなりますか？



エラーを検出するための最良のオプションは、エラーが将来再発するのを防ぐための単体テスト（いわゆる回帰 ）を作成することです。



ただし、同じテスト内で2つのクエリをエミュレートする必要があるため、このエラーのテストを作成するのは多少困難です。 最初のリクエストはPostオブジェクトにアクセスし、ページにデータを表示するために作成したリクエストをエミュレートします。 これが最初のリクエストであるため、セッション「1」を使用します。 次に、このセッションを忘れて、Flask-SQLAlchemyとまったく同じように新しいセッションを作成する必要があります。 最初のセッションが期待どおりに終了しないため、2番目のセッションでPostオブジェクトを削除しようとすると、このエラーが再度発生します。



Flask-SQLAlchemyのソースコードをもう一度見ると、db.create_scoped_session（）関数によって新しいセッションが作成され、リクエストが完了すると、db.session.remove（）関数を呼び出すことでセッションが破棄されることがわかります。 これを知っているので、このエラーのテストを書くのは非常に簡単です。

 def test_delete_post(self): # create a user and a post u = User(nickname = 'john', email = 'john@example.com') p = Post(body = 'test post', author = u, timestamp = datetime.utcnow()) db.session.add(u) db.session.add(p) db.session.commit() # query the post and destroy the session p = Post.query.get(1) db.session.remove() # delete the post using a new session db.session = db.create_scoped_session() db.session.delete(p) db.session.commit()
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

そして、もちろん、テストを実行すると、失敗したテストに関するメッセージが表示されます。

 $ ./tests.py .E.... ====================================================================== ERROR: test_delete_post (__main__.TestCase) ---------------------------------------------------------------------- Traceback (most recent call last): File "./tests.py", line 133, in test_delete_post db.session.delete(p) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/scoping.py", line 114, in do return getattr(self.registry(), name)(*args, **kwargs) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1400, in delete self._attach(state) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1656, in _attach state.session_id, self.hash_key)) InvalidRequestError: Object '<Post at 0xff09b7ac>' is already attached to session '1' (this is '3') ---------------------------------------------------------------------- Ran 6 tests in 3.852s FAILED (errors=1)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

訂正

この問題を解決するには、Flask-WhooshAlchemyリクエストオブジェクトをモデルにバインドする別の方法を見つける必要があります。



Flask-SQLAlchemyのドキュメントには、クエリの実行に使用されるクラスを含むmodel.query_class属性が記載されています。 実際、これは、Flask-WhooshAlchemyで使用されるものよりも、Flask-SQLAlchemyが変更されたクエリクラスを使用するように強制する、はるかに透過的で理解可能な方法です。 Flask-SQLAlchemyを設定してWhooshクエリクラス（Flask-SQLAlchemyからBaseQueryクラスを継承）を使用してクエリを作成する場合、結果は変わりませんが、エラーは消えます。



これらの変更を実装したgithubでFlask-WhooshAlchemyプロジェクトのフォークを作成しました。 変更を理解したい場合は 、コミットのgithub diffを見るか、拡張機能全体をダウンロードして元のflask_whooshalchemy.pyファイルに置き換えることができます。



私は開発者Flask-WhooshAlchemyに行った変更を送信しましたが、今度はそれらが公式バージョンに含まれることを願っています。

テストカバレッジ

アプリケーションをサーバーにデプロイした後にエラーの可能性を大幅に減らす1つの方法は、テスト範囲を厳しくすることです。 既にテストフレームワークがありますが、アプリケーションのどの部分が実際に使用されているかをどのようにテストするかをどのようにして知るのでしょうか



テストカバレッジ測定ツールは、実行中のアプリケーションを調べて、実行中または実行中でないコード行をマークできます。 完了後、開始されなかったコードの行を示すレポートを発行します。 テスト用にこのようなレポートを受け取ったら、完了したテストによってコードのどの部分が影響を受けなかったかを正確に判断できます。



Pythonには、簡単な名前coverageを備えた独自のテストカバレッジ測定ツールがあります。 インストールしましょう：

 flask/bin/pip install coverage
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

このツールは、コマンドラインから使用するか、スクリプトに直接呼び出しを埋め込むことができます。 誤って実行するのを忘れないように、最後のオプションを選択します。



レポート（tests.pyファイル）を生成するためにテストに追加する必要がある変更は次のとおりです。

 from coverage import coverage cov = coverage(branch = True, omit = ['flask/*', 'tests.py']) cov.start() # ... if __name__ == '__main__': try: unittest.main() except: pass cov.stop() cov.save() print "\n\nCoverage Report:\n" cov.report() print "HTML version: " + os.path.join(basedir, "tmp/coverage/index.html") cov.html_report(directory = 'tmp/coverage') cov.erase()
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

スクリプトの最初にカバレッジモジュールを初期化することから始めます。 branch = Trueパラメーターは、通常の行ごとのカバレッジチェックに加えて、実行ブランチの分析の必要性を示します。 除外パラメーターは、仮想環境にインストールされているすべてのサードパーティモジュールとテストフレームワーク自体をテストから除外するために必要です。これは、アプリケーションのみのコードを分析することに関心があるためです。



カバレッジ統計を収集するには、cov.start（）を呼び出してからユニットテストを実行します。そうしないと、テストカバレッジレポートを生成せずにスクリプトが終了するため、テストフレームワークで発生した例外をキャッチしてスキップする必要があります。テストが終了したら、cov.stop（）でカバレッジを停止し、cov.save（）で結果を記録します。最終的に、cov.report（）は統計をコンソールに出力し、cov.html_report（）は同じデータでより魅力的なHTMLレポートを生成し、cov.erase（）はデータファイルを削除します。



以下は、レポート生成をアクティブにしてテストを実行する例です（注意：落下テストは終了しました）。

 $ ./tests.py .....F ====================================================================== FAIL: test_translation (__main__.TestCase) ---------------------------------------------------------------------- Traceback (most recent call last): File "./tests.py", line 143, in test_translation assert microsoft_translate(u'English', 'en', 'es') == u'Inglés' AssertionError ---------------------------------------------------------------------- Ran 6 tests in 3.981s FAILED (failures=1) Coverage Report: Name Stmts Miss Branch BrMiss Cover Missing ------------------------------------------------------------ app/__init__ 39 0 6 3 93% app/decorators 6 2 0 0 67% 5-6 app/emails 14 6 0 0 57% 9, 12-15, 21 app/forms 30 14 8 8 42% 15-16, 19-30 app/models 63 8 10 1 88% 32, 37, 47, 50, 53, 56, 78, 90 app/momentjs 12 5 0 0 58% 5, 8, 11, 14, 17 app/translate 33 24 4 3 27% 10-36, 39-56 app/views 169 124 46 46 21% 16, 20, 24-30, 34-37, 41, 45-46, 53-67, 75-81, 88-109, 113-114, 120-125, 132-143, 149-164, 169-183, 188-198, 203-205, 210-211, 218 config 22 0 0 0 100% ------------------------------------------------------------ TOTAL 388 183 74 61 47% HTML version: /home/microblog/tmp/coverage/index.html
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

レポートによると、アプリケーションの47％をテストでカバーしました。また、テストによって起動されなかった行のリストを取得しました。つまり、これらの行を調べて、どのテストがそれらをカバーできるかを考える必要があります。



また、主にモデルのテストに重点を置いているため、app / models.pyモジュールのカバレッジがかなり高い（88％）こともわかりました。現在、テストでは表現の機能を実行していないため、app / views.pyモジュールのカバレッジは比較的低くなっています（21％）。



このツールは、テストでスキップされた行に加えて、Branch列とBrMiss列の実行ブランチのカバレッジに関する情報を提供します。次のスクリプト例を検討してください。

 def f(x): if x >= 0: x = x + 1 return x f(1)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

この単純な関数のカバレッジを実行すると、100％のカバレッジが得られます。入力で1を取得すると、関数は3行すべてを実行します。しかし、0未満の引数でこの関数を実行しなかったため、異なる動作が発生する可能性があります。より複雑なケースでは、これによりエラーが発生する可能性があります。



実行ブランチのカバレッジをチェックすると、スキップした実行ブランチの数がわかります。これは、十分でない可能性があるテストについて考えるもう1つの理由です。



カバレッジモジュールは、テストで覆われスキップされた色付きの行と実行ブランチを含むソースコードを表示するHTMLレポートも生成します。



主にモデルテストに焦点を当てた戦略を継続し、テストでカバーされていないapp / models.pyファイルの部分を考慮することができます。これはHTMLレポートを使用して非常に簡単に行うことができ、そこから次のリストを取得します。

• User.make_valid_nickname（）
• User.is_authenticated（）
• User.is_active（）
• User.is_anonymous（）
• User.get_id（）
• ユーザー.__ repr __（）
• 投稿.__ repr __（）

User.make_unique_nickname（）（結果の名前が一意であり、変換



を必要としない場合、実行ブランチのみ）次のテストで最初の5つのフラグメントを結合できます。

 def test_user(self): # make valid nicknames n = User.make_valid_nickname('John_123') assert n == 'John_123' n = User.make_valid_nickname('John_[123]\n') assert n == 'John_123' # create a user u = User(nickname = 'john', email = 'john@example.com') db.session.add(u) db.session.commit() assert u.is_authenticated() == True assert u.is_active() == True assert u.is_anonymous() == False assert u.id == int(u.get_id())
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

__repr __（）関数は内部使用専用であるため、テストする必要はありません。そのため、それらを無視としてマークできます。

 def __repr__(self): # pragma: no cover return '<User %r>' % (self.nickname)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

最後に、make_unique_nickname（）のテストを作成するとき、名前の競合の処理に焦点を合わせましたが、名前が一意であり、処理を必要としない場合のテストを追加するのを忘れました。このケースもカバーするように既存のテストを拡張できます。

 def test_make_unique_nickname(self): # create a user and write it to the database u = User(nickname = 'john', email = 'john@example.com') db.session.add(u) db.session.commit() nickname = User.make_unique_nickname('susan') assert nickname == 'susan' nickname = User.make_unique_nickname('john') assert nickname != 'john' #...
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

そして、これらの簡単な修正のおかげで、models.pyモデルファイルを100％カバーしています。



とりあえず、そこで停止しましょう。おそらくいつか、カバレッジの作業を続行し、プレゼンテーション機能をテストするための良い方法を考え出すことを決定するでしょうが、今のところ、データベース作業コードをテストで完全にカバーしたことを知るだけで十分でしょう。

パフォーマンスプロファイリング

その日の次のトピックはパフォーマンスです。長いページの読み込みほど、サイトのユーザーにとってひどいものはありません。アプリケーションを可能な限り高速で実行することを確認したいので、パフォーマンスの問題を解決するために準備するためにいくつかの対策を講じる必要があります。



適用する手法は、プロファイリングと呼ばれます。。プロファイラーは、カバレッジと同じ方法で実行可能プログラムを監視しますが、実行中の行やスキップされた行を考慮する代わりに、各関数に費やされた時間を考慮します。プロファイリングの最後に、実行されたすべての機能のリストと、それぞれに費やされた時間に関する情報が表示されます。このリストは、ランタイムでソートされ、主にランタイムを最適化するために注意するコードのセクションを示します。



Pythonには適切なcProfileプロファイラーが付属しています。このプロファイラーをアプリケーションに直接埋め込むこともできますが、これを行う前に、既製のソリューションを探す価値があります。「Flaskプロファイラー」というフレーズをすばやく検索すると、Flaskで使用されるWerkzeugにはすぐに使用できるプロファイラーモジュールが付属しているため、使用できるのはそれだけであることがわかります。



Werkzeugプロファイラーをアクティブにするには、run.pyなどの別のスタートアップスクリプトを作成します。profile.pyと呼びましょう：

 #!flask/bin/python from werkzeug.contrib.profiler import ProfilerMiddleware from app import app app.config['PROFILE'] = True app.wsgi_app = ProfilerMiddleware(app.wsgi_app, restrictions = [30]) app.run(debug = True)
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

このスクリプトを使用してアプリケーションを起動すると、プロファイラーは各リクエストの最長30個の関数を表示できます（制限の詳細については、ドキュメントをご覧ください）。



アプリケーションを起動すると、各リクエストにプロファイラー情報が表示されます。以下に例を示します。

 -------------------------------------------------------------------------------- PATH: '/' 95477 function calls (89364 primitive calls) in 0.202 seconds Ordered by: internal time, call count List reduced from 1587 to 30 due to restriction <30> ncalls tottime percall cumtime percall filename:lineno(function) 1 0.061 0.061 0.061 0.061 {method 'commit' of 'sqlite3.Connection' objects} 1 0.013 0.013 0.018 0.018 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/pysqlite.py:278(dbapi) 16807 0.006 0.000 0.006 0.000 {isinstance} 5053 0.006 0.000 0.012 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:163(iter_child_nodes) 8746/8733 0.005 0.000 0.005 0.000 {getattr} 817 0.004 0.000 0.011 0.000 flask/lib/python2.7/site-packages/jinja2/lexer.py:548(tokeniter) 1 0.004 0.004 0.004 0.004 /usr/lib/python2.7/sqlite3/dbapi2.py:24(<module>) 4 0.004 0.001 0.015 0.004 {__import__} 1 0.004 0.004 0.009 0.009 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/__init__.py:7(<module>) 1808/8 0.003 0.000 0.033 0.004 flask/lib/python2.7/site-packages/jinja2/visitor.py:34(visit) 9013 0.003 0.000 0.005 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:147(iter_fields) 2822 0.003 0.000 0.003 0.000 {method 'match' of '_sre.SRE_Pattern' objects} 738 0.003 0.000 0.003 0.000 {method 'split' of 'str' objects} 1808 0.003 0.000 0.006 0.000 flask/lib/python2.7/site-packages/jinja2/visitor.py:26(get_visitor) 2862 0.003 0.000 0.003 0.000 {method 'append' of 'list' objects} 110/106 0.002 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/parser.py:544(parse_primary) 11 0.002 0.000 0.002 0.000 {posix.stat} 5 0.002 0.000 0.010 0.002 flask/lib/python2.7/site-packages/sqlalchemy/engine/base.py:1549(_execute_clauseelement) 1 0.002 0.002 0.004 0.004 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/base.py:124(<module>) 1229/36 0.002 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:183(find_all) 416/4 0.002 0.000 0.006 0.002 flask/lib/python2.7/site-packages/jinja2/visitor.py:58(generic_visit) 101/10 0.002 0.000 0.003 0.000 flask/lib/python2.7/sre_compile.py:32(_compile) 15 0.002 0.000 0.003 0.000 flask/lib/python2.7/site-packages/sqlalchemy/schema.py:1094(_make_proxy) 8 0.002 0.000 0.002 0.000 {method 'execute' of 'sqlite3.Cursor' objects} 1 0.002 0.002 0.002 0.002 flask/lib/python2.7/encodings/base64_codec.py:8(<module>) 2 0.002 0.001 0.002 0.001 {method 'close' of 'sqlite3.Connection' objects} 1 0.001 0.001 0.001 0.001 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/pysqlite.py:215(<module>) 2 0.001 0.001 0.002 0.001 flask/lib/python2.7/site-packages/wtforms/form.py:162(__call__) 980 0.001 0.000 0.001 0.000 {id} 936/127 0.001 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/visitor.py:41(generic_visit) -------------------------------------------------------------------------------- 127.0.0.1 - - [09/Mar/2013 19:35:49] "GET / HTTP/1.1" 200 -
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

このレポートの列は次のことを示しています。

• ncalls: .
• tottime: , .
• percall: tottime ncalls.
• cumtime: .
• percall: cumtime ncalls.
• filename:lineno(function): .

ここでテンプレートが関数の形でここにあることも注目に値します。これは、Jinja2がテンプレートをPythonコードにコンパイルするためです。これは、プロファイラーが遅いコードだけでなく、遅いパターンについても教えてくれることを意味します！



現時点では、パフォーマンスに関する特別な問題はありません。少なくともこの特定のリクエストでは、間違いなくそうです。 sqlite3データベースを操作する関数とJinja2テンプレートの表示に最も時間がかかることがわかります。タイトルは、このリクエストの実行に0.2秒しかかからなかったことを示していることに注意してください。個々の関数の実行時間は無視できます。



アプリケーションが成長するにつれて、プロファイラを使用して新しい追加リクエストを起動し、適切な軌道に乗っていることを確認することが役立つ場合があります。

データベースのパフォーマンス

そして、この記事の最後で、データベースのパフォーマンスの問題を見てみましょう。上記で、データベースの操作がプロファイラーレポートの一番上にあることに気づいたので、バトルサーバーでデータベースの動作が遅くなりすぎた場合（およびその場合）に警告する統合システムがあると便利です。



Flask-SQLAlchemyのドキュメントにはget_debug_queries関数が記載されており、実行時間とともに実行されたクエリのリストを返します。



これは非常に役立つ情報です。アプリケーションの対象領域は、開発およびテスト中にクエリの実行時間を測定しますが、すべてのリクエストの実行時間がわずかに増加したとしても、リクエストが長時間実行されたときに信号を送信する機能は、産業運用中にも役立ちます。



本番環境でこのプロパティを使用するには、構成ファイル（config.pyファイル）で明示的に有効にする必要があります。

 SQLALCHEMY_RECORD_QUERIES = True
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

さらに、リクエストの期間に制限を設定する必要があります。これにより、時間がかかるものはすべて「遅い」と見なされます（config.pyファイル）。

 # slow database query threshold (in seconds) DATABASE_QUERY_TIMEOUT = 0.5
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

シグナルを送信する必要性を確認するために、各リクエストの後にチェックを追加します。Flaskの使用は簡単です。after_requestハンドラー（app / views.pyファイル）を構成するだけです。

 from flask.ext.sqlalchemy import get_debug_queries from config import DATABASE_QUERY_TIMEOUT @app.after_request def after_request(response): for query in get_debug_queries(): if query.duration >= DATABASE_QUERY_TIMEOUT: app.logger.warning("SLOW QUERY: %s\nParameters: %s\nDuration: %fs\nContext: %s\n" % (query.statement, query.parameters, query.duration, query.context)) return response
      
      

        
        
        
      

    
        
        
        
      
      

        
        
        
      

    
     

したがって、0.5秒より長く実行されているすべての要求がログに記録されます。ログ内の情報には、SQL式、使用される実際のパラメーター、期間、およびこの要求が呼び出されたソースコード内の場所が含まれます。



私たちの場合のようにデータベースのサイズが小さい場合、クエリが遅くなるという問題は発生しないようですが、アプリケーションとデータベースの成長に伴い、一部のクエリは、たとえば追加のインデックスを作成することで最適化が必要であることがわかります。このログを随時確認し、リクエストの最適化が必要かどうかを確認します。

おわりに

今日、私たちはいくつかの深刻な措置を講じました。これは、信頼できるアプリケーションにとっても非常に重要です。更新されたアプリケーションコードは、



ダウンロードmicroblog-0.16.zipでダウンロードできます。



GitHubに精通している読者は、ここから新しいバージョンを入手できます。



私はこのシリーズの終わりに容赦なく近づいているようです。なぜなら、私は他に何を伝えることができるかについてのアイデアを使い果たしたからです。次の、おそらく最後の部分では、従来型とクラウドの両方でアプリケーションをデプロイするプロセスを見ていきます。

この一連の記事で見落とした問題についてご意見がありましたら、以下のコメントでお知らせください。



じゃあね！



ミゲル