journald ログの順序がシェル出力の順序と異なるのはなぜですか?

journald ログの順序がシェル出力の順序と異なるのはなぜですか?

私は次の Python スクリプトを実行しています./test.py:

#!/usr/bin/python3
import snowboydecoder
import sys
import signal
import speech_recognition as sr
import cec
import os

"""
This demo file shows you how to use the new_message_callback to interact with
the recorded audio after a keyword is spoken. It uses the speech recognition
library in order to convert the recorded audio into text.

Information on installing the speech recognition library can be found at:
https://pypi.python.org/pypi/SpeechRecognition/
"""

interrupted = False

def audioRecorderCallback(fname):
    print("converting audio to text")
    r = sr.Recognizer()

    f = open("key.json")
    key = f.read()
    f.close()

    with sr.AudioFile(fname) as source:
        audio = r.record(source)  # read the entire audio file
    # recognize speech using Google Speech Recognition
    try:
        print(r.recognize_google_cloud(audio, key, "hu-HU"))
    except sr.UnknownValueError:
        print("Google Speech Recognition could not understand audio")
    except sr.RequestError as e:
        print("Could not request results from Google Speech Recognition service; {0}".format(e))

    os.remove(fname)



def detectedCallback():
  print('recording audio...', end='', flush=True)

def signal_handler(signal, frame):
    global interrupted
    interrupted = True


def interrupt_callback():
    global interrupted
    return interrupted

if len(sys.argv) == 1:
    print("Unspecified model, defaulting to snowboy.umdl")
    print("Usage: test.py your.model")
    model = "/mnt/samba/shared/snowboy/snowboy.umdl"
else:
    model = sys.argv[1]

cec.init()
cec_devices = cec.list_devices()

# capture SIGINT signal, e.g., Ctrl+C
signal.signal(signal.SIGINT, signal_handler)

detector = snowboydecoder.HotwordDetector(model, sensitivity=0.7, audio_gain=1)
print('Listening... Press Ctrl+C to exit')

# main loop
detector.start(detected_callback=detectedCallback,
               audio_recorder_callback=audioRecorderCallback,
               silent_count_threshold=4,
               recording_timeout=10,
               interrupt_check=interrupt_callback,
               sleep_time=0.01)

detector.terminate()

出力はほぼ予想通りで、次のような項目があります [[[は私のコメントです]]]:

Unspecified model, defaulting to snowboy.umdl
Usage: test.py your.model
Listening... Press Ctrl+C to exit
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 924
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 924
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 924
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.front.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM front
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround21
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround40.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround40
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround41
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround50
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround51.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround51
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.surround71.0:CARD=0'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM surround71
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM iec958
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'cards.bcm2835_hdmi.pcm.iec958.0:CARD=0,AES0=4,AES1=130,AES2=0,AES3=2'
ALSA lib conf.c:4568:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5047:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM spdif
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
ALSA lib pcm.c:2565:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
Cannot connect to server socket err = No such file or directory
Cannot connect to server request channel
jack server is not running or cannot be started
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
[[[Program waits here for verbal input]]]
INFO:snowboy:Keyword 1 detected at time: 2020-12-02 12:09:45
recording audio...converting audio to text
[[[Likely unrelated googleapi timeout error]]]

ただし、スクリプトを systemd スクリプトに変換すると、次のようになります/etc/systemd/system/test.service

[Unit]
Description=Super user test service
After=sound.target network.target
Requires=sound.target
Wants=network.target
StartLimitIntervalSec=0

[Service]
Type=simple
Restart=always
RestartSec=1
User=pi
WorkingDirectory=/home/pi/snowboy
ExecStart=/mnt/samba/shared/snowboy/test.py

[Install]
WantedBy=multi-user.target

不可解なことに、出力結果が異なりますjournalctl -u test.service -f

Dec 02 12:00:59 ARPI systemd[1]: Started Super user test service.
Dec 02 12:01:08 ARPI test.py[25846]: Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 924
[[[Identical ALSA lib messages]]]
Dec 02 12:01:08 ARPI test.py[25846]: JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
[[[Program waits here for verbal input]]]
Dec 02 12:04:47 ARPI test.py[25846]: INFO:snowboy:Keyword 1 detected at time: 2020-12-02 12:04:47
Dec 02 12:04:47 ARPI test.py[25846]: Unspecified model, defaulting to snowboy.umdl
Dec 02 12:04:47 ARPI test.py[25846]: Usage: test.py your.model
Dec 02 12:04:47 ARPI test.py[25846]: Listening... Press Ctrl+C to exit
Dec 02 12:05:49 ARPI test.py[25846]: recording audio...WARNING:googleapiclient.http:Sleeping 1.39 seconds before retry 1 of 1 for request: GET https://www.googleapis.com/discovery/v1/apis/speech/v1/rest, after timed out
Dec 02 12:06:51 ARPI test.py[25846]: converting audio to text
[[[Likely unrelated googleapi timeout error]]]
Dec 02 12:06:51 ARPI systemd[1]: test.service: Main process exited, code=exited, status=1/FAILURE
Dec 02 12:06:51 ARPI systemd[1]: test.service: Failed with result 'exit-code'.
Dec 02 12:06:52 ARPI systemd[1]: test.service: Service RestartSec=1s expired, scheduling restart.
Dec 02 12:06:52 ARPI systemd[1]: test.service: Scheduled restart job, restart counter is at 2.
Dec 02 12:06:52 ARPI systemd[1]: Stopped Super user test service.

サービスが入力を待機している間に試してみましたsudo journalctl --syncが、予想していた行 (Unspecified model、listening、などなど) がジャーナルに表示されませんでした。

答え1

私は見つけたこの記事についてjournald、バッファリングに問題がある可能性があると指摘しました。

それは私をこのPython固有のUnix StackExchangeの質問解決策とともに。

systemd サービス ファイルにEnvironment="PYTHONUNBUFFERED=1"以下を追加すると、問題は解決しました。[Service]

関連情報