Reassemble partial messages that are in JSON format

[weathe...@gmail.com]

Hello.

We are running td-agent 0.12.31.   We are running fluentd to gather our docker logs and ship them to elasticsearch.    This worked great until we deployed docker 1.13 which splits up messages that are over 16k in length.    Issue related to making that configurable in docker is here https://github.com/moby/moby/issues/32923.   

When docker does split a message it sets an attribute on the log line called `Partial` and this get's applied to the all of the message pieces except the last.    So if I had a log line that was 40K in length docker would split that into 3 individual log entries and apply the `Partial` attribute to the first 2 pieces.    Currently the only docker log driver that does anything with the `Partial` attribute is the journald log driver.    Which brings me to my question.

If i'm running fluentd with the plugin fluent-plugin-systemd that reads from journald do any plugins exist that would allow me to piece these messages back together or will i be writing my own?    To further complicate matters I like many other docker users write structured log data and not only do I need to stitch the logs back together but I need to stitch back the chunks into a specific JSON key.

Below is an example of a single large (56k) log line that got written from a docker container as read from journald. I have added a blank line between each partial message for clarity and replaced the actual log payload with <SNIPPED LOG DATA> for readability. As you can see in the first 3 payloads the journald field "CONTAINER_PARTIAL_MESSAGE" exists and is set to true while the final piece of the log does not.   Additionally the way most of our applications write logs is in JSON format with the key name `message` actually holding the log payload.    So to further complicate the matters i'm wanting to not only stitch the pieces back together but the results need to be a valid JSON object with the extra payloads being concatenated onto the value of the `message` key.

I don't mind writing a plugin but I was hoping to get feedback from the community as to whether all or some of my objective can already be achieved either through the core capabilities of fluentd or by any existing plugins.

