no logs in the journal when running with rkt #5779

f0 · 2016-06-27T16:46:46Z

Hi,

if i run etcd with rkt (the official provided aci) and systemd, i do not see the etcd logs.
Is there a way to get the logs into the journal?

regards f0

gyuho · 2016-06-27T16:48:23Z

Seems related to #5449.

f0 · 2016-06-27T16:50:21Z

@gyuho maybe, but i see no logs on stdout and no logs in the journal... etcd version is 2.3.6

gyuho · 2016-06-27T16:51:14Z

You should be able to get logs from journald... Can you give us a way to reproduce? Like how you run etcd with rkt? I will take a look.

f0 · 2016-06-27T16:57:13Z

systemd file

https://gist.github.com/f0/79460de6b451db57287bc4eb7ed9956a
journal output
https://gist.github.com/f0/0d7410e72cc95953bf3c612e1bb289a4

rkt version

rkt Version: 1.7.0
appc Version: 0.8.4
Go Version: go1.6.1
Go OS/Arch: linux/amd64
Features: -TPM

f0 · 2016-06-27T17:03:13Z

also testet with the latest rkt version (1.9.1) no change

gyuho · 2016-06-27T23:45:50Z

@f0 Think with newer rkt, I see the same problem.

# RKT_VERSION=1.9.1
sudo ./rkt trust --prefix coreos.com/etcd
sudo ./rkt --debug run --volume data-dir,kind=host,source=/tmp --mds-register=false coreos.com/etcd:v3.0.0-beta.0

sudo ./rkt trust --prefix coreos.com/etcd
sudo ./rkt --debug run --stage1-name=coreos.com/rkt/stage1-coreos:1.3.0 coreos.com/etcd:v3.0.0-beta.0

<<COMMENT
image: using image from local store for image name coreos.com/rkt/stage1-coreos:1.3.0
image: using image from local store for image name coreos.com/etcd:v3.0.0-beta.0
stage0: Preparing stage1
stage0: Writing image manifest
stage0: Loading image sha512-2bdba926abef05d7397e4977a9acb33ddddd9b60d9a168186763ac1b12e5293b
stage0: Writing image manifest
stage0: Writing pod manifest
run: group "rkt" not found, will use default gid when rendering images
stage0: Setting up stage1
stage0: Wrote filesystem to /var/lib/rkt/pods/run/8f1296c4-38ac-46f8-a0ed-7abc0230b752
stage0: Pivoting to filesystem /var/lib/rkt/pods/run/8f1296c4-38ac-46f8-a0ed-7abc0230b752
stage0: Execing /init
networking: loading networks from /etc/rkt/net.d
networking: loading network default with type ptp
stage1: warning: error setting journal ACLs, you'll need root to read the pod journal
  └─group "rkt" not found
