Otdfbt

I'm using Google Kubernetes Engine (GKE) in conjunction with Stackdriver Logging.

The Stackdriver's documentation says there are some special fields used by Logging agent to set fields in the LogEntry object.

As regard to severity field, it works fine. However, time field doesn't work as intended.

The following JSON is a MySQL error log, which was modified and redirected to stdout:

(beautified and annotated for clarity)

 "prio": 0,
 "err_code": 11323,
 "component": "mysqlx",
 "source_line": 154,
 "source_file": "socket_acceptors_task.cc",
 "function": "show_startup_log",
 "msg": "X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060",
 "err_symbol": "ER_XPLUGIN_LISTENER_STATUS_MSG",
 "SQL_state": "HY000",
 "subsystem": "Server",
 "label": "System",

 // Added for Stackdriver Logging
 "severity": "INFO",
 "time": "1548054692.636",

 // This is the same time written in human-readable format.
 "time.readable": "2019-01-21T07:11:32.636761Z"

And the following is the corresponding log recorded by Stackdriver Logging:

(beautified and annotated for clarity)

 "insertId": "1jibhqgfw4kum0",
 "jsonPayload": 
 // Both `severity` and `time` fields were removed.

 "msg": "X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060",
 "label": "System",
 "prio": 0,
 "err_code": 11323,
 "time.readable": "2019-01-21T07:11:32.636761Z",
 "subsystem": "Server",
 "source_file": "socket_acceptors_task.cc",
 "err_symbol": "ER_XPLUGIN_LISTENER_STATUS_MSG",
 "function": "show_startup_log",
 "SQL_state": "HY000",
 "source_line": 154,
 "component": "mysqlx"
 ,
 "resource": 
 "type": "container",
 "labels": 
 "namespace_id": "myproject",
 "instance_id": "506697609301173766",
 "zone": "asia-east1-b",
 "pod_id": "demo-demoid1234567890-sns7g",
 "project_id": "harai-development",
 "cluster_name": "myproject",
 "container_name": "mysql-errorlog-output"
 
 ,

 // `timestamp` doesn't reflect the value in the original log,
 // which is "2019-01-21T07:11:32.636761Z".
 "timestamp": "2019-01-21T07:11:44Z",

 // `severity` reflects the value in the original log
 "severity": "INFO",

 "labels": 
 "compute.googleapis.com/resource_name": "fluentd-gcp-v3.1.0-pwc9k",
 "container.googleapis.com/pod_name": "demo-demoid1234567890-sns7g",
 "container.googleapis.com/stream": "stdout",
 "container.googleapis.com/namespace_name": "myproject"
 ,
 "logName": "projects/harai-development/logs/mysql-errorlog-output",
 "receiveTimestamp": "2019-01-21T07:11:49.560205566Z"

Although the both time and severity fields were removed, timestamp field in LogEntry doesn't reflect the time specified in the original time field.

How can I set timestamp to the time the log is created?

In the Fluentd configuration for GKE cluster, the time format is defined like this:

time_format %Y-%m-%dT%H:%M:%S.%NZ

Therefore, it will work as expected by setting the time field as "2019-01-21T07:11:32.636761000Z".

Ref: https://issuetracker.google.com/issues/123303610