{ "__CURSOR" : "s=bd23be54ae3247e2906300a42c12cc77;i=17488;b=922ce21a313346e0a7cfc51b5af3c346;m=7bffd2b0;t=54ea1f408b4af;x=3325688f82101b49", "__REALTIME_TIMESTAMP" : "1493832374465711", "__MONOTONIC_TIMESTAMP" : "2080363184", "_BOOT_ID" : "922ce21a313346e0a7cfc51b5af3c346", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "3fffffffff", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:kernel_t:s0", "_MACHINE_ID" : "f0e59e84e6cc4eb59901e1c216ef4e49", "_HOSTNAME" : "ip-10-20-0-109.ec2.internal", "_TRANSPORT" : "journal", "_PID" : "3965", "_COMM" : "dockerd", "_EXE" : "/usr/bin/dockerd", "_CMDLINE" : "dockerd --host=fd:// --containerd=/var/run/docker/libcontainerd/docker-containerd.sock --iptables=false --ip-masq=false --storage-driver=overlay --log-driver=journald --live-restore --bip=172.20.108.1/24 --mtu=8951 --ip-masq=false", "_SYSTEMD_CGROUP" : "/system.slice/docker.service", "_SYSTEMD_UNIT" : "docker.service", "CONTAINER_ID_FULL" : "dab733a81ac07c28cfd2fcc564b9e017f8a14e1bbabb1e0a5a3a69e6062acf06", "CONTAINER_NAME" : "practical_booth", "CONTAINER_TAG" : "dab733a81ac0", "CONTAINER_ID" : "dab733a81ac0", "CONTAINER_PARTIAL_MESSAGE" : "true", "MESSAGE" : "{\"message\":\"LOGSPEWPREFIXSIZE51200:<SNIPPED LOG DATA>", "_SOURCE_REALTIME_TIMESTAMP" : "1493832374428321" }

{ "__CURSOR" : "s=bd23be54ae3247e2906300a42c12cc77;i=17489;b=922ce21a313346e0a7cfc51b5af3c346;m=7bffdfc0;t=54ea1f408c1bf;x=5cdb6569722db4d1", "__REALTIME_TIMESTAMP" : "1493832374469055", "__MONOTONIC_TIMESTAMP" : "2080366528", "_BOOT_ID" : "922ce21a313346e0a7cfc51b5af3c346", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "3fffffffff", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:kernel_t:s0", "_MACHINE_ID" : "f0e59e84e6cc4eb59901e1c216ef4e49", "_HOSTNAME" : "ip-10-20-0-109.ec2.internal", "_TRANSPORT" : "journal", "_PID" : "3965", "_COMM" : "dockerd", "_EXE" : "/usr/bin/dockerd", "_CMDLINE" : "dockerd --host=fd:// --containerd=/var/run/docker/libcontainerd/docker-containerd.sock --iptables=false --ip-masq=false --storage-driver=overlay --log-driver=journald --live-restore --bip=172.20.108.1/24 --mtu=8951 --ip-masq=false", "_SYSTEMD_CGROUP" : "/system.slice/docker.service", "_SYSTEMD_UNIT" : "docker.service", "CONTAINER_ID_FULL" : "dab733a81ac07c28cfd2fcc564b9e017f8a14e1bbabb1e0a5a3a69e6062acf06", "CONTAINER_NAME" : "practical_booth", "CONTAINER_TAG" : "dab733a81ac0", "CONTAINER_ID" : "dab733a81ac0", "CONTAINER_PARTIAL_MESSAGE" : "true", "MESSAGE" : "<SNIPPED LOG DATA>", "_SOURCE_REALTIME_TIMESTAMP" : "1493832374457753" }

{ "__CURSOR" : "s=bd23be54ae3247e2906300a42c12cc77;i=1748a;b=922ce21a313346e0a7cfc51b5af3c346;m=7bffed56;t=54ea1f408cf55;x=b0ec77a5a05afc07", "__REALTIME_TIMESTAMP" : "1493832374472533", "__MONOTONIC_TIMESTAMP" : "2080370006", "_BOOT_ID" : "922ce21a313346e0a7cfc51b5af3c346", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "3fffffffff", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:kernel_t:s0", "_MACHINE_ID" : "f0e59e84e6cc4eb59901e1c216ef4e49", "_HOSTNAME" : "ip-10-20-0-109.ec2.internal", "_TRANSPORT" : "journal", "_PID" : "3965", "_COMM" : "dockerd", "_EXE" : "/usr/bin/dockerd", "_CMDLINE" : "dockerd --host=fd:// --containerd=/var/run/docker/libcontainerd/docker-containerd.sock --iptables=false --ip-masq=false --storage-driver=overlay --log-driver=journald --live-restore --bip=172.20.108.1/24 --mtu=8951 --ip-masq=false", "_SYSTEMD_CGROUP" : "/system.slice/docker.service", "_SYSTEMD_UNIT" : "docker.service", "CONTAINER_ID_FULL" : "dab733a81ac07c28cfd2fcc564b9e017f8a14e1bbabb1e0a5a3a69e6062acf06", "CONTAINER_NAME" : "practical_booth", "CONTAINER_TAG" : "dab733a81ac0", "CONTAINER_ID" : "dab733a81ac0", "CONTAINER_PARTIAL_MESSAGE" : "true", "MESSAGE" : "<SNIPPED LOG DATA>", "_SOURCE_REALTIME_TIMESTAMP" : "1493832374457892" }

{ "__CURSOR" : "s=bd23be54ae3247e2906300a42c12cc77;i=1748b;b=922ce21a313346e0a7cfc51b5af3c346;m=7bfffb35;t=54ea1f408dd33;x=a6c38ff8c9f1c5ae", "__REALTIME_TIMESTAMP" : "1493832374476083", "__MONOTONIC_TIMESTAMP" : "2080373557", "_BOOT_ID" : "922ce21a313346e0a7cfc51b5af3c346", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "3fffffffff", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:kernel_t:s0", "_MACHINE_ID" : "f0e59e84e6cc4eb59901e1c216ef4e49", "_HOSTNAME" : "ip-10-20-0-109.ec2.internal", "_TRANSPORT" : "journal", "_PID" : "3965", "_COMM" : "dockerd", "_EXE" : "/usr/bin/dockerd", "_CMDLINE" : "dockerd --host=fd:// --containerd=/var/run/docker/libcontainerd/docker-containerd.sock --iptables=false --ip-masq=false --storage-driver=overlay --log-driver=journald --live-restore --bip=172.20.108.1/24 --mtu=8951 --ip-masq=false", "_SYSTEMD_CGROUP" : "/system.slice/docker.service", "_SYSTEMD_UNIT" : "docker.service", "CONTAINER_ID_FULL" : "dab733a81ac07c28cfd2fcc564b9e017f8a14e1bbabb1e0a5a3a69e6062acf06", "CONTAINER_NAME" : "practical_booth", "CONTAINER_TAG" : "dab733a81ac0", "CONTAINER_ID" : "dab733a81ac0", "MESSAGE" : "<SNIPPED LOG DATA>:LOGSPEWPOSTFIXSIZE51200\",\"service_name\":\"logspew\",\"length\":51200}", "_SOURCE_REALTIME_TIMESTAMP" : "1493832374457912" }

Thanks for any tips or ideas on how best to approach this!

[Mr. Fiber]

I'm not sure the details of docker log splitting feature so I have one question.

How to know what log is the first part of long log?

Yeah, I can see "CONTAINER_PARTIAL_MESSAGE" in the log but

there is no field to indicate log position.

Masahiro

--
You received this message because you are subscribed to the Google Groups "Fluentd Google Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fluentd+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[weathe...@gmail.com]

How to know what log is the first part of long log?

Docker does not provide anyway to determine what is the first part of the long log.    Are you thinking that it's not guaranteed that the logs come into fluentd in the correct order and without more details about which part is first or second or last it would be hard to reliably reconstruct the message?

Thanks.  

To unsubscribe from this group and stop receiving emails from it, send an email to fluentd+u...@googlegroups.com.