stage1: warning: no volume specified for mount point "data-dir", implicitly creating an "empty" volume. This volume will be removed when the pod is garbage-collected.
stage1: creating an empty volume folder for sharing: "sharedVolumes/etcd-data-dir"
Spawning container rkt-8f1296c4-38ac-46f8-a0ed-7abc0230b752 on /var/lib/rkt/pods/run/8f1296c4-38ac-46f8-a0ed-7abc0230b752/stage1/rootfs.
Press ^] three times within 1s to kill container.
Failed to create directory /var/lib/rkt/pods/run/8f1296c4-38ac-46f8-a0ed-7abc0230b752/stage1/rootfs/sys/fs/selinux: Read-only file system
Failed to create directory /var/lib/rkt/pods/run/8f1296c4-38ac-46f8-a0ed-7abc0230b752/stage1/rootfs/sys/fs/selinux: Read-only file system
/etc/localtime is not a symlink, not updating container timezone.
systemd 225 running in system mode. (-PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT -GNUTLS -ACL +XZ -LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
Detected virtualization systemd-nspawn.
Detected architecture x86-64.

Welcome to Linux!

Set hostname to <rkt-8f1296c4-38ac-46f8-a0ed-7abc0230b752>.
Initializing machine ID from container UUID.
Failed to install release agent, ignoring: File exists
[  OK  ] Created slice -.slice.
[  OK  ] Listening on Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket.
[  OK  ] Created slice system.slice.
[  OK  ] Created slice system-prepare\x2dapp.slice.
[  OK  ] Started Pod shutdown.
[  OK  ] Started etcd Reaper.
         Starting Journal Service...
[  OK  ] Started Journal Service.
         Starting Prepare minimum e...chrooted applications...
[  OK  ] Started Prepare minimum en...r chrooted applications.
[  OK  ] Started Application=etcd Image=coreos.com/etcd.
[  OK  ] Reached target rkt apps target.
COMMENT

journalctl

Jun 27 16:40:04 gyuho sudo[4333]:    gyuho : TTY=pts/2 ; PWD=/home/gyuho/rkt-v1.9.1 ; USER=root ; COMMAND=./rkt --debug run --stage1-name=coreos.com/rkt/stage1-coreos:1.3.0 coreos.com/etcd:v3.
Jun 27 16:40:04 gyuho sudo[4333]: pam_unix(sudo:session): session opened for user root by gyuho(uid=0)
Jun 27 16:40:05 gyuho kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jun 27 16:40:05 gyuho NetworkManager[710]: <warn>  [1467070805.5145] device (vethc8359a35): failed to find device 6 'vethc8359a35' with udev
Jun 27 16:40:05 gyuho systemd-udevd[4364]: Could not generate persistent MAC address for vethc8359a35: No such file or directory
Jun 27 16:40:05 gyuho avahi-daemon[753]: Joining mDNS multicast group on interface vethc8359a35.IPv4 with address 172.16.28.1.
Jun 27 16:40:05 gyuho avahi-daemon[753]: New relevant interface vethc8359a35.IPv4 for mDNS.
Jun 27 16:40:05 gyuho avahi-daemon[753]: Registering new address record for 172.16.28.1 on vethc8359a35.IPv4.
Jun 27 16:40:05 gyuho kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Jun 27 16:40:05 gyuho NetworkManager[710]: <info>  [1467070805.5183] manager: (vethc8359a35): new Veth device (/org/freedesktop/NetworkManager/Devices/5)
Jun 27 16:40:05 gyuho NetworkManager[710]: <info>  [1467070805.5204] device (vethc8359a35): link connected
Jun 27 16:40:05 gyuho NetworkManager[710]: <info>  [1467070805.5228] devices added (path: /sys/devices/virtual/net/vethc8359a35, iface: vethc8359a35)
Jun 27 16:40:05 gyuho NetworkManager[710]: <info>  [1467070805.5228] device added (path: /sys/devices/virtual/net/vethc8359a35, iface: vethc8359a35): no ifupdown configuration found.
Jun 27 16:40:06 gyuho avahi-daemon[753]: Joining mDNS multicast group on interface vethc8359a35.IPv6 with address fe80::a4e9:fcff:fe3f:3b18.
Jun 27 16:40:06 gyuho avahi-daemon[753]: New relevant interface vethc8359a35.IPv6 for mDNS.
Jun 27 16:40:06 gyuho avahi-daemon[753]: Registering new address record for fe80::a4e9:fcff:fe3f:3b18 on vethc8359a35.*.
Jun 27 16:40:08 gyuho ntpd[2049]: Listen normally on 13 vethc8359a35 [fe80::a4e9:fcff:fe3f:3b18%6]:123
Jun 27 16:40:08 gyuho ntpd[2049]: new interface(s) found: waking up resolver

# no etcd logs...

@jonboulle

Could anybody in rkt team help on this? Maybe I am using it wrong.

Thanks!

f0 · 2016-06-28T16:17:08Z

any news here?

yifan-gu · 2016-06-29T01:31:13Z

what's the systemd version?

f0 · 2016-06-29T06:04:09Z

@yifan-gu

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/os-release 
NAME=CoreOS
ID=coreos
VERSION=1010.5.0
VERSION_ID=1010.5.0
BUILD_ID=2016-05-26-2225
PRETTY_NAME="CoreOS 1010.5.0 (MoreOS)"
ANSI_COLOR="1;32"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://github.com/coreos/bugs/issues"

lucab · 2016-06-29T08:26:14Z

I think this may be a request for #5449. I just tried and can confirm that etcd is directly shipping its logs to journald. @f0: you should be able to see them with sudo journalctl -M rkt-$UUID as shown in rkt doc. You can also inspect logs merged from multiple containers with journactl -m switch.

f0 · 2016-06-29T10:59:51Z

@lucab hm i assumed i can see the logs for my systemd unit..... why does etcd log directly to the journal and not to stdout.
Now i need to find the uuid, and thats not easy with multiple etcd containers running..... (hopfully rkt supports names in the near future)

lucab · 2016-06-29T13:26:19Z

Now i need to find the uuid, and thats not easy with multiple etcd containers running..... (hopefully rkt supports names in the near future)

How do you run those multiple containers? rkt already supports custom annotation (that's what kubernetes uses to distinguish pods) but in this case you would need something that systemd-* understand too.

I think the cleanest way is to use a service template in conjunction with --uuid-file-save=. That way you directly know which service is associated to a specific uuid.

f0 · 2016-06-29T15:23:09Z

@lucab i run them with system units
I take a look at --uuid-file-save=

f0 · 2016-06-29T15:33:35Z

@lucab hm i do not see how this helps? if i write the uuid into a file, i have the same problem with journalctl ....

lucab · 2016-06-29T20:51:10Z

@f0 sorry if I was unclear. This is an updated version of your etcd service unit. Once installed you can use the following to access journals from different services/pods:

$ sudo systemctl start etcd@0
$ sudo systemctl start etcd@1
$ machinectl
MACHINE                                  CLASS     SERVICE
rkt-7cce2fd6-3c3c-4104-a03f-8b4cee01887c container rkt    
rkt-a1ea1c35-c830-4292-85d5-d9b745f98f37 container rkt 

# log from instance/pod 0
$ sudo journalctl -M rkt-`cat /var/run/rkt-etcd-0.uuid`

# log from instance/pod 1
$ sudo journalctl -M rkt-`cat /var/run/rkt-etcd-1.uuid`

f0 · 2016-06-30T05:31:36Z

@lucab thank you for the further explanation. Yor first explanation was clear, i understand the workaround.

But i do not understand the reason for this...

If you run etcd (without any container) on the commandline, you see logs on stdout
if you run etcd inside a rkt container in interactiv mode (--exec /bin/bash) you see logs on stdout
if you run etcd in a rkt container in non interactive mode you see no logs on stdout <-- why does this differ?

If you run things with systemd the expectation is you can use journalctl -u $unit and see all logs
If you take a look at other projects e.g prometheus, this works without problems.

So the main question is, why does etcd does this in a different way?

regards f0

jonboulle · 2016-06-30T10:50:11Z

@f0 it's basically a capnslog problem - #5449 (comment)

xiang90 · 2016-06-30T17:06:42Z

This turns out a "dup" with #5449. We will resolve this in #5449.

xiang90 mentioned this issue Jun 30, 2016

capnslog: why check ppid = 1 for systemd? coreos/pkg#38

Open

xiang90 closed this as completed Jun 30, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

no logs in the journal when running with rkt #5779

no logs in the journal when running with rkt #5779

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016

f0 commented Jun 27, 2016 •

edited

Loading

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016 •

edited

Loading

f0 commented Jun 28, 2016

yifan-gu commented Jun 29, 2016

f0 commented Jun 29, 2016 •

edited

Loading

lucab commented Jun 29, 2016

f0 commented Jun 29, 2016

lucab commented Jun 29, 2016

f0 commented Jun 29, 2016

f0 commented Jun 29, 2016 •

edited

Loading

lucab commented Jun 29, 2016

f0 commented Jun 30, 2016

jonboulle commented Jun 30, 2016

xiang90 commented Jun 30, 2016

no logs in the journal when running with rkt #5779

no logs in the journal when running with rkt #5779

Comments

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016

f0 commented Jun 27, 2016 • edited Loading

f0 commented Jun 27, 2016

gyuho commented Jun 27, 2016 • edited Loading

f0 commented Jun 28, 2016

yifan-gu commented Jun 29, 2016

f0 commented Jun 29, 2016 • edited Loading

lucab commented Jun 29, 2016

f0 commented Jun 29, 2016

lucab commented Jun 29, 2016

f0 commented Jun 29, 2016

f0 commented Jun 29, 2016 • edited Loading

lucab commented Jun 29, 2016

f0 commented Jun 30, 2016

jonboulle commented Jun 30, 2016

xiang90 commented Jun 30, 2016

f0 commented Jun 27, 2016 •

edited

Loading

gyuho commented Jun 27, 2016 •

edited

Loading

f0 commented Jun 29, 2016 •

edited

Loading

f0 commented Jun 29, 2016 •

edited

Loading