Nomad: Logging driver is combining stdout and stderr

[justinwalz]

Hi,

Having some issues with logging. I'm seeing both STDOUT and STDERR going to STDOUT. This happened after upgrading to Nomad 0.5.6, but the new AMI included a docker version bump too. See below.

Thanks!

Nomad version

Nomad v0.5.6

Operating system and Environment details

uname -a
Linux ip-10-202-XXX-XXX 4.4.0-77-generic #98-Ubuntu SMP Wed Apr 26 08:34:02 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

docker -v
Docker version 17.05.0-ce, build 89658be

Issue

Logs are being combined into single STDOUT stream. Running the job with nomad (file below) results in logs being written to stdout, on nomad logs <id>.

nomad run test.nomad
nomad status log-test
nomad alloc-status 6ae05f04
# see ls err
nomad logs 6ae05f04
# nothing
nomad logs -stderr 6ae05f04

# writes to err
docker run  --log-opt syslog-format=rfc5424 --log-driver syslog busybox ls asdfa 2> err 1> out



md5-659608f05f822f709a50c2396a9a07d1



job "log-test" {
  region = "us-west"
  datacenters = ["aws-us-west-1"]
  type = "batch"

  group "tg" {
    restart {
      interval = "5m"
      attempts = 10
      mode = "delay"
      delay = "25s"
    }

    task "log-test" {
      driver = "docker"
      config {
        image = "busybox"
        command = "ls"
        args = ["foobar"]
      }

      service {
        name = "log-test"
        tags = ["test", "logs"]
      }

      resources {
        cpu = 512
        memory = 256
      }
    }
  }
}

[justinwalz]

@dadgar Were you able to reproduce?

[dadgar]

@justinwalz Haven't got to play with it yet.

[sheldonkwok]

@dadgar any update on this? We're still unable to get separate stdout/stderr which is hindering our teams from parsing them effectively.

[sheldonkwok]

@dadgar @schmichael any update on this? It's extremely frustrating seeing our noisy stdout logs combined with our important stderr messages.

[schmichael]

Sorry for the long delay @sheldonkwok. Reproduced and working on a fix now.

[schmichael]

Turns out it's a Docker bug! I filed https://github.com/moby/moby/issues/33834#issuecomment-311252891 and it appears a fix has already been submitted: https://github.com/moby/moby/pull/33832

The reason your docker run works as expected is because in the terminal docker simply attaches stdout and stderr in the container to stdout and stderr on your kernel. However if you add a -d like in this docker line:

docker run -d --log-driver syslog busybox ls asdfa

stdin and stderr are not attached because we're daemonizing the container. This is similar to Nomad's behavior.

Once you do that you can see the bug in action. Repro details in that issue I submitted above.

This bug will be fixed by upgrading Docker once they release the fix.

[justinwalz]

Great, thanks for diving into this @schmichael