Kibana showing one log but not the other

Elastic Stack Kibana
1

ELK: 6.2.1

Testing that there are results in elasticsearch for both queries:

hits total: 10

POST /slow_queries/_search
    {
        "_source": {
            "includes": [ "message" ]
        },
        "query" : {
            "match" : { "message" : "sleep" }
        }
    }

hits total: 45

POST /slow_queries/_search
    {
        "_source": {
            "includes": [ "message" ]
        },
        "query" : {
            "match" : { "message" : "long" }
        }
    }

All logs including the word "long" are showing up in Kibana, but no single log line with "sleep" (see screenshot).

35%20pm
Screen Shot 2018-03-12 at 4.48.35 pm.png1218×643 95.8 KB

Here are example logs for two loglines taken from the logstash logs.

"long"

{
    "@timestamp" => 2018-03-12T05:18:51.614Z,
    "@version" => "1",
    "args" => [],
    "created" => 1520831920.4154787,
    "docker" => {
        "hostname" => "8c439904695d",
        "id" => "8c439904695d828ec3cd1e7a903958ad498a689d2c0ae212c04d0ef443525655",
        "image" => "****/slow-queries:468c1f0@sha256:965215c3d6bf99b0c74b622bc5e5d84155a3914b7248f0d5f446104bebee6cd0",
        "name" => "/production_slow_queries.1.33bloga27tt1epfzuxy5f2uku"
    },
    "exc_info" => nil,
    "exc_text" => nil,
    "filename" => "worker.py",
    "funcName" => "work",
    "host" => "10.255.0.2",
    "levelname" => "INFO",
    "levelno" => 20,
    "lineno" => 37,
    "message" => "[****] Found 0 long running queries.",
    "module" => "worker",
    "msecs" => 415.4787063598633,
    "msg" => "[****] Found 0 long running queries.",
    "name" => "hal",
    "pathname" => "/source/slow_queries/worker.py",
    "process" => 5,
    "processName" => "MainProcess",
    "relativeCreated" => 1455101.0446548462,
    "revision" => "468c1f0",
    "service" => "slow_queries",
    "severity" => "INFO",
    "stack_info" => nil,
    "thread" => 139987722451688,
    "threadName" => "Thread-1"
    }
}

"sleep"

{
    "@timestamp" => 2018-03-12T16:18:36.000Z,
    "@version" => "1",
    "args" => [],
    "created" => 1520831963.603542,
    "db" => "",
    "docker" => {
        "hostname" => "68a5a0bc355b",
        "id" => "68a5a0bc355b0e90376d7c66fa5ee578fc991f347bda5b1e65cb4bde7dfb67c2",
        "image" => "****/slow-queries:468c1f0@sha256:965215c3d6bf99b0c74b622bc5e5d84155a3914b7248f0d5f446104bebee6cd0",
        "name" => "/production_slow_queries.1.bkkqodxf5d0adb1zrlu877wst"
    },
    "exc_info" => nil,
    "exc_text" => nil,
    "filename" => "worker.py",
    "funcName" => "work",
    "host" => "10.255.0.2",
    "insert_id" => 0,
    "last_insert_id" => 0,
    "levelname" => "INFO",
    "levelno" => 20,
    "lineno" => 34,
    "lock_time" => "0:00:00",
    "message" => "select sleep(65)",
    "module" => "worker",
    "msecs" => 603.5420894622803,
    "name" => "****",
    "pathname" => "/source/slow_queries/worker.py",
    "process" => 5,
    "processName" => "MainProcess",
    "query_time" => "0:01:05",
    "relativeCreated" => 1501900.234222412,
    "revision" => "468c1f0",
    "rows_examined" => 0,
    "rows_sent" => 1,
    "server_id" => 772747237,
    "service" => "slow_queries",
    "severity" => "INFO",
    "sql_text" => "select sleep(65)",
    "stack_info" => nil,
    "start_time" => "2018-03-12T16:18:36",
    "thread" => 140652554259176,
    "threadName" => "Thread-1",
    "thread_id" => 1354578,
    "user_host" => "****[****] @  [172.30.0.172]"
}

Any help/hint is appreciated.

2

Hey @k.art the timefilter that you can change in the upper right corner of Kibana is excluding the specific "long" message. The timestamp for the "long" example is "2018-03-12T05:18:51.614Z" which falls outside of the "Last 1 Hour" time filter.

3

@Brandon_Kobel You are right. Thanks for pointing that out.
It was confusing as the database returns local time (not my design decision!) which was even unaware of its timezone and ELK treats incoming timestamps as UTC and converts them for display purposes (back) to local time again.
The timestamp for the "long" query was UTC already, hence the difference.

4

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.