¿Por qué los registros diarios están en un orden diferente al de la salida del shell?

¿Por qué los registros diarios están en un orden diferente al de la salida del shell?

Estoy ejecutando el siguiente script de Python con ./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()

El resultado es en gran medida el que esperaba; elementos que se ven así [[[es mi comentario]]]:

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]]]

Sin embargo, cuando convierto el script en un script systemd con /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

Obtengo un resultado inexplicablemente diferente dejournalctl -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.

Lo intenté sudo journalctl --syncmientras el servicio esperaba información, pero las líneas que esperaba (modelo no especificado, escucha, yada-yada...) no aparecieron en el diario.

Respuesta1

He encontradoeste artículoabout journald, que señaló que podría haber problemas con el almacenamiento en búfer.

Me lleva aesta pregunta específica de Python sobre Unix StackExchangecon una solución.

Agregar Environment="PYTHONUNBUFFERED=1"debajo [Service]en el archivo de servicio systemd resolvió el problema.

información relacionada