Stackdriver Logging doesn't recognize time field in JSON logInstalling StackDriver Logging agent on cos imageUse a wild card in StackDriver LoggingSpecifying resource in Stackdriver loggingGoogle Stackdriver Policy Alert Time PeriodKubernetes Nginx Ingress Controllers log to StackdriverStackdriver logs stopped appearing in GCP Stackdriver Logging Console

How was Apollo supposed to rendezvous in the case of a lunar abort?

Creating Fictional Slavic Place Names

Are academic associations obliged to comply with the US government?

Why use water tanks from a retired Space Shuttle?

Is the capacitor drawn or wired wrongly?

Humans meet a distant alien species. How do they standardize? - Units of Measure

What does War Machine's "Canopy! Canopy!" line mean in "Avengers: Endgame"?

How can a single Member of the House block a Congressional bill?

What does the behaviour of water on the skin of an aircraft in flight tell us?

What are the problems in teaching guitar via Skype?

Should this code fail to compile in C++17?

Do adult Russians normally hand-write Cyrillic as cursive or as block letters?

what's the equivalent of helper in LWC?

Can you please explain this joke: "I'm going bananas is what I tell my bananas before I leave the house"?

Applicants clearly not having the skills they advertise

Coding Challenge Solution - Good Range

Working in the USA for living expenses only; allowed on VWP?

Why don't I have ground wiring on any of my outlets?

Is there any Biblical Basis for 400 years of silence between Old and New Testament?

Estimate related to the Möbius function

California: "For quality assurance, this phone call is being recorded"

How do I get a cleat that's stuck in a pedal, detached from the shoe, out?

Recording the inputs of a command and producing a list of them later on

How can I grammatically understand "Wir über uns"?



Stackdriver Logging doesn't recognize time field in JSON log


Installing StackDriver Logging agent on cos imageUse a wild card in StackDriver LoggingSpecifying resource in Stackdriver loggingGoogle Stackdriver Policy Alert Time PeriodKubernetes Nginx Ingress Controllers log to StackdriverStackdriver logs stopped appearing in GCP Stackdriver Logging Console






.everyoneloves__top-leaderboard:empty,.everyoneloves__mid-leaderboard:empty,.everyoneloves__bot-mid-leaderboard:empty height:90px;width:728px;box-sizing:border-box;








0















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?










share|improve this question






















  • To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

    – Fady
    Jan 24 at 0:46











  • @Fady With respect to severity, it definitely reflects the value in the logs.

    – Akihiro HARAI
    Jan 24 at 3:03











  • So I assume you have tried a different severity like “debug” and it did show, correct ?

    – Fady
    Jan 24 at 3:36











  • @Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

    – Akihiro HARAI
    Jan 24 at 5:26






  • 1





    At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

    – Fady
    Jan 24 at 5:42

















0















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?










share|improve this question






















  • To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

    – Fady
    Jan 24 at 0:46











  • @Fady With respect to severity, it definitely reflects the value in the logs.

    – Akihiro HARAI
    Jan 24 at 3:03











  • So I assume you have tried a different severity like “debug” and it did show, correct ?

    – Fady
    Jan 24 at 3:36











  • @Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

    – Akihiro HARAI
    Jan 24 at 5:26






  • 1





    At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

    – Fady
    Jan 24 at 5:42













0












0








0








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?










share|improve this question














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?







google-kubernetes-engine google-stackdriver






share|improve this question













share|improve this question











share|improve this question




share|improve this question










asked Jan 21 at 8:27









Akihiro HARAIAkihiro HARAI

1305




1305












  • To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

    – Fady
    Jan 24 at 0:46











  • @Fady With respect to severity, it definitely reflects the value in the logs.

    – Akihiro HARAI
    Jan 24 at 3:03











  • So I assume you have tried a different severity like “debug” and it did show, correct ?

    – Fady
    Jan 24 at 3:36











  • @Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

    – Akihiro HARAI
    Jan 24 at 5:26






  • 1





    At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

    – Fady
    Jan 24 at 5:42

















  • To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

    – Fady
    Jan 24 at 0:46











  • @Fady With respect to severity, it definitely reflects the value in the logs.

    – Akihiro HARAI
    Jan 24 at 3:03











  • So I assume you have tried a different severity like “debug” and it did show, correct ?

    – Fady
    Jan 24 at 3:36











  • @Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

    – Akihiro HARAI
    Jan 24 at 5:26






  • 1





    At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

    – Fady
    Jan 24 at 5:42
















To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

– Fady
Jan 24 at 0:46





To verify that you are using structured logging (single line) as per 1 2, you may change the severity to something other than info, like “DEBUG”, would it reflect in the logs ?

– Fady
Jan 24 at 0:46













@Fady With respect to severity, it definitely reflects the value in the logs.

– Akihiro HARAI
Jan 24 at 3:03





@Fady With respect to severity, it definitely reflects the value in the logs.

– Akihiro HARAI
Jan 24 at 3:03













So I assume you have tried a different severity like “debug” and it did show, correct ?

– Fady
Jan 24 at 3:36





So I assume you have tried a different severity like “debug” and it did show, correct ?

– Fady
Jan 24 at 3:36













@Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

– Akihiro HARAI
Jan 24 at 5:26





@Fady Yes, I have output several log messages with different severities, and confirmed they were properly recognized by the agent.

– Akihiro HARAI
Jan 24 at 5:26




1




1





At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

– Fady
Jan 24 at 5:42





At this point I suggest opening an issuetracker report as to be investigated by the Stackdriver team. Include simple reproduction steps (e.g how did you configure structured logging) as to help the team with their investigation.

– Fady
Jan 24 at 5:42










1 Answer
1






active

oldest

votes


















0














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






share|improve this answer























    Your Answer








    StackExchange.ready(function()
    var channelOptions =
    tags: "".split(" "),
    id: "2"
    ;
    initTagRenderer("".split(" "), "".split(" "), channelOptions);

    StackExchange.using("externalEditor", function()
    // Have to fire editor after snippets, if snippets enabled
    if (StackExchange.settings.snippets.snippetsEnabled)
    StackExchange.using("snippets", function()
    createEditor();
    );

    else
    createEditor();

    );

    function createEditor()
    StackExchange.prepareEditor(
    heartbeatType: 'answer',
    autoActivateHeartbeat: false,
    convertImagesToLinks: true,
    noModals: true,
    showLowRepImageUploadWarning: true,
    reputationToPostImages: 10,
    bindNavPrevention: true,
    postfix: "",
    imageUploader:
    brandingHtml: "Powered by u003ca class="icon-imgur-white" href="https://imgur.com/"u003eu003c/au003e",
    contentPolicyHtml: "User contributions licensed under u003ca href="https://creativecommons.org/licenses/by-sa/3.0/"u003ecc by-sa 3.0 with attribution requiredu003c/au003e u003ca href="https://stackoverflow.com/legal/content-policy"u003e(content policy)u003c/au003e",
    allowUrls: true
    ,
    onDemand: true,
    discardSelector: ".discard-answer"
    ,immediatelyShowMarkdownHelp:true
    );



    );













    draft saved

    draft discarded


















    StackExchange.ready(
    function ()
    StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fserverfault.com%2fquestions%2f950024%2fstackdriver-logging-doesnt-recognize-time-field-in-json-log%23new-answer', 'question_page');

    );

    Post as a guest















    Required, but never shown

























    1 Answer
    1






    active

    oldest

    votes








    1 Answer
    1






    active

    oldest

    votes









    active

    oldest

    votes






    active

    oldest

    votes









    0














    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






    share|improve this answer



























      0














      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






      share|improve this answer

























        0












        0








        0







        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






        share|improve this answer













        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







        share|improve this answer












        share|improve this answer



        share|improve this answer










        answered May 17 at 2:37









        Akihiro HARAIAkihiro HARAI

        1305




        1305



























            draft saved

            draft discarded
















































            Thanks for contributing an answer to Server Fault!


            • Please be sure to answer the question. Provide details and share your research!

            But avoid


            • Asking for help, clarification, or responding to other answers.

            • Making statements based on opinion; back them up with references or personal experience.

            To learn more, see our tips on writing great answers.




            draft saved


            draft discarded














            StackExchange.ready(
            function ()
            StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fserverfault.com%2fquestions%2f950024%2fstackdriver-logging-doesnt-recognize-time-field-in-json-log%23new-answer', 'question_page');

            );

            Post as a guest















            Required, but never shown





















































            Required, but never shown














            Required, but never shown












            Required, but never shown







            Required, but never shown

































            Required, but never shown














            Required, but never shown












            Required, but never shown







            Required, but never shown







            Popular posts from this blog

            RemoteApp sporadic failureWindows 2008 RemoteAPP client disconnects within a matter of minutesWhat is the minimum version of RDP supported by Server 2012 RDS?How to configure a Remoteapp server to increase stabilityMicrosoft RemoteApp Active SessionRDWeb TS connection broken for some users post RemoteApp certificate changeRemote Desktop Licensing, RemoteAPPRDS 2012 R2 some users are not able to logon after changed date and time on Connection BrokersWhat happens during Remote Desktop logon, and is there any logging?After installing RDS on WinServer 2016 I still can only connect with two users?RD Connection via RDGW to Session host is not connecting

            How to write a 12-bar blues melodyI-IV-V blues progressionHow to play the bridges in a standard blues progressionHow does Gdim7 fit in C# minor?question on a certain chord progressionMusicology of Melody12 bar blues, spread rhythm: alternative to 6th chord to avoid finger stretchChord progressions/ Root key/ MelodiesHow to put chords (POP-EDM) under a given lead vocal melody (starting from a good knowledge in music theory)Are there “rules” for improvising with the minor pentatonic scale over 12-bar shuffle?Confusion about blues scale and chords

            Esgonzo ibérico Índice Descrición Distribución Hábitat Ameazas Notas Véxase tamén "Acerca dos nomes dos anfibios e réptiles galegos""Chalcides bedriagai"Chalcides bedriagai en Carrascal, L. M. Salvador, A. (Eds). Enciclopedia virtual de los vertebrados españoles. Museo Nacional de Ciencias Naturales, Madrid. España.Fotos