スクリプトのお勉強

Pythonでコマンド非同期起動

投稿日:

はじめに

小ネタです。

作成するプログラムの要件で、コマンドを起動して、そのコマンドが「継続」している/していないことを確認する、という要件があります。

具体的には、pingコマンドを普通に打つと、コマンド自体は永遠に終わらず、
標準出力に延々と出続けます。

人が見るには標準出力にずっと出力し続けるのはいいですが、
プログラム的に処理する場合は、通常3回ぐらいで終わらせるものです。

が、、まぁ要件としてあるとしましょう。

そういう場合にPythonで書いてみました。

sarge

というライブラリがあります。

https://sarge.readthedocs.io/en/latest/overview.html

pythonに元々あるSubprocessを、簡単に使用するためのライブラリです。

特に、Subprocessを素で使うと面倒な処理に向いているようです。なので使ってみました。
ちなみに他も使ってみたのですが、むしろSubprocessより面倒だったという理由もあります。

環境

動作した環境は以下のとおりです。

  • python 3.8.5
  • sarge 0.1.6
$ pip install sarge

サンプルプログラム

以下がサンプルプログラムです。sargeのチュートリアルをほぼ丸パクリしました。

import sys
import threading
from multiprocessing import Value
import time
import logging

from sarge import capture_stdout, run, Capture

logger = logging.getLogger(__name__)


def progress(capture, d):

    while True:
        s = capture.readline(timeout=10.0)
        if not s:
            # timeoutのときにここに入る
            logger.debug('No more data, breaking out')
            with d.get_lock():
                d.value = 100
            break
        logger.debug(f'cmd output {s}')
        with d.get_lock():
            d.value += 1
        if d.value >= 5:
            logger.debug(f'progress exited at {d.value}')
            break

def main():
    logger.debug(f'main start')

    cmd = 'ping 192.168.132.128'
    # cmd = 'ping 10.0.0.1' # エラーで出力しない場合はこちらを有効にする。
    p = capture_stdout(cmd, async_=True)
    d = Value('i')
    d.value = 0

    time.sleep(0.01)
    t = threading.Thread(target=progress, args=(p.stdout, d))
    t.start()

    while(p.returncodes[0] is None):
        p.commands[0].poll()
        time.sleep(0.05)
        if d.value >= 5:
            break
    t.join()
    logger.debug(f'main exited')

if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG, filename='test_progress.log',
                        filemode='w', format='%(asctime)s %(threadName)-10s %(name)-15s %(lineno)4d %(message)s')
    sys.exit(main())

プログラムの内容は見てのとおりですがサンプルと違うのは

  • スレッド起動した関数と、メイン関数の間でd変数を用意
  • スレッド内でd変数を変更
  • main関数でチェック
    • 5以上ならループを終了

です。pingが延々と帰ってこない場合も制御できているかを確認したかったので追加しました。

ログ

どのように動作しているか、細かく見るためにログを追加し、出力してみました。実際に動かしてみないとわからない人でして。。

以下は、ping 192.168.132.128(実在するIPアドレス)に出力した場合です。

pingコマンドの出力を取り出せているのが分かります。

