Nomad 0.9.0-rc1 does not collect logs from Windows Server 2019 containers

[vyacheslav-skvortsov]

Nomad version

Nomad v0.9.0-rc1 (7c00ab4)

Operating system and Environment details

Windows Server 2019 Standard
1809
10.0.17763

Issue

posh-get-service.stdout.0

C:\Users\TP>docker logs daf503e3cf80
Windows PowerShell

Nomad Client logs

2019-03-27T07:37:44.097Z [DEBUG] client: allocation updates applied: added=1 removed=0 updated=3 ignored=4 errors=0
    2019-03-27T07:37:44.099Z [DEBUG] client.alloc_migrator: waiting for previous alloc to terminate: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b previous_alloc=53c5d57c-d7f5-a449-5af4-9c053fdf9377
    2019-03-27T07:37:44.099Z [DEBUG] client.alloc_migrator: waiting for previous alloc to terminate: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b previous_alloc=53c5d57c-d7f5-a449-5af4-9c053fdf9377
    2019-03-27T07:37:44.149Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon: starting plugin: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe args="[C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe logmon]"
    2019-03-27T07:37:44.152Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon: plugin started: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe pid=7260
    2019-03-27T07:37:44.152Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon: waiting for RPC address: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe
    2019-03-27T07:37:44.256Z [DEBUG] client: updated allocations: index=189981 total=8 pulled=2 filtered=6
    2019-03-27T07:37:44.256Z [DEBUG] client: allocation updates: added=0 removed=0 updated=2 ignored=6
    2019-03-27T07:37:44.304Z [DEBUG] client: allocation updates applied: added=0 removed=0 updated=2 ignored=6 errors=0
    2019-03-27T07:37:44.463Z [DEBUG] client: updated allocations: index=189982 total=8 pulled=2 filtered=6
    2019-03-27T07:37:44.464Z [DEBUG] client: allocation updates: added=0 removed=0 updated=2 ignored=6
    2019-03-27T07:37:44.538Z [DEBUG] client: allocation updates applied: added=0 removed=0 updated=2 ignored=6 errors=0
    2019-03-27T07:37:44.591Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon: using plugin: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service version=2
    2019-03-27T07:37:44.591Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon.nomad.exe: plugin address: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service @module=logmon address=127.0.0.1:10002 network=tcp timestamp=2019-03-27T07:37:44.591Z
    2019-03-27T07:37:44.593Z [INFO ] client.alloc_runner.task_runner.task_hook.logmon.nomad.exe: opening fifo: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service @module=logmon path=//./pipe/posh-get-service-2f7d55cf.stdout timestamp=2019-03-27T07:37:44.593Z
    2019-03-27T07:37:44.593Z [INFO ] client.alloc_runner.task_runner.task_hook.logmon.nomad.exe: opening fifo: alloc_id=afd22ea6-6942-2de5-bdc2-42c839b19e8b task=posh-get-service path=//./pipe/posh-get-service-2f7d55cf.stderr @module=logmon timestamp=2019-03-27T07:37:44.593Z
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: image reference count incremented: driver=docker image_name=mcr.microsoft.com/windows/servercore:1809 image_id=sha256:1206cbf9524ce814348336149dd5fab82bd7a5a2552b13f84e45eafd41748bbc references=4
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: configured resources: driver=docker task_name=posh-get-service memory=1048576000 cpu_shares=1000 cpu_quota=0 cpu_period=0
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: binding directories: driver=docker task_name=posh-get-service binds="[]string{"C:\\ProgramData\\nomad\\data\\alloc\\afd22ea6-6942-2de5-bdc2-42c839b19e8b\\alloc:c:\\alloc", "C:\\ProgramData\\nomad\\data\\alloc\\afd22ea6-6942-2de5-bdc2-42c839b19e8b\\posh-get-service\\local:c:\\local", "C:\\ProgramData\\nomad\\data\\alloc\\afd22ea6-6942-2de5-bdc2-42c839b19e8b\\posh-get-service\\secrets:c:\\secrets"}"
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: networking mode not specified; using default: driver=docker task_name=posh-get-service network_mode=nat
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: no network interfaces are available: driver=docker task_name=posh-get-service
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: setting container startup command: driver=docker task_name=posh-get-service command=powershell
    2019-03-27T07:37:44.749Z [DEBUG] client.driver_mgr.docker: setting container name: driver=docker task_name=posh-get-service container_name=afd22ea6-6942-2de5-bdc2-42c839b19e8b_posh-get-service_f11f5f68
    2019-03-27T07:37:44.821Z [INFO ] client.driver_mgr.docker: created container: driver=docker container_id=daf503e3cf80e24fd749fa650237287082658633f8f3a2d78ff29a3359050ef3
    2019-03-27T07:37:47.239Z [INFO ] client.driver_mgr.docker: started container: driver=docker container_id=daf503e3cf80e24fd749fa650237287082658633f8f3a2d78ff29a3359050ef3
    2019-03-27T07:37:47.239Z [DEBUG] client.driver_mgr.docker.docker_logger: starting plugin: driver=docker path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe args="[C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe docker_logger]"
    2019-03-27T07:37:47.248Z [DEBUG] client.driver_mgr.docker.docker_logger: plugin started: driver=docker path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe pid=6536
    2019-03-27T07:37:47.248Z [DEBUG] client.driver_mgr.docker.docker_logger: waiting for RPC address: driver=docker path=C:\ProgramData\chocolatey\lib\nomad\tools\nomad.exe
    2019-03-27T07:37:48.636Z [DEBUG] client.driver_mgr.docker.docker_logger.nomad.exe: plugin address: driver=docker address=127.0.0.1:10003 network=tcp @module=docker_logger timestamp=2019-03-27T07:37:48.635Z
    2019-03-27T07:37:48.636Z [DEBUG] client.driver_mgr.docker.docker_logger: using plugin: driver=docker version=2
    2019-03-27T07:37:48.637Z [DEBUG] client.driver_mgr.docker.docker_logger.nomad.exe: using client connection initialized from environment: driver=docker @module=docker_logger timestamp=2019-03-27T07:37:48.637Z
    2019-03-27T07:37:49.107Z [DEBUG] client: updated allocations: index=189983 total=8 pulled=2 filtered=6
    2019-03-27T07:37:49.107Z [DEBUG] client: allocation updates: added=0 removed=0 updated=2 ignored=6
    2019-03-27T07:37:49.193Z [DEBUG] client: allocation updates applied: added=0 removed=0 updated=2 ignored=6 errors=0
    2019-03-27T07:37:51.914Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration=3.4583ms

Job file

job "win2019-test" {
  datacenters = ["dc1"]
  type = "service"

  group "test-env" {
    constraint {
      attribute = "${node.unique.name}"
      operator  = "regexp"
      value     = "tp-0[1-2]"
    }

    task "posh-get-service" {
      driver = "docker"
      config {
        image = "mcr.microsoft.com/windows/servercore:1809"
        command  = "powershell"
        interactive = true
        tty = true
      }

      resources {
        cpu = 1000
        memory = 1000
      }
    }
  }
}

[schmichael]

Confirmed logs are broken when using tty = true on Windows.

Removing tty = true makes the logs work as expected. Is a tty required for your use case?

[vyacheslav-skvortsov]

Thank you for the reply.
Yes, tty is required for me for several cases. Some legacy console apps expect stdin for proper work.
This issue #5464 has the same reasons.

[github-actions]

I'm going to lock this issue because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.