diff --git a/src/base/date_time_scanner.cc b/src/base/date_time_scanner.cc index eeb3659f..c3a904b1 100644 --- a/src/base/date_time_scanner.cc +++ b/src/base/date_time_scanner.cc @@ -47,8 +47,14 @@ date_time_scanner::ftime(char* dst, { off_t off = 0; - if (time_fmt == nullptr) { - PTIMEC_FORMATS[this->dts_fmt_lock].pf_ffunc(dst, off, len, tm); + if (time_fmt == nullptr || this->dts_fmt_lock == -1 + || (tm.et_flags & ETF_MACHINE_ORIENTED)) + { + auto index + = this->dts_fmt_lock != -1 && !(tm.et_flags & ETF_MACHINE_ORIENTED) + ? this->dts_fmt_lock + : PTIMEC_DEFAULT_FMT_INDEX; + PTIMEC_FORMATS[index].pf_ffunc(dst, off, len, tm); if (tm.et_flags & ETF_SUB_NOT_IN_FORMAT) { if (tm.et_flags & ETF_MILLIS_SET) { dst[off++] = '.'; @@ -61,6 +67,9 @@ date_time_scanner::ftime(char* dst, ftime_N(dst, off, len, tm); } } + if (index == PTIMEC_DEFAULT_FMT_INDEX && tm.et_flags & ETF_ZONE_SET) { + ftime_z(dst, off, len, tm); + } dst[off] = '\0'; } else { off = ftime_fmt(dst, len, time_fmt[this->dts_fmt_lock], tm); diff --git a/src/formats/nextcloud_log.json b/src/formats/nextcloud_log.json index d0affadd..9806ee07 100644 --- a/src/formats/nextcloud_log.json +++ b/src/formats/nextcloud_log.json @@ -48,8 +48,7 @@ }, "line-format": [ { - "field": "__timestamp__", - "timestamp-format": "%b %e %H:%M:%S" + "field": "__timestamp__" }, " ", { diff --git a/src/log_format.cc b/src/log_format.cc index 22a9c6f9..7ce39029 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -794,6 +794,7 @@ struct json_log_userdata { scan_batch_context* jlu_batch_context; nonstd::optional jlu_opid_frag; nonstd::optional jlu_subid; + struct exttm jlu_exttm; }; static int read_json_field(yajlpp_parse_context* ypc, @@ -844,33 +845,44 @@ read_json_number(yajlpp_parse_context* ypc, tv.tv_sec = val / divisor; tv.tv_usec = fmod(val, divisor) * (1000000.0 / divisor); - if (jlu->jlu_format->lf_date_time.dts_local_time) { - struct tm ltm; - localtime_r(&tv.tv_sec, <m); -#ifdef HAVE_STRUCT_TM_TM_ZONE - ltm.tm_zone = nullptr; -#endif - ltm.tm_isdst = 0; - tv.tv_sec = tm2sec(<m); + jlu->jlu_format->lf_date_time.to_localtime(tv.tv_sec, jlu->jlu_exttm); + tv.tv_sec = tm2sec(&jlu->jlu_exttm.et_tm); + jlu->jlu_exttm.et_gmtoff + = jlu->jlu_format->lf_date_time.dts_local_offset_cache; + jlu->jlu_exttm.et_flags + |= ETF_MACHINE_ORIENTED | ETF_SUB_NOT_IN_FORMAT | ETF_ZONE_SET; + if (divisor == 1000) { + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; + } else { + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; } + jlu->jlu_exttm.et_nsec = jlu->jlu_exttm.et_nsec = tv.tv_usec * 1000; jlu->jlu_base_line->set_time(tv); } else if (jlu->jlu_format->lf_subsecond_field == field_name) { uint64_t millis = 0; + jlu->jlu_exttm.et_flags &= ~(ETF_MICROS_SET | ETF_MILLIS_SET); switch (jlu->jlu_format->lf_subsecond_unit.value()) { case log_format::subsecond_unit::milli: millis = val; + jlu->jlu_exttm.et_nsec = val * 1000000; + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; break; case log_format::subsecond_unit::micro: millis = std::chrono::duration_cast( std::chrono::microseconds((int64_t) val)) .count(); + jlu->jlu_exttm.et_nsec = val * 1000; + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; break; case log_format::subsecond_unit::nano: millis = std::chrono::duration_cast( std::chrono::nanoseconds((int64_t) val)) .count(); + jlu->jlu_exttm.et_nsec = val; + jlu->jlu_exttm.et_flags |= ETF_NANOS_SET; break; } + jlu->jlu_exttm.et_flags |= ETF_SUB_NOT_IN_FORMAT; jlu->jlu_base_line->set_millis(millis); } else if (jlu->jlu_format->elf_level_field == field_name) { if (jlu->jlu_format->elf_level_pairs.empty()) { @@ -982,6 +994,42 @@ rewrite_json_int(yajlpp_parse_context* ypc, long long val) json_log_userdata* jlu = (json_log_userdata*) ypc->ypc_userdata; const intern_string_t field_name = ypc->get_path(); + if (jlu->jlu_format->lf_timestamp_field == field_name) { + long long divisor = jlu->jlu_format->elf_timestamp_divisor; + struct timeval tv; + + tv.tv_sec = val / divisor; + tv.tv_usec = fmod(val, divisor) * (1000000.0 / divisor); + jlu->jlu_format->lf_date_time.to_localtime(tv.tv_sec, jlu->jlu_exttm); + jlu->jlu_exttm.et_gmtoff + = jlu->jlu_format->lf_date_time.dts_local_offset_cache; + jlu->jlu_exttm.et_flags |= ETF_MACHINE_ORIENTED | ETF_SUB_NOT_IN_FORMAT + | ETF_ZONE_SET | ETF_Z_FOR_UTC; + if (divisor == 1) { + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; + } else { + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; + } + jlu->jlu_exttm.et_nsec = jlu->jlu_exttm.et_nsec = tv.tv_usec * 1000; + } else if (jlu->jlu_format->lf_subsecond_field == field_name) { + jlu->jlu_exttm.et_flags &= ~(ETF_MICROS_SET | ETF_MILLIS_SET); + switch (jlu->jlu_format->lf_subsecond_unit.value()) { + case log_format::subsecond_unit::milli: + jlu->jlu_exttm.et_nsec = val * 1000000; + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; + break; + case log_format::subsecond_unit::micro: + jlu->jlu_exttm.et_nsec = val * 1000; + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; + break; + case log_format::subsecond_unit::nano: + jlu->jlu_exttm.et_nsec = val; + jlu->jlu_exttm.et_flags |= ETF_NANOS_SET; + break; + } + jlu->jlu_exttm.et_flags |= ETF_SUB_NOT_IN_FORMAT; + } + if (!ypc->is_level(1) && !jlu->jlu_format->has_value_def(field_name)) { return 1; } @@ -998,6 +1046,42 @@ rewrite_json_double(yajlpp_parse_context* ypc, double val) json_log_userdata* jlu = (json_log_userdata*) ypc->ypc_userdata; const intern_string_t field_name = ypc->get_path(); + if (jlu->jlu_format->lf_timestamp_field == field_name) { + long long divisor = jlu->jlu_format->elf_timestamp_divisor; + struct timeval tv; + + tv.tv_sec = val / divisor; + tv.tv_usec = fmod(val, divisor) * (1000000.0 / divisor); + jlu->jlu_format->lf_date_time.to_localtime(tv.tv_sec, jlu->jlu_exttm); + jlu->jlu_exttm.et_gmtoff + = jlu->jlu_format->lf_date_time.dts_local_offset_cache; + jlu->jlu_exttm.et_flags |= ETF_MACHINE_ORIENTED | ETF_SUB_NOT_IN_FORMAT + | ETF_ZONE_SET | ETF_Z_FOR_UTC; + if (divisor == 1) { + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; + } else { + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; + } + jlu->jlu_exttm.et_nsec = jlu->jlu_exttm.et_nsec = tv.tv_usec * 1000; + } else if (jlu->jlu_format->lf_subsecond_field == field_name) { + jlu->jlu_exttm.et_flags &= ~(ETF_MICROS_SET | ETF_MILLIS_SET); + switch (jlu->jlu_format->lf_subsecond_unit.value()) { + case log_format::subsecond_unit::milli: + jlu->jlu_exttm.et_nsec = val * 1000000; + jlu->jlu_exttm.et_flags |= ETF_MILLIS_SET; + break; + case log_format::subsecond_unit::micro: + jlu->jlu_exttm.et_nsec = val * 1000; + jlu->jlu_exttm.et_flags |= ETF_MICROS_SET; + break; + case log_format::subsecond_unit::nano: + jlu->jlu_exttm.et_nsec = val; + jlu->jlu_exttm.et_flags |= ETF_NANOS_SET; + break; + } + jlu->jlu_exttm.et_flags |= ETF_SUB_NOT_IN_FORMAT; + } + if (!ypc->is_level(1) && !jlu->jlu_format->has_value_def(field_name)) { return 1; } @@ -1839,7 +1923,6 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len) { json_log_userdata* jlu = (json_log_userdata*) ypc->ypc_userdata; const intern_string_t field_name = ypc->get_path(); - struct exttm tm_out; struct timeval tv_out; auto frag = string_fragment::from_bytes(str, len); @@ -1848,7 +1931,7 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len) (const char*) str, len, jlu->jlu_format->get_timestamp_formats(), - &tm_out, + &jlu->jlu_exttm, tv_out); if (last == nullptr) { auto ls = jlu->jlu_format->lf_date_time.unlock(); @@ -1856,7 +1939,7 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len) (const char*) str, len, jlu->jlu_format->get_timestamp_formats(), - &tm_out, + &jlu->jlu_exttm, tv_out)) == nullptr) { @@ -1865,7 +1948,7 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len) 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; + auto new_flags = jlu->jlu_exttm.et_flags & DATE_TIME_SET_FLAGS; // It is unlikely a valid timestamp would lose much // precision. @@ -1875,7 +1958,7 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len) } } if (last != nullptr) { - jlu->jlu_format->lf_timestamp_flags = tm_out.et_flags; + jlu->jlu_format->lf_timestamp_flags = jlu->jlu_exttm.et_flags; jlu->jlu_base_line->set_time(tv_out); } } else if (jlu->jlu_format->elf_level_pointer.pp_value != nullptr) { @@ -1937,15 +2020,17 @@ rewrite_json_field(yajlpp_parse_context* ypc, char time_buf[64]; // TODO add a timeval kind to logline_value - if (jlu->jlu_line->is_time_skewed()) { + if (jlu->jlu_line->is_time_skewed() + || (jlu->jlu_format->lf_timestamp_flags + & (ETF_MICROS_SET | ETF_NANOS_SET | ETF_ZONE_SET))) + { struct timeval tv; - struct exttm tm; const auto* last = jlu->jlu_format->lf_date_time.scan( (const char*) str, len, jlu->jlu_format->get_timestamp_formats(), - &tm, + &jlu->jlu_exttm, tv); if (last == nullptr) { auto ls = jlu->jlu_format->lf_date_time.unlock(); @@ -1953,18 +2038,29 @@ rewrite_json_field(yajlpp_parse_context* ypc, (const char*) str, len, jlu->jlu_format->get_timestamp_formats(), - &tm, + &jlu->jlu_exttm, tv)) == nullptr) { jlu->jlu_format->lf_date_time.relock(ls); } } - sql_strftime(time_buf, sizeof(time_buf), tv, 'T'); + jlu->jlu_format->lf_date_time.ftime( + time_buf, + sizeof(time_buf), + jlu->jlu_format->get_timestamp_formats(), + jlu->jlu_exttm); } else { sql_strftime( time_buf, sizeof(time_buf), jlu->jlu_line->get_timeval(), 'T'); } + if (jlu->jlu_exttm.et_flags & ETF_ZONE_SET + && jlu->jlu_format->lf_date_time.dts_zoned_to_local) + { + jlu->jlu_exttm.et_flags &= ~ETF_Z_IS_UTC; + } + jlu->jlu_exttm.et_gmtoff + = jlu->jlu_format->lf_date_time.dts_local_offset_cache; jlu->jlu_format->jlf_line_values.lvv_values.emplace_back( jlu->jlu_format->get_value_meta(field_name, value_kind_t::VALUE_TEXT), @@ -2229,17 +2325,22 @@ external_log_format::get_subline(const logline& ll, struct line_range lr; ssize_t ts_len; char ts[64]; + struct exttm et; + ll.to_exttm(et); + et.et_nsec += jlu.jlu_exttm.et_nsec % 1000000; + et.et_gmtoff = jlu.jlu_exttm.et_gmtoff; + et.et_flags |= jlu.jlu_exttm.et_flags; if (!jfe.jfe_prefix.empty()) { this->json_append_to_cache(jfe.jfe_prefix); } if (jfe.jfe_ts_format.empty()) { - ts_len = sql_strftime( - ts, sizeof(ts), ll.get_timeval(), 'T'); + ts_len = this->lf_date_time.ftime( + ts, + sizeof(ts), + this->get_timestamp_formats(), + et); } else { - struct exttm et; - - ll.to_exttm(et); ts_len = ftime_fmt(ts, sizeof(ts), jfe.jfe_ts_format.c_str(), @@ -2759,6 +2860,7 @@ external_log_format::build(std::vector& errors) if (this->elf_type == elf_type_t::ELF_TYPE_JSON) { this->lf_multiline = true; this->lf_structured = true; + this->lf_formatted_lines = true; this->jlf_parse_context = std::make_shared(this->elf_name); this->jlf_yajl_handle.reset( diff --git a/src/log_format.hh b/src/log_format.hh index 90d16724..55da2028 100644 --- a/src/log_format.hh +++ b/src/log_format.hh @@ -562,6 +562,7 @@ public: uint8_t lf_mod_index{0}; bool lf_multiline{true}; bool lf_structured{false}; + bool lf_formatted_lines{false}; date_time_scanner lf_date_time; date_time_scanner lf_time_scanner; std::vector lf_pattern_locks; diff --git a/src/logfile_sub_source.cc b/src/logfile_sub_source.cc index 12b8d705..0c0e5ff4 100644 --- a/src/logfile_sub_source.cc +++ b/src/logfile_sub_source.cc @@ -319,7 +319,7 @@ logfile_sub_source::text_value_for_line(textview_curses& tc, this->lss_token_attrs.emplace_back(lr, SA_ORIGINAL_LINE.value()); } - if (!this->lss_token_line->is_continued() + if (!this->lss_token_line->is_continued() && !format->lf_formatted_lines && (this->lss_token_file->is_time_adjusted() || ((format->lf_timestamp_flags & ETF_ZONE_SET || format->lf_date_time.dts_default_zone != nullptr) diff --git a/src/ptimec.c b/src/ptimec.c index 725a341b..7ac648ba 100644 --- a/src/ptimec.c +++ b/src/ptimec.c @@ -145,8 +145,12 @@ main(int argc, char* argv[]) printf("}\n\n"); } + size_t default_format_index = 0; printf("struct ptime_fmt PTIMEC_FORMATS[] = {\n"); for (int lpc = 1; lpc < argc; lpc++) { + if (strcmp(argv[lpc], "%Y-%m-%dT%H:%M:%S") == 0) { + default_format_index = lpc - 1; + } printf(" { \"%s\", ptime_f%d, ftime_f%d },\n", argv[lpc], lpc, lpc); } printf("\n"); @@ -161,5 +165,8 @@ main(int argc, char* argv[]) printf(" nullptr\n"); printf("};\n"); + printf("\n"); + printf("size_t PTIMEC_DEFAULT_FMT_INDEX = %zu;\n", default_format_index); + return retval; } diff --git a/src/ptimec.hh b/src/ptimec.hh index 5f4a3598..527b33da 100644 --- a/src/ptimec.hh +++ b/src/ptimec.hh @@ -520,7 +520,8 @@ ptime_i(struct exttm* dst, const char* str, off_t& off_inout, ssize_t len) secs2tm(epoch, &dst->et_tm); dst->et_flags = ETF_DAY_SET | ETF_MONTH_SET | ETF_YEAR_SET | ETF_HOUR_SET | ETF_MINUTE_SET | ETF_SECOND_SET | ETF_MILLIS_SET - | ETF_MACHINE_ORIENTED | ETF_EPOCH_TIME | ETF_ZONE_SET; + | ETF_MACHINE_ORIENTED | ETF_EPOCH_TIME | ETF_ZONE_SET + | ETF_SUB_NOT_IN_FORMAT; return (epoch_ms > 0); } @@ -557,7 +558,8 @@ ptime_6(struct exttm* dst, const char* str, off_t& off_inout, ssize_t len) secs2tm(epoch, &dst->et_tm); dst->et_flags = ETF_DAY_SET | ETF_MONTH_SET | ETF_YEAR_SET | ETF_HOUR_SET | ETF_MINUTE_SET | ETF_SECOND_SET | ETF_MICROS_SET - | ETF_MACHINE_ORIENTED | ETF_EPOCH_TIME | ETF_ZONE_SET; + | ETF_MACHINE_ORIENTED | ETF_EPOCH_TIME | ETF_ZONE_SET + | ETF_SUB_NOT_IN_FORMAT | ETF_Z_FOR_UTC; return (epoch_us > 0); } @@ -1285,4 +1287,6 @@ extern struct ptime_fmt PTIMEC_FORMATS[]; extern const char* PTIMEC_FORMAT_STR[]; +extern size_t PTIMEC_DEFAULT_FMT_INDEX; + #endif diff --git a/src/time_formats.am b/src/time_formats.am index 141792d2..1716f276 100644 --- a/src/time_formats.am +++ b/src/time_formats.am @@ -25,8 +25,8 @@ TIME_FORMATS = \ "%Y-%m-%dT%H:%M:%S.%L%z" \ "%y-%m-%dT%H:%M:%S.%L%z" \ "%Y-%m-%dT%H:%M:%S%z" \ - "%Y-%m-%dT%H:%M:%S" \ "%Y-%m-%dT%H:%M:%S%z" \ + "%Y-%m-%dT%H:%M:%S" \ "%Y-%m-%dT%H:%M" \ "%Y/%m/%d %H:%M:%S %z" \ "%Y/%m/%d %H:%M:%S%z" \ diff --git a/test/expected/test_json_format.sh_4315a3d6124c14cbe3c474b6dbf4cc8720a9859f.out b/test/expected/test_json_format.sh_4315a3d6124c14cbe3c474b6dbf4cc8720a9859f.out index 9b7fbf17..2063d713 100644 --- a/test/expected/test_json_format.sh_4315a3d6124c14cbe3c474b6dbf4cc8720a9859f.out +++ b/test/expected/test_json_format.sh_4315a3d6124c14cbe3c474b6dbf4cc8720a9859f.out @@ -1,3 +1,3 @@ -2017-03-24T20:06:26.240 1.1.1.1 GET 200 443 /example/uri/5 -2017-03-24T20:12:47.764 1.1.1.1 GET 500 4433 /example/uri/5 -2017-03-24T20:15:31.694 1.1.1.1 GET 400 44345 /example/uri/5 +2017-03-24T20:06:26.240Z 1.1.1.1 GET 200 443 /example/uri/5 +2017-03-24T20:12:47.764Z 1.1.1.1 GET 500 4433 /example/uri/5 +2017-03-24T20:15:31.694Z 1.1.1.1 GET 400 44345 /example/uri/5 diff --git a/test/expected/test_json_format.sh_469f005b0708d629bc95f0c48a5e390f440c1fef.out b/test/expected/test_json_format.sh_469f005b0708d629bc95f0c48a5e390f440c1fef.out index 2976ed34..8a1d53c6 100644 --- a/test/expected/test_json_format.sh_469f005b0708d629bc95f0c48a5e390f440c1fef.out +++ b/test/expected/test_json_format.sh_469f005b0708d629bc95f0c48a5e390f440c1fef.out @@ -1,29 +1,29 @@ -[2013-09-06T20:00:48.124] ⋮ trace test +[2013-09-06T20:00:48.124817Z] ⋮ trace test -[2013-09-06T20:00:49.124] ⋮ Starting up service +[2013-09-06T20:00:49.124817Z] ⋮ Starting up service -[2013-09-06T22:00:49.124] ⋮ Shutting down service +[2013-09-06T22:00:49.124817Z] ⋮ Shutting down service user: steve@example.com -[2013-09-06T22:00:59.124] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... -[2013-09-06T22:00:59.124] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... -[2013-09-06T22:00:59.124] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... -[2013-09-06T22:00:59.124] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... -[2013-09-06T22:01:00.000] ⋮ Details... +[2013-09-06 22:01:00Z] ⋮ Details... -[2013-09-06T22:01:49.124] ⋮ 1 beat per second +[2013-09-06T22:01:49.124817Z] ⋮ 1 beat per second -[2013-09-06T22:01:49.124] ⋮ not looking good +[2013-09-06T22:01:49.124817Z] ⋮ not looking good -[2013-09-06T22:01:49.124] ⋮ looking bad +[2013-09-06T22:01:49.124817Z] ⋮ looking bad -[2013-09-06T22:01:49.124] ⋮ sooo bad +[2013-09-06T22:01:49.124817Z] ⋮ sooo bad -[2013-09-06T22:01:49.124] ⋮ shoot +[2013-09-06T22:01:49.124817Z] ⋮ shoot  obj: { "field1" : "hi", "field2": 2 }  arr: ["hi", {"sub1": true}] diff --git a/test/expected/test_json_format.sh_7724d1a96d74d4418dd44d7416270f9bb64b2564.out b/test/expected/test_json_format.sh_7724d1a96d74d4418dd44d7416270f9bb64b2564.out index 39538c52..16d7261e 100644 --- a/test/expected/test_json_format.sh_7724d1a96d74d4418dd44d7416270f9bb64b2564.out +++ b/test/expected/test_json_format.sh_7724d1a96d74d4418dd44d7416270f9bb64b2564.out @@ -1,29 +1,29 @@ -2013-09-06T20:00:48.124000Z TRACE trace test +2013-09-06T20:00:48.124817Z TRACE trace test @fields: { "lvl": "TRACE", "msg": "trace test"} -2013-09-06T20:00:49.124000Z INFO Starting up service +2013-09-06T20:00:49.124817Z INFO Starting up service @fields: { "lvl": "INFO", "msg": "Starting up service"} -2013-09-06T22:00:49.124000Z INFO Shutting down service +2013-09-06T22:00:49.124817Z INFO Shutting down service @fields/user: steve@example.com @fields: { "lvl": "INFO", "msg": "Shutting down service", "user": "steve@example.com"} -2013-09-06T22:00:59.124000Z DEBUG5 Details... +2013-09-06T22:00:59.124817Z DEBUG5 Details... @fields: { "lvl": "DEBUG5", "msg": "Details..."} -2013-09-06T22:00:59.124000Z DEBUG4 Details... +2013-09-06T22:00:59.124817Z DEBUG4 Details... @fields: { "lvl": "DEBUG4", "msg": "Details..."} -2013-09-06T22:00:59.124000Z DEBUG3 Details... +2013-09-06T22:00:59.124817Z DEBUG3 Details... @fields: { "lvl": "DEBUG3", "msg": "Details..."} -2013-09-06T22:00:59.124000Z DEBUG2 Details... +2013-09-06T22:00:59.124817Z DEBUG2 Details... @fields: { "lvl": "DEBUG2", "msg": "Details..."} -2013-09-06T22:00:59.124000Z DEBUG Details... +2013-09-06T22:00:59.124817Z DEBUG Details... @fields: { "lvl": "DEBUG", "msg": "Details..."} -2013-09-06T22:01:49.124000Z STATS 1 beat per second +2013-09-06T22:01:49.124817Z STATS 1 beat per second @fields: { "lvl": "STATS", "msg": "1 beat per second"} -2013-09-06T22:01:49.124000Z WARNING not looking good +2013-09-06T22:01:49.124817Z WARNING not looking good  @fields: { "lvl": "WARNING", "msg": "not looking good"} -2013-09-06T22:01:49.124000Z ERROR looking bad +2013-09-06T22:01:49.124817Z ERROR looking bad  @fields: { "lvl": "ERROR", "msg": "looking bad"} -2013-09-06T22:01:49.124000Z CRITICAL sooo bad +2013-09-06T22:01:49.124817Z CRITICAL sooo bad  @fields: { "lvl": "CRITICAL", "msg": "sooo bad"} -2013-09-06T22:01:49.124000Z FATAL shoot +2013-09-06T22:01:49.124817Z FATAL shoot  @fields/trace#: line:1  @fields/trace#: line:2  @fields: { "lvl": "FATAL", "msg": "shoot", "trace": ["line:1", "line:2"]} diff --git a/test/expected/test_json_format.sh_7c6529f6bf4a0cb565f5665fdcba032f0ae1ebbe.out b/test/expected/test_json_format.sh_7c6529f6bf4a0cb565f5665fdcba032f0ae1ebbe.out index 173ba542..72f625aa 100644 --- a/test/expected/test_json_format.sh_7c6529f6bf4a0cb565f5665fdcba032f0ae1ebbe.out +++ b/test/expected/test_json_format.sh_7c6529f6bf4a0cb565f5665fdcba032f0ae1ebbe.out @@ -1,12 +1,12 @@ -2013-09-06T20:00:48.124000Z TRACE trace test +2013-09-06T20:00:48.124817Z TRACE trace test @fields: { "lvl": "TRACE", "msg": "trace test"} -2013-09-06T20:00:49.124000Z INFO Starting up service +2013-09-06T20:00:49.124817Z INFO Starting up service @fields: { "lvl": "INFO", "msg": "Starting up service"} [offset: 186] {"ts": "2013-09-06T22:00:49.124817Z", "@fields": { "lvl": "INFO", "msg": "Shutting down service\nline2\nline3\nline4\nline5\nline6\nline7\nline8\nline9\nline10 parse error: premature EOF {"ts": "2013-09-06T22:00:49.124 (right here) ------^ -2013-09-06T22:00:59.124000Z DEBUG5 Details... +2013-09-06T22:00:59.124817Z DEBUG5 Details... @fields: { "lvl": "DEBUG5", "msg": "Details..."} -2013-09-06T22:00:59.222000Z DEBUG4 Details... +2013-09-06T22:00:59.222222Z DEBUG4 Details... @fields: { "lvl": "DEBUG4", "msg": "Details..."} diff --git a/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out b/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out index 197667f9..4656a00d 100644 --- a/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out +++ b/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out @@ -1,6 +1,6 @@ -2013-09-06T20:00:48.124000Z TRACE trace test +2013-09-06T20:00:48.124817Z TRACE trace test @fields: { "lvl": "TRACE", "msg": "trace test"} -2013-09-06T20:00:49.124000Z INFO Starting up service +2013-09-06T20:00:49.124817Z INFO Starting up service @fields: { "lvl": "INFO", "msg": "Starting up service"} [offset: 186] {"ts": "2013-09-06T22:00:49.124817Z", "@fields": { "lvl": "INFO", "msg": parse error: premature EOF diff --git a/test/expected/test_json_format.sh_84a71e94dc34661a70bb9015b67ba00e93e9cfb5.out b/test/expected/test_json_format.sh_84a71e94dc34661a70bb9015b67ba00e93e9cfb5.out index 42d978a9..474ad837 100644 --- a/test/expected/test_json_format.sh_84a71e94dc34661a70bb9015b67ba00e93e9cfb5.out +++ b/test/expected/test_json_format.sh_84a71e94dc34661a70bb9015b67ba00e93e9cfb5.out @@ -1,2 +1,2 @@ -2018-08-21 14:04:21.221000 38708007 medusa-GpsLocator.service python[184] FATAL GPS Reference longitude: 7.358143333 -2018-08-21 14:04:21.221000 38708007 medusa-GpsLocator.service python[184] INFO GPS Reference latitude: 46.908706667 +2018-08-21T14:04:21.221373Z 38708007 medusa-GpsLocator.service python[184] FATAL GPS Reference longitude: 7.358143333 +2018-08-21T14:04:21.221373Z 38708007 medusa-GpsLocator.service python[184] INFO GPS Reference latitude: 46.908706667 diff --git a/test/expected/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out b/test/expected/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out index 7cb7336c..6de63a2e 100644 --- a/test/expected/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out +++ b/test/expected/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out @@ -1,4 +1,4 @@ -[-09-06T22:00:49.124] INFO Shutting down service +[-09-06T22:00:49.124817Z] INFO Shutting down service user: steve@example.com diff --git a/test/expected/test_json_format.sh_a06b3cdd46b387e72d6faa4cce648b8b11ae870b.out b/test/expected/test_json_format.sh_a06b3cdd46b387e72d6faa4cce648b8b11ae870b.out index f1f02034..264a35e2 100644 --- a/test/expected/test_json_format.sh_a06b3cdd46b387e72d6faa4cce648b8b11ae870b.out +++ b/test/expected/test_json_format.sh_a06b3cdd46b387e72d6faa4cce648b8b11ae870b.out @@ -1,29 +1,29 @@ -[2013-09-06T20:00:48.124000Z] ⋮ trace testbork bork bork +[2013-09-06T20:00:48.124817Z] ⋮ trace testbork bork bork -[2013-09-06T20:00:49.124000Z] ⋮ Starting up servicebork bork bork +[2013-09-06T20:00:49.124817Z] ⋮ Starting up servicebork bork bork -[2013-09-06T22:00:49.124000Z] ⋮ Shutting down servicebork bork bork +[2013-09-06T22:00:49.124817Z] ⋮ Shutting down servicebork bork bork user: mailto:steve@example.com -[2013-09-06T22:00:59.124000Z] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... bork bork bork -[2013-09-06T22:00:59.124000Z] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... bork bork bork -[2013-09-06T22:00:59.124000Z] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... bork bork bork -[2013-09-06T22:00:59.124000Z] ⋮ Details... +[2013-09-06T22:00:59.124817Z] ⋮ Details... bork bork bork -[2013-09-06T22:01:00.000000Z] ⋮ Details...bork bork bork +[2013-09-06 22:01:00Z] ⋮ Details...bork bork bork -[2013-09-06T22:01:49.124000Z] ⋮ 1 beat per secondbork bork bork +[2013-09-06T22:01:49.124817Z] ⋮ 1 beat per secondbork bork bork -[2013-09-06T22:01:49.124000Z] ⋮ not looking goodbork bork bork +[2013-09-06T22:01:49.124817Z] ⋮ not looking goodbork bork bork -[2013-09-06T22:01:49.124000Z] ⋮ looking badbork bork bork +[2013-09-06T22:01:49.124817Z] ⋮ looking badbork bork bork -[2013-09-06T22:01:49.124000Z] ⋮ sooo badbork bork bork +[2013-09-06T22:01:49.124817Z] ⋮ sooo badbork bork bork diff --git a/test/expected/test_json_format.sh_c1a23804c39b0f74642286d69865ee9d0961a58a.out b/test/expected/test_json_format.sh_c1a23804c39b0f74642286d69865ee9d0961a58a.out index 889eb99d..dc777533 100644 --- a/test/expected/test_json_format.sh_c1a23804c39b0f74642286d69865ee9d0961a58a.out +++ b/test/expected/test_json_format.sh_c1a23804c39b0f74642286d69865ee9d0961a58a.out @@ -1,2 +1,2 @@ -2022-09-24T00:00:09.484 Hello, World! -2022-09-24T00:00:19.222 Goodbye, World! +2022-09-24T00:00:09.484000000Z Hello, World! +2022-09-24T00:00:19.222000123Z Goodbye, World! diff --git a/test/expected/test_json_format.sh_d7362cffc8335c2fe6b6527315de59bd6f5dcc7f.out b/test/expected/test_json_format.sh_d7362cffc8335c2fe6b6527315de59bd6f5dcc7f.out index 9a1c8824..c65a346b 100644 --- a/test/expected/test_json_format.sh_d7362cffc8335c2fe6b6527315de59bd6f5dcc7f.out +++ b/test/expected/test_json_format.sh_d7362cffc8335c2fe6b6527315de59bd6f5dcc7f.out @@ -1,3 +1,3 @@ -2017-03-24T16:06:26.240 1.1.1.1 GET 200 443 /example/uri/5 -2017-03-24T16:12:47.764 1.1.1.1 GET 500 4433 /example/uri/5 -2017-03-24T16:15:31.694 1.1.1.1 GET 400 44345 /example/uri/5 +2017-03-24T16:06:26.240-0400 1.1.1.1 GET 200 443 /example/uri/5 +2017-03-24T16:12:47.764-0400 1.1.1.1 GET 500 4433 /example/uri/5 +2017-03-24T16:15:31.694-0400 1.1.1.1 GET 400 44345 /example/uri/5 diff --git a/test/expected/test_json_format.sh_f740026626ab554dacb249762d8be7d6539b8c6e.out b/test/expected/test_json_format.sh_f740026626ab554dacb249762d8be7d6539b8c6e.out index 31775359..d1cb8737 100644 --- a/test/expected/test_json_format.sh_f740026626ab554dacb249762d8be7d6539b8c6e.out +++ b/test/expected/test_json_format.sh_f740026626ab554dacb249762d8be7d6539b8c6e.out @@ -1,2 +1,2 @@ -[2013-09-06T20:00:49.124] ⋮ Starting up service +[2013-09-06T20:00:49.124817Z] ⋮ Starting up service diff --git a/test/expected/test_json_format.sh_fe19b7ebd349cd689b3f5c22618eab5ce995e68e.out b/test/expected/test_json_format.sh_fe19b7ebd349cd689b3f5c22618eab5ce995e68e.out index 325af1fd..87d2dd4f 100644 --- a/test/expected/test_json_format.sh_fe19b7ebd349cd689b3f5c22618eab5ce995e68e.out +++ b/test/expected/test_json_format.sh_fe19b7ebd349cd689b3f5c22618eab5ce995e68e.out @@ -1,4 +1,4 @@ --09-06T22:00:49.124 INFO Shutting down service +-09-06T22:00:49.124817Z INFO Shutting down service @fields/user: steve@example.com @fields: { "lvl": "INFO", "msg": "Shutting down service", "user": "steve@example.com"} diff --git a/test/logfile_json_subsec.json b/test/logfile_json_subsec.json index 3ddc190d..c5726510 100644 --- a/test/logfile_json_subsec.json +++ b/test/logfile_json_subsec.json @@ -1,2 +1,2 @@ {"instant":{"epochSecond": 1663977609,"nanoOfSecond": 484000000}, "msg": "Hello, World!"} -{"instant":{"epochSecond": 1663977619,"nanoOfSecond": 222000000}, "msg": "Goodbye, World!"} +{"instant":{"epochSecond": 1663977619,"nanoOfSecond": 222000123}, "msg": "Goodbye, World!"}