New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

systemd specifier for literal percent symbol (%%) no longer working in CoreOS 1068.6.0 #1459

Closed
sweber83 opened this Issue Jul 14, 2016 · 2 comments

Comments

Projects
None yet
2 participants
@sweber83

sweber83 commented Jul 14, 2016

Issue Report

Bug

CoreOS Version

NAME=CoreOS
ID=coreos
VERSION=1068.6.0
VERSION_ID=1068.6.0
BUILD_ID=2016-07-12-1826
PRETTY_NAME="CoreOS 1068.6.0 (MoreOS)"
ANSI_COLOR="1;32"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://github.com/coreos/bugs/issues"

Environment

What hardware/cloud provider/hypervisor is being used to run CoreOS?
We are running CoreOS on Digital Ocean.

Expected Behavior

In a unit file one should be able to escape systemd specifiers using two percent symbols ( %% ).
We have a unit file like this one:

[Unit]
Description=Forward Systemd Journal to logentries.com
After=systemd-journald.service

[Service]
Restart=always
RestartSec=5s
IgnoreSIGPIPE=no
ExecStart=/usr/bin/bash -c "\
  token=$(etcdctl get /logentries.com/token);\
  date=$(etcdctl get /logentries.com/$(hostname)/lastlog);\
  if [ -z \"$date\" ]; then\
    date=$(date +%F);\
  fi;\
  journalctl --since \"$date\" -o json --boot -f |\
  jq -c '{timestamp:.__REALTIME_TIMESTAMP,time:.__REALTIME_TIMESTAMP | tonumber | ( . / 1000000 ) | strftime(\"%Y-%%m-%dT%%H:%M:%SZ\"),host:._HOSTNAME,unit:._SYSTEMD_UNIT,message_raw: .MESSAGE, message_parsed: ( try ( .MESSAGE | fromjson ) catch false)} | {timestamp:.timestamp, time:.time, host:.host, unit:.unit, message:(if .message_parsed == false then .message_raw else .message_parsed end)}' |\
  awk -v token=\"$token\" '{ print token,$0; fflush(); }' |\
  ncat --ssl api.logentries.com 20000;"

ExecStop=/usr/bin/bash -c "etcdctl set /logentries.com/$(hostname)/lastlog \"$(date +'%F %%H:%M:%S')\""

[X-Fleet]
Global=true

On ExecStop the date and and time should be written to etcd.

Actual Behavior

Instead of the hour we get the hostname written to etcd.

Reproduction Steps

  1. Set your logentries.com token with etcdctl set /logentries.com/token $YOUR_TOKEN
  2. Start and stop the unit then inspect etcd with etcdctl get /logentries.com/($hostname)/lastlog.

Other Information

This doesn't happen on the last stable release 1010.6.0.
I'm not really sure if this is a CoreOS or systemd issue but the systemd documentation has not changed:
https://www.freedesktop.org/software/systemd/man/systemd.unit.html

@crawford

This comment has been minimized.

Member

crawford commented Jul 14, 2016

$ systemctl --version
systemd 229
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS -ACL +XZ -LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD -IDN

$ cat /etc/systemd/system/test.service
[Service]
Type=oneshot
ExecStart=/usr/bin/echo Hello
ExecStart=/usr/bin/echo %%
ExecStart=/usr/bin/echo Goodbye

$ sudo systemctl start test

$ journalctl -u test
Jul 14 16:51:16 ip-172-31-24-65.us-west-2.compute.internal systemd[1]: Starting test.service...
Jul 14 16:51:16 ip-172-31-24-65.us-west-2.compute.internal echo[911]: Hello
Jul 14 16:51:16 ip-172-31-24-65.us-west-2.compute.internal echo[919]: Goodbye
Jul 14 16:51:16 ip-172-31-24-65.us-west-2.compute.internal systemd[1]: Started test.service.
$ systemctl --version
systemd 225
-PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS -ACL +XZ -LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD -IDN

$ cat /etc/systemd/system/test.service
[Service]
Type=oneshot
ExecStart=/usr/bin/echo Hello
ExecStart=/usr/bin/echo %%
ExecStart=/usr/bin/echo Goodbye

$ sudo systemctl start test

$ journalctl -u test
-- Logs begin at Thu 2016-07-14 16:47:13 UTC, end at Thu 2016-07-14 16:52:22 UTC. --
Jul 14 16:52:22 ip-172-31-16-69.us-west-2.compute.internal systemd[1]: Starting test.service...
Jul 14 16:52:22 ip-172-31-16-69.us-west-2.compute.internal echo[888]: Hello
Jul 14 16:52:22 ip-172-31-16-69.us-west-2.compute.internal echo[890]: %
Jul 14 16:52:22 ip-172-31-16-69.us-west-2.compute.internal echo[893]: Goodbye
Jul 14 16:52:22 ip-172-31-16-69.us-west-2.compute.internal systemd[1]: Started test.service.
@crawford

This comment has been minimized.

Member

crawford commented Jul 14, 2016

Looks like this was a systemd regression systemd/systemd#2637. We'll backport the fix and continue rolling out the update.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment