Skip to content

Invalid Characters in Windows Event Log Break winlogbeat

Summary

When running gitlab-runner 13.0, or earlier, as a service on Windows 10 1909, or earlier, it pollutes the Windows Event Log with invalid characters, e.g. Unicode Character 'ESCAPE' (U+001B). This causes the Windows Event Viewer to be unable to show the details section of the event. Even worse, it breaks winlogbeat, which is a widely used log sender for Windows to send the Windows Event Logs to Graylog, logstash, etc. Breaking it means it won't send the logs to the log server, which makes logging rather pointless.

Steps to reproduce

  1. Install Windows.
  2. Install gitlab-runner.
  3. Run something.
  4. Open the Windows Event Log.
  5. Select the Application log.
  6. Click on a gitlab-runner log.
  7. Click on details.

Actual behavior

The runner logs to the Windows Event Log by just forwarding the output to the Windows Event log that it would have written to console. This include ANSI colour codes, which always start with U+001B.

Expected behavior

The runner should check if the terminal supports ANSI colour codes before using them. Using them on terminals that don't support them looks ugly, and doesn't really help debugging problems. In this case, it even breaks things. While it is unclear to me if this could also be a bug in both winlogbeat and Windows Event Log, or some Windows logging subsystem, it is the unusual behaviour of the gitlab-runner which causes it. Gitlab-runner is also the place, where it could be easily fixed.

Relevant logs and/or screenshots

The following, or similar events show up in the log file of winlogbeat. Notice the appearance of U+001B in front of the terminal escapes to colour the console output.

2020-05-20T01:14:34.262+0200	ERROR	eventlog/wineventlog.go:177	WinEventLog[Application] Dropping event. Failed to unmarshal XML='<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='gitlab-runner'/><EventID Qualifiers='0'>1</EventID><Level>4</Level><Task>0</Task><Keywords>0x80000000000000</Keywords><TimeCreated SystemTime='2020-05-19T23:14:34.250290500Z'/><EventRecordID>21076</EventRecordID><Channel>Application</Channel><Computer>win10buildbot</Computer><Security/></System><EventData><Data>Checking for jobs... received                     [0;m  job[0;m=134984 repo_url[0;m=https://gitlab/repo.git runner[0;m=KpJzWEns

Also, the Windows Event Viewer details page always looks something like this for gitlab-runner events. It's the German translation of roughly "This log entry isn't shown as intended, because the XML is not well-formed." Windows Event Viewer Details

Environment description

OS is Windows 10 1909.

config.toml contents 
concurrent = 4
check_interval = 0
listen_address = ":9252"

[session_server]
  session_timeout = 1800

[[runners]]
  name = "win10buildbot"
  url = "https://gitlab/"
  token = ""
  executor = "shell"
  environment = [...]
  [runners.custom_build_dir]
  [runners.cache]
    Type = "s3"
    Shared = true
    [runners.cache.s3]
      ServerAddress = "gitlab:9001"
      AccessKey = "...
      SecretKey = "..."
      BucketName = "gitlab-runner"   
      Insecure = false

Used GitLab Runner version

Version:      13.0.0
Git revision: c127439c
Git branch:   13-0-stable
GO version:   go1.13.8
Built:        2020-05-20T09:05:27+0000
OS/Arch:      windows/amd64

Affects older versions, too.

Possible fixes

While Microsoft doesn't seem to specify not to use such characters for logging, gitlab-runner should drop the colour codes, or at least the U+001B, from the console output on Windows, or at least when writing to the Windows Event Log.