2021-06-03 00:12:09,129 MainThread __main__          28 main start
2021-06-03 00:12:09,129 MainThread sarge.parse      854 starting parse of 'ping 192.168.132.128'
2021-06-03 00:12:09,129 MainThread sarge.parse      996 returning CommandNode(command=['ping'] redirects={})
2021-06-03 00:12:09,129 MainThread sarge.parse      996 returning CommandNode(command=['192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 MainThread sarge.parse      939 returning CommandNode(command=['ping', '192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 MainThread sarge.parse      922 returning CommandNode(command=['ping', '192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 MainThread sarge.parse      893 returning CommandNode(command=['ping', '192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 MainThread sarge.parse      877 returning CommandNode(command=['ping', '192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 MainThread sarge           1067 thread Thread-1 started to run node: CommandNode(command=['ping', '192.168.132.128'] redirects={})
2021-06-03 00:12:09,130 Thread-1   sarge           1335 started: CommandNode(command=['ping', '192.168.132.128'] redirects={}), None, True
2021-06-03 00:12:09,130 Thread-1   sarge            629 Command('ping 192.168.132.128') created
2021-06-03 00:12:09,130 Thread-1   sarge            665 About to call Popen: ['ping', '192.168.132.128'], {'stdout': -1, 'stderr': None, 'stdin': None}
2021-06-03 00:12:09,149 Thread-1   sarge            674 Popen: Command('ping 192.168.132.128'), {'stdout': -1, 'stderr': None, 'stdin': None} -> {'_waitpid_lock': <unlocked _thread.lock object at 0x7f05a8eea120>, '_input': None, '_communication_started': False, 'args': ['ping', '192.168.132.128'], 'stdin': None, 'stdout': <_io.BufferedReader name=4>, 'stderr': None, 'pid': 5290, 'returncode': None, 'encoding': None, 'errors': None, 'text_mode': None, '_sigint_wait_secs': 0.25, '_closed_child_pipe_fds': True, '_child_created': True}
2021-06-03 00:12:09,150 Thread-1   sarge            215 Created thread Thread-2 as reader for Capture-1
2021-06-03 00:12:09,151 Thread-2   sarge            237 Capture-1: reader thread about to read line
2021-06-03 00:12:09,151 Thread-1   sarge            219 Capture-1: reader thread kicked off, waiting start
2021-06-03 00:12:09,151 Thread-1   sarge            221 Capture-1: reader thread now started
2021-06-03 00:12:09,151 Thread-1   sarge            697 returning Command('ping 192.168.132.128') (Popen(returncode=None stdin=None stdout=<_io.BufferedReader name=4> stderr=None))
2021-06-03 00:12:09,170 Thread-2   sarge            246 queued chunk of length 68 to <queue.Queue object at 0x7f05a97caf70>: b'PING 192.168.132.128 (192.168.'
2021-06-03 00:12:09,170 Thread-2   sarge            246 queued chunk of length 86 to <queue.Queue object at 0x7f05a97caf70>: b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 1'
2021-06-03 00:12:09,182 Thread-3   __main__          20 cmd output b'PING 192.168.132.128 (192.168.132.128) 56(84) \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe3\x81\xae\xe3\x83\x87\xe3\x83\xbc\xe3\x82\xbf\n'
2021-06-03 00:12:09,182 Thread-3   __main__          20 cmd output b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 192.168.132.128: icmp_seq=1 ttl=64 \xe6\x99\x82\xe9\x96\x93=0.023\xe3\x83\x9f\xe3\x83\xaa\xe7\xa7\x92\n'
2021-06-03 00:12:10,159 Thread-2   sarge            246 queued chunk of length 86 to <queue.Queue object at 0x7f05a97caf70>: b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 1'
2021-06-03 00:12:10,159 Thread-3   __main__          20 cmd output b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 192.168.132.128: icmp_seq=2 ttl=64 \xe6\x99\x82\xe9\x96\x93=0.030\xe3\x83\x9f\xe3\x83\xaa\xe7\xa7\x92\n'
2021-06-03 00:12:11,183 Thread-2   sarge            246 queued chunk of length 86 to <queue.Queue object at 0x7f05a97caf70>: b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 1'
2021-06-03 00:12:11,184 Thread-3   __main__          20 cmd output b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 192.168.132.128: icmp_seq=3 ttl=64 \xe6\x99\x82\xe9\x96\x93=0.061\xe3\x83\x9f\xe3\x83\xaa\xe7\xa7\x92\n'
2021-06-03 00:12:12,208 Thread-2   sarge            246 queued chunk of length 86 to <queue.Queue object at 0x7f05a97caf70>: b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 1'
2021-06-03 00:12:12,208 Thread-3   __main__          20 cmd output b'64 \xe3\x83\x90\xe3\x82\xa4\xe3\x83\x88\xe5\xbf\x9c\xe7\xad\x94 \xe9\x80\x81\xe4\xbf\xa1\xe5\x85\x83 192.168.132.128: icmp_seq=4 ttl=64 \xe6\x99\x82\xe9\x96\x93=0.025\xe3\x83\x9f\xe3\x83\xaa\xe7\xa7\x92\n'
2021-06-03 00:12:12,208 Thread-3   __main__          24 progress exited at 5
2021-06-03 00:12:12,222 MainThread __main__          46 main exited

ping失敗時ログ

ping 10.0.0.1(存在しないIPアドレス)のコマンドは以下のようになります。
“No more data, breaking out”が出た後、main関数を抜けているのが分かります。

2021-06-03 00:20:04,075 MainThread __main__          30 main start
2021-06-03 00:20:04,075 MainThread sarge.parse      854 starting parse of 'ping 10.0.0.1'
2021-06-03 00:20:04,075 MainThread sarge.parse      996 returning CommandNode(command=['ping'] redirects={})
2021-06-03 00:20:04,075 MainThread sarge.parse      996 returning CommandNode(command=['10.0.0.1'] redirects={})
2021-06-03 00:20:04,076 MainThread sarge.parse      939 returning CommandNode(command=['ping', '10.0.0.1'] redirects={})
2021-06-03 00:20:04,076 MainThread sarge.parse      922 returning CommandNode(command=['ping', '10.0.0.1'] redirects={})
2021-06-03 00:20:04,076 MainThread sarge.parse      893 returning CommandNode(command=['ping', '10.0.0.1'] redirects={})
2021-06-03 00:20:04,076 MainThread sarge.parse      877 returning CommandNode(command=['ping', '10.0.0.1'] redirects={})
2021-06-03 00:20:04,076 MainThread sarge           1067 thread Thread-1 started to run node: CommandNode(command=['ping', '10.0.0.1'] redirects={})
2021-06-03 00:20:04,077 Thread-1   sarge           1335 started: CommandNode(command=['ping', '10.0.0.1'] redirects={}), None, True
2021-06-03 00:20:04,077 Thread-1   sarge            629 Command('ping 10.0.0.1') created
2021-06-03 00:20:04,077 Thread-1   sarge            665 About to call Popen: ['ping', '10.0.0.1'], {'stdout': -1, 'stderr': None, 'stdin': None}
2021-06-03 00:20:04,082 Thread-1   sarge            674 Popen: Command('ping 10.0.0.1'), {'stdout': -1, 'stderr': None, 'stdin': None} -> {'_waitpid_lock': <unlocked _thread.lock object at 0x7f35c2e122a0>, '_input': None, '_communication_started': False, 'args': ['ping', '10.0.0.1'], 'stdin': None, 'stdout': <_io.BufferedReader name=4>, 'stderr': None, 'pid': 5408, 'returncode': None, 'encoding': None, 'errors': None, 'text_mode': None, '_sigint_wait_secs': 0.25, '_closed_child_pipe_fds': True, '_child_created': True}
2021-06-03 00:20:04,082 Thread-1   sarge            215 Created thread Thread-2 as reader for Capture-1
2021-06-03 00:20:04,086 Thread-2   sarge            237 Capture-1: reader thread about to read line
2021-06-03 00:20:04,086 Thread-1   sarge            219 Capture-1: reader thread kicked off, waiting start
2021-06-03 00:20:04,086 Thread-1   sarge            221 Capture-1: reader thread now started
2021-06-03 00:20:04,086 Thread-1   sarge            697 returning Command('ping 10.0.0.1') (Popen(returncode=None stdin=None stdout=<_io.BufferedReader name=4> stderr=None))
2021-06-03 00:20:24,103 Thread-3   __main__          18 No more data, breaking out
2021-06-03 00:20:24,141 MainThread __main__          48 main exited

終わりに

ログを出してみて、どんな感じで動作しているかを確認することができました。ある程度は理解できたと思います。

参考

  • https://sarge.readthedocs.io/en/latest/tutorial.html
    サンプルプログラムの参考にした

-スクリプトのお勉強

執筆者:

関連記事

顔画像のモザイク方法(python + OpenCV + face_recognition)

Python3での顔画像モザイク方法 python3での顔画像モザイクの方法を調べてみました。 仕事とは関係なく、単なる趣味だったりしますが。。 この内容で、Djangoと統合する予定です。 Open …

Mojolicious XML-RPC Pluginの開発(2)

はじめに 「Mojolicious XML-RPC Pluginの開発」のその2です。 本内容では、前回の内容を踏まえ、XML-RPC実装を、Mojoliciousのプラグイン機能を使用して実装しよう …

Nuxt.jsのFormで入力/確認/完了フォームを作成してみた(その1)

背景 今回は、Webアプリケーションの、フロントエンド系のお話です。ほとんどの場合、バックエンドなのですが、時々フロントエンドもするんですよね。。 私の派遣先では、入力フォームを以下のように分ける要望 …

神奈川県横浜市神奈川区のワクチン接種地図作った

作ってみた。東白楽駅を真ん中にしてみました。なんとなく真ん中な感じなので。 データ元 以下のテキストデータからゴニョゴニョしてます。 https://www.city.yokohama.lg.jp/k …

言語別ログイン機能パスワード保存処理方針

ちょっと前に、ログイン機能を作成した際、パスワードを暗号化するか、という議論を目にしたことがありました。 昔だと、「パスワードを暗号化しない」方で実装していましたが、最近はセキュリティが当たり前になっ …

google オプトアウト Click here to opt-out.