I have a systemd service with gunicorn. I have a print statement in a function.Problem is that, journalctl does not show the print output when i call the function but it shows the output after refresing the systemd service unit. Should it behave like this? What could be the solution for this?
Journalctl only refreshing after restarting systemd service
daemongunicornjournalctlloggingsystemd
Related Solutions
Update 1: The verbose option will list in long format and so includes the UNIT:
[root@localhost]# journalctl --unit newnginx -o verbose
-- Logs begin at Sun 2015-04-05 10:36:30 BST, end at Mon 2015-06-01 08:17:58 BST. --
Sun 2015-05-31 10:27:38.344553 BST [s=4cc44a9cf9344c948fd4716fe024439e;i=3198;b=be3381af5b1d4743a4ccc1e346eab405;m=1548bfaf08;t=5175d51fadf41;x=eb6bb8ee2b2be47e]
PRIORITY=6
_UID=0
_GID=0
_BOOT_ID=be3381af5b1d4743a4ccc1e346eab405
_MACHINE_ID=9619293167aa4f76b45b745e9f4e8935
_HOSTNAME=localhost.localdomain
_CAP_EFFECTIVE=1fffffffff
_SYSTEMD_CGROUP=/
SYSLOG_FACILITY=3
SYSLOG_IDENTIFIER=systemd
_TRANSPORT=journal
_PID=1
_COMM=systemd
_EXE=/usr/lib/systemd/systemd
_CMDLINE=/usr/lib/systemd/systemd --system --deserialize 21
_SELINUX_CONTEXT=system_u:system_r:init_t:s0
CODE_FILE=src/core/unit.c
CODE_LINE=1115
CODE_FUNCTION=unit_status_log_starting_stopping_reloading
MESSAGE_ID=7d4958e842da4a758f6c1cdc7b36dcc5
MESSAGE=Starting nginx - high performance web server...
UNIT=newnginx.service
_SOURCE_REALTIME_TIMESTAMP=1433064458344553
Sun 2015-05-31 10:27:38.354983 BST [s=4cc44a9cf9344c948fd4716fe024439e;i=3199;b=be3381af5b1d4743a4ccc1e346eab405;m=1548bfd0ee;t=5175d51fb0127;x=bc50f03db39f8d09]
PRIORITY=6
_UID=0
_GID=0
_BOOT_ID=be3381af5b1d4743a4ccc1e346eab405
_MACHINE_ID=9619293167aa4f76b45b745e9f4e8935
_HOSTNAME=localhost.localdomain
_CAP_EFFECTIVE=1fffffffff
_SYSTEMD_CGROUP=/
SYSLOG_FACILITY=3
_SELINUX_CONTEXT=system_u:system_r:init_t:s0
_TRANSPORT=stdout
Update 2: Python script to print wanted entries:
from systemd import journal
j = journal.Reader()
j.this_boot()
j.add_match(_SYSTEMD_UNIT="newnginx.service")
for entry in j:
print('{} {}'.format(entry['_SYSTEMD_UNIT'], entry['MESSAGE']))
Have a look at this example from nginx:
[root@localhost tmp]# journalctl --unit nginx
-- Logs begin at Sun 2015-04-05 10:36:30 BST, end at Sun 2015-05-31 11:12:29 BST. --
May 31 10:20:41 localhost.localdomain systemd[1]: Starting nginx - high performance web server...
May 31 10:20:41 localhost.localdomain nginx[111169]: nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
May 31 10:20:41 localhost.localdomain nginx[111169]: nginx: configuration file /etc/nginx/nginx.conf test is successful
May 31 10:20:41 localhost.localdomain systemd[1]: Failed to read PID from file /run/nginx.pid: Invalid argument
May 31 10:20:41 localhost.localdomain systemd[1]: Started nginx - high performance web server.
May 31 10:27:05 localhost.localdomain systemd[1]: Stopping nginx - high performance web server...
May 31 10:27:05 localhost.localdomain systemd[1]: Stopped nginx - high performance web server.
May 31 10:58:36 localhost.localdomain systemd[1]: Stopped nginx - high performance web server.
May 31 11:12:29 localhost.localdomain systemd[1]: Starting nginx - high performance web server...
May 31 11:12:29 localhost.localdomain nginx[112202]: nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
May 31 11:12:29 localhost.localdomain nginx[112202]: nginx: configuration file /etc/nginx/nginx.conf test is successful
May 31 11:12:29 localhost.localdomain systemd[1]: Failed to read PID from file /run/nginx.pid: Invalid argument
May 31 11:12:29 localhost.localdomain systemd[1]: Started nginx - high performance web server.
Somebody comes along and does a ps to find and kill nginx:
[root@localhost tmp]# ps -ef | grep nginx
root 112205 1 0 11:12 ? 00:00:00 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf
nginx 112207 112205 0 11:12 ? 00:00:00 nginx: worker process
root 112212 111775 0 11:12 pts/4 00:00:00 grep --color=auto nginx
[root@localhost tmp]# kill -9 112205
The journal now contains:
[root@localhost tmp]# journalctl --unit nginx
-- Logs begin at Sun 2015-04-05 10:36:30 BST, end at Sun 2015-05-31 11:12:57 BST. --
May 31 10:20:41 localhost.localdomain systemd[1]: Starting nginx - high performance web server...
May 31 10:20:41 localhost.localdomain nginx[111169]: nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
May 31 10:20:41 localhost.localdomain nginx[111169]: nginx: configuration file /etc/nginx/nginx.conf test is successful
May 31 10:20:41 localhost.localdomain systemd[1]: Failed to read PID from file /run/nginx.pid: Invalid argument
May 31 10:20:41 localhost.localdomain systemd[1]: Started nginx - high performance web server.
May 31 10:27:05 localhost.localdomain systemd[1]: Stopping nginx - high performance web server...
May 31 10:27:05 localhost.localdomain systemd[1]: Stopped nginx - high performance web server.
May 31 10:58:36 localhost.localdomain systemd[1]: Stopped nginx - high performance web server.
May 31 11:12:29 localhost.localdomain systemd[1]: Starting nginx - high performance web server...
May 31 11:12:29 localhost.localdomain nginx[112202]: nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
May 31 11:12:29 localhost.localdomain nginx[112202]: nginx: configuration file /etc/nginx/nginx.conf test is successful
May 31 11:12:29 localhost.localdomain systemd[1]: Failed to read PID from file /run/nginx.pid: Invalid argument
May 31 11:12:29 localhost.localdomain systemd[1]: Started nginx - high performance web server.
May 31 11:12:57 localhost.localdomain systemd[1]: nginx.service: main process exited, code=killed, status=9/KILL
May 31 11:12:57 localhost.localdomain kill[112215]: Usage:
May 31 11:12:57 localhost.localdomain kill[112215]: kill [options] <pid|name> [...]
May 31 11:12:57 localhost.localdomain kill[112215]: Options:
May 31 11:12:57 localhost.localdomain kill[112215]: -a, --all do not restrict the name-to-pid conversion to processes
May 31 11:12:57 localhost.localdomain kill[112215]: with the same uid as the present process
May 31 11:12:57 localhost.localdomain kill[112215]: -s, --signal <sig> send specified signal
May 31 11:12:57 localhost.localdomain kill[112215]: -q, --queue <sig> use sigqueue(2) rather than kill(2)
May 31 11:12:57 localhost.localdomain kill[112215]: -p, --pid print pids without signaling them
May 31 11:12:57 localhost.localdomain kill[112215]: -l, --list [=<signal>] list signal names, or convert one to a name
May 31 11:12:57 localhost.localdomain kill[112215]: -L, --table list signal names and numbers
May 31 11:12:57 localhost.localdomain kill[112215]: -h, --help display this help and exit
May 31 11:12:57 localhost.localdomain kill[112215]: -V, --version output version information and exit
May 31 11:12:57 localhost.localdomain kill[112215]: For more details see kill(1).
May 31 11:12:57 localhost.localdomain systemd[1]: nginx.service: control process exited, code=exited status=1
May 31 11:12:57 localhost.localdomain systemd[1]: Unit nginx.service entered failed state.
Observe how the column where you are seeing only php contains the name of the process that is acting upon the nginx systemd unit, systemd, nginx, kill are all listed there. Does that help to explain.
The unit name is given to it by the filename. On a Centos 7 I did:
(cfs)[root@localhost system]# pwd
/usr/lib/systemd/system
^?(cfs)[root@localhost system]# cp nginx.service newnginx.service
Stop the original nxginx:
(cfs)[root@localhost system]# service nginx stop
Redirecting to /bin/systemctl stop nginx.service
(cfs)[root@localhost system]# service h^Cinx stop
Look at and start "newnginx":
(cfs)[root@localhost system]# service newnginx status
Redirecting to /bin/systemctl status newnginx.service
newnginx.service - nginx - high performance web server
Loaded: loaded (/usr/lib/systemd/system/newnginx.service; disabled)
Active: inactive (dead)
Docs: http://nginx.org/en/docs/
(cfs)[root@localhost system]# service newnginx start
Redirecting to /bin/systemctl start newnginx.service
Journalctl now lists the newnginx unit:
(cfs)[root@localhost system]# journalctl --unit newnginx
-- Logs begin at Sun 2015-04-05 10:36:30 BST, end at Sun 2015-05-31 10:27:38 BST. --
May 31 10:27:38 localhost.localdomain systemd[1]: Starting nginx - high performance web server...
May 31 10:27:38 localhost.localdomain nginx[111311]: nginx: the configuration file /etc/nginx/nginx.conf syntax is o
May 31 10:27:38 localhost.localdomain nginx[111311]: nginx: configuration file /etc/nginx/nginx.conf test is success
May 31 10:27:38 localhost.localdomain systemd[1]: Failed to read PID from file /run/nginx.pid: Invalid argument
May 31 10:27:38 localhost.localdomain systemd[1]: Started nginx - high performance web server.
There are now two nginx systemd units:
# systemctl list-unit-files --all | grep nginx
newnginx.service disabled
nginx.service disabled
To have a service restart 3 times at 90 second intervals include the following lines in your systemd service file:
[Unit]
StartLimitIntervalSec=400
StartLimitBurst=3
[Service]
Restart=always
RestartSec=90
Before systemd-230 it was called just StartLimitInterval:
[Unit]
StartLimitInterval=400
StartLimitBurst=3
[Service]
Restart=always
RestartSec=90
This worked worked for me for a service that runs a script using Type=idle. Note that StartLimitIntervalSec must be greater than RestartSec * StartLimitBurst otherwise the service will be restarted indefinitely.
It took me some time with a lot of trial and error to work out how systemd uses these options, which suggests that systemd isn't as well documented as one would hope. These options effectively provide the retry cycle time and maximum retries that I was looking for.
References: https://manpages.debian.org/testing/systemd/systemd.unit.5.en.html for Unit section https://manpages.debian.org/testing/systemd/systemd.exec.5.en.html for Service section
Related Topic
- Systemd ignores return code while starting service
- Systemd does not restart service, although Restart=always
- Ubuntu – How do view older journalctl logs (after a rotation maybe?)
- Linux – Systemd python service buffers journalctl output even with -u
- Linux – Journalctl Not Synced with Systemctl Status / Journalctl Not Updating
Best Answer
This is due to Python's default behavior to buffer stdin, stdout and stderr. For a systemd file, include the following line within the same block as
ExecStart=/path/to/gunicorn.Environment=PYTHONUNBUFFERED=1Refer to https://stackoverflow.com/questions/107705/disable-output-buffering for alternative ways to disable it.