Output of a python script running as unit is out of order while shells seems unnafected

13,058

Stdout is being buffered, probably because of systemd redirect

Adding sys.stdout.flush() after write or PYTHONUNBUFFERED environment will solve this problem

See also the Stack Overflow question Python output buffering.

Share:
13,058

Related videos on Youtube

DoubleThePsycho
Author by

DoubleThePsycho

Updated on September 18, 2022

Comments

  • DoubleThePsycho
    DoubleThePsycho over 1 year

    How would I get all outputs of systemd managed python2 script instantly into journal, just like it appears in terminal

    I'm on centos 7, but seems to be same on arch

    according to systemd manual, stdout and stderr should automatically go to journal

    systemd config

    #DefaultStandardOutput=journal
    #DefaultStandardError=inherit
    

    Here is my unit /usr/lib/systemd/system/tick.service

    [Unit]
    Description=Tick
    
    [Service]
    Type=simple
    ExecStart=/home/stack/tick
    

    script

    #!/usr/bin/python
    import time
    import sys
    
    print "Tick"
    sys.stderr.write('First error\n')
    time.sleep(10)
    sys.stdout.write("Tick\n")
    sys.stderr.write('Second error\n')
    time.sleep(10)
    

    and here is the output from journal, notice the time and order

    Oct 30 14:30:41 controller systemd[1]: Starting Tick...
    Oct 30 14:30:41 controller systemd[1]: Started Tick.
    Oct 30 14:30:41 controller tick[5020]: First error
    Oct 30 14:30:51 controller tick[5020]: Second error
    Oct 30 14:31:01 controller tick[5020]: Tick
    Oct 30 14:31:01 controller tick[5020]: Tick
    

    With python3 even stderr is delayed until process ends

    I tried similar c program, and seems to be same

    but this does not seem to affect bash script

    #!/bin/bash
    echo "Tick"
    echo "First error" 1>&2
    sleep 10
    echo "Tick"
    echo "Second error" 1>&2
    sleep 10
    

    journal

    Oct 30 14:41:36 controller systemd[1]: Starting Tick...
    Oct 30 14:41:36 controller systemd[1]: Started Tick.
    Oct 30 14:41:36 controller tick[5084]: Tick
    Oct 30 14:41:36 controller tick[5084]: First error
    Oct 30 14:41:46 controller tick[5084]: Tick
    Oct 30 14:41:46 controller tick[5084]: Second error
    
  • jorijnsmit
    jorijnsmit about 5 years