[log_format] detect time format change in JSON logs

Related to #1215
pull/1235/head
Tim Stack 5 months ago
parent 57467edea7
commit 22a5781e88

@ -1817,14 +1817,40 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len)
auto frag = string_fragment::from_bytes(str, len);
if (jlu->jlu_format->lf_timestamp_field == field_name) {
jlu->jlu_format->lf_date_time.scan(
const auto* last = jlu->jlu_format->lf_date_time.scan(
(const char*) str,
len,
jlu->jlu_format->get_timestamp_formats(),
&tm_out,
tv_out);
jlu->jlu_format->lf_timestamp_flags = tm_out.et_flags;
jlu->jlu_base_line->set_time(tv_out);
if (last == nullptr) {
auto ls = jlu->jlu_format->lf_date_time.unlock();
if ((last = jlu->jlu_format->lf_date_time.scan(
(const char*) str,
len,
jlu->jlu_format->get_timestamp_formats(),
&tm_out,
tv_out))
== nullptr)
{
jlu->jlu_format->lf_date_time.relock(ls);
}
if (last != nullptr) {
auto old_flags
= jlu->jlu_format->lf_timestamp_flags & DATE_TIME_SET_FLAGS;
auto new_flags = tm_out.et_flags & DATE_TIME_SET_FLAGS;
// It is unlikely a valid timestamp would lose much
// precision.
if (new_flags != old_flags) {
last = nullptr;
}
}
}
if (last != nullptr) {
jlu->jlu_format->lf_timestamp_flags = tm_out.et_flags;
jlu->jlu_base_line->set_time(tv_out);
}
} else if (jlu->jlu_format->elf_level_pointer.pp_value != nullptr) {
if (jlu->jlu_format->elf_level_pointer.pp_value
->find_in(field_name.to_string_fragment(), PCRE2_NO_UTF_CHECK)
@ -1884,12 +1910,25 @@ rewrite_json_field(yajlpp_parse_context* ypc,
struct timeval tv;
struct exttm tm;
jlu->jlu_format->lf_date_time.scan(
const auto* last = jlu->jlu_format->lf_date_time.scan(
(const char*) str,
len,
jlu->jlu_format->get_timestamp_formats(),
&tm,
tv);
if (last == nullptr) {
auto ls = jlu->jlu_format->lf_date_time.unlock();
if ((last = jlu->jlu_format->lf_date_time.scan(
(const char*) str,
len,
jlu->jlu_format->get_timestamp_formats(),
&tm,
tv))
== nullptr)
{
jlu->jlu_format->lf_date_time.relock(ls);
}
}
sql_strftime(time_buf, sizeof(time_buf), tv, 'T');
} else {
sql_strftime(

@ -29,6 +29,10 @@ TIME_FORMATS = \
"%Y-%m-%dT%H:%M" \
"%Y/%m/%d %H:%M:%S %z" \
"%Y/%m/%d %H:%M:%S%z" \
"%Y/%m/%d %H:%M:%S.%f%z" \
"%Y/%m/%d %H:%M:%S.%f%Z" \
"%Y/%m/%d %H:%M:%S.%f %z" \
"%Y/%m/%d %H:%M:%S.%f %Z" \
"%Y/%m/%d %H:%M:%S.%f" \
"%Y/%m/%d %H:%M:%S.%L" \
"%Y/%m/%d %H:%M:%S" \

@ -5,7 +5,7 @@
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG4", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG3", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG2", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG", "msg": "Details..."}
{"ts": "2013-09-06 22:01:00Z", "lvl": "DEBUG", "msg": "Details..."}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "STATS", "msg": "1 beat per second"}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "WARNING", "msg": "not looking good"}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "ERROR", "msg": "looking bad"}

@ -114,8 +114,8 @@
{
"log_line": 15,
"log_part": null,
"log_time": "2013-09-06 22:00:59.124",
"log_idle_msecs": 0,
"log_time": "2013-09-06 22:01:00.000",
"log_idle_msecs": 876,
"log_level": "debug",
"log_mark": 0,
"log_comment": null,
@ -131,7 +131,7 @@
"log_line": 17,
"log_part": null,
"log_time": "2013-09-06 22:01:49.124",
"log_idle_msecs": 50000,
"log_idle_msecs": 49124,
"log_level": "stats",
"log_mark": 0,
"log_comment": null,

@ -14,7 +14,7 @@
[2013-09-06T22:00:59.124] DEBUG2 Details...
[2013-09-06T22:00:59.124] DEBUG Details...
[2013-09-06T22:01:00.000] DEBUG Details...
[2013-09-06T22:01:49.124] STATS 1 beat per second

@ -6,8 +6,8 @@ log_line,log_part,log_time,log_idle_msecs,log_level,log_mark,log_comment,log_tag
9,<NULL>,2013-09-06 22:00:59.124,0,debug4,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,DEBUG4,<NULL>
11,<NULL>,2013-09-06 22:00:59.124,0,debug3,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,DEBUG3,<NULL>
13,<NULL>,2013-09-06 22:00:59.124,0,debug2,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,DEBUG2,<NULL>
15,<NULL>,2013-09-06 22:00:59.124,0,debug,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,DEBUG,<NULL>
17,<NULL>,2013-09-06 22:01:49.124,50000,stats,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,STATS,<NULL>
15,<NULL>,2013-09-06 22:01:00.000,876,debug,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,DEBUG,<NULL>
17,<NULL>,2013-09-06 22:01:49.124,49124,stats,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,STATS,<NULL>
19,<NULL>,2013-09-06 22:01:49.124,0,warning,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,WARNING,<NULL>
21,<NULL>,2013-09-06 22:01:49.124,0,error,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,ERROR,<NULL>
23,<NULL>,2013-09-06 22:01:49.124,0,critical,0,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,<NULL>,CRITICAL,<NULL>

@ -18,7 +18,7 @@ bork bork bork
[2013-09-06T22:00:59.124000Z] ⋮ Details...
bork bork bork
[2013-09-06T22:00:59.124000Z] ⋮ Details...bork bork bork
[2013-09-06T22:01:00.000000Z] ⋮ Details...bork bork bork
[2013-09-06T22:01:49.124000Z] ⋮ 1 beat per secondbork bork bork

@ -5,7 +5,7 @@
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG4", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG3", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG2", "msg": "Details...\n"}
{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG", "msg": "Details..."}
{"ts": "2013-09-06 22:01:00Z", "lvl": "DEBUG", "msg": "Details..."}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "STATS", "msg": "1 beat per second"}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "WARNING", "msg": "not looking good"}
{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "ERROR", "msg": "looking bad"}

@ -213,7 +213,7 @@ ts
2013-09-06T22:00:59.124817Z
2013-09-06T22:00:59.124817Z
2013-09-06T22:00:59.124817Z
2013-09-06T22:00:59.124817Z
2013-09-06 22:01:00Z
2013-09-06T22:01:49.124817Z
2013-09-06T22:01:49.124817Z
2013-09-06T22:01:49.124817Z

Loading…
Cancel
Save