diff --git a/NEWS b/NEWS index 4aa75307..8ae33db1 100644 --- a/NEWS +++ b/NEWS @@ -38,6 +38,7 @@ lnav v0.8.1: executions. * Added a "/ui/clock-format" configuration option that controls the time format in the top-left corner. + * Added support for TAI64 timestamps (http://cr.yp.to/libtai/tai64.html). Interface Changes: * The 'o/O' hotkeys have been reassigned to navigate through log diff --git a/src/Makefile.am b/src/Makefile.am index bbf1d33d..54d9a0bb 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -36,6 +36,7 @@ init-sql.c: bin2c $(BIN2C_V)./bin2c -z -c $< $@ TIME_FORMATS = \ + "@%@" \ "%Y-%m-%d %H:%M:%S" \ "%Y-%m-%d %H:%M" \ "%Y-%m-%dT%H:%M:%S.%f%z" \ diff --git a/src/lnav_util.cc b/src/lnav_util.cc index c4f8cb36..67c6b98d 100644 --- a/src/lnav_util.cc +++ b/src/lnav_util.cc @@ -38,8 +38,6 @@ #include #include -#include - #include #include "auto_fd.hh" @@ -226,12 +224,6 @@ std::string precise_time_ago(const struct timeval &tv, bool convert_local) } } -/* XXX figure out how to do this with the template */ -void sqlite_close_wrapper(void *mem) -{ - sqlite3_close((sqlite3 *)mem); -} - std::string get_current_dir(void) { char cwd[FILENAME_MAX]; @@ -561,7 +553,8 @@ const char *date_time_scanner::scan(const char *time_dest, if (tm_out->et_tm.tm_year < 70) { tm_out->et_tm.tm_year = 80; } - if (convert_local && this->dts_local_time) { + if (convert_local && + (this->dts_local_time || tm_out->et_flags & ETF_EPOCH_TIME)) { time_t gmt = tm2sec(&tm_out->et_tm); this->to_localtime(gmt, *tm_out); @@ -584,7 +577,8 @@ const char *date_time_scanner::scan(const char *time_dest, if (tm_out->et_tm.tm_year < 70) { tm_out->et_tm.tm_year = 80; } - if (convert_local && this->dts_local_time) { + if (convert_local && + (this->dts_local_time || tm_out->et_flags & ETF_EPOCH_TIME)) { time_t gmt = tm2sec(&tm_out->et_tm); this->to_localtime(gmt, *tm_out); diff --git a/src/lnav_util.hh b/src/lnav_util.hh index 39e4cb65..df646733 100644 --- a/src/lnav_util.hh +++ b/src/lnav_util.hh @@ -168,9 +168,6 @@ object_field_t object_field(UnaryFunction &func, return object_field_t(func, mem); } -/* XXX figure out how to do this with the template */ -void sqlite_close_wrapper(void *mem); - std::string get_current_dir(void); bool change_to_parent_dir(void); diff --git a/src/log_format.cc b/src/log_format.cc index 662afa65..9580b467 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -280,6 +280,7 @@ const char *log_format::log_scanf(const char *line, if (retval) { this->lf_fmt_lock = curr_fmt; + this->lf_timestamp_flags = tm_out->et_flags; done = true; } } @@ -712,6 +713,7 @@ log_format::scan_result_t external_log_format::scan(std::vector &dst, continue; } + this->lf_timestamp_flags = log_time_tm.et_flags; if (level_cap != NULL && level_cap->c_begin != -1) { pcre_context_static<128> pc_level; pcre_input pi_level(pi.get_substr_start(level_cap), @@ -979,6 +981,7 @@ static int read_json_field(yajlpp_parse_context *ypc, const unsigned char *str, if (jlu->jlu_format->lf_timestamp_field == field_name) { 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); } else if (jlu->jlu_format->elf_level_field == field_name) { diff --git a/src/log_format.hh b/src/log_format.hh index aad0dba9..44b78773 100644 --- a/src/log_format.hh +++ b/src/log_format.hh @@ -669,7 +669,8 @@ public: log_format() : lf_mod_index(0), lf_fmt_lock(-1), - lf_timestamp_field(intern_string::lookup("timestamp", -1)) { + lf_timestamp_field(intern_string::lookup("timestamp", -1)), + lf_timestamp_flags(0) { }; virtual ~log_format() { }; @@ -779,6 +780,7 @@ public: int lf_fmt_lock; intern_string_t lf_timestamp_field; std::vector lf_timestamp_format; + int lf_timestamp_flags; std::map lf_action_defs; std::vector lf_value_stats; protected: diff --git a/src/log_format_impls.cc b/src/log_format_impls.cc index 57da3d9a..cbaa9a64 100644 --- a/src/log_format_impls.cc +++ b/src/log_format_impls.cc @@ -87,6 +87,7 @@ class generic_log_format : public log_format { static pcre_format *get_pcre_log_formats() { static pcre_format log_fmt[] = { + pcre_format("^(?@[0-9a-zA-Z]{16,24})(.*)"), pcre_format("^(?[\\dTZ: +/\\-,\\.-]+)([^:]+)"), pcre_format("^(?[\\w:+/\\.-]+) \\[\\w (.*)"), pcre_format("^(?[\\w:,/\\.-]+) (.*)"), diff --git a/src/logfile_sub_source.cc b/src/logfile_sub_source.cc index 22be4b2e..f86c0101 100644 --- a/src/logfile_sub_source.cc +++ b/src/logfile_sub_source.cc @@ -46,7 +46,6 @@ bookmark_type_t logfile_sub_source::BM_FILES(""); logfile_sub_source::logfile_sub_source() : lss_flags(0), lss_token_file(NULL), - lss_token_date_end(0), lss_min_log_level(logline::LEVEL_UNKNOWN), lss_index_delegate(NULL), lss_longest_line(0) @@ -118,54 +117,82 @@ void logfile_sub_source::text_value_for_line(textview_curses &tc, return; } + this->lss_token_attrs.clear(); + this->lss_token_values.clear(); this->lss_share_manager.invalidate_refs(); this->lss_token_value = this->lss_token_file->read_line(this->lss_token_line); - this->lss_token_date_end = 0; + log_format *format = this->lss_token_file->get_format(); + value_out = this->lss_token_value; if (this->lss_flags & F_SCRUB) { - log_format *lf = this->lss_token_file->get_format(); - - lf->scrub(value_out); + format->scrub(value_out); } - if (this->lss_token_file->is_time_adjusted() && - !this->lss_token_line->is_continued()) { - log_format *format = this->lss_token_file->get_format(); + if (!this->lss_token_line->is_continued()) { + shared_buffer_ref sbr; - if (format->lf_date_time.dts_fmt_lock != -1) { - shared_buffer_ref sbr; - std::vector line_values; - struct timeval adjusted_time; - struct tm adjusted_tm; - string_attrs_t sa; - char buffer[128]; - const char *fmt; - - fmt = PTIMEC_FORMAT_STR[format->lf_date_time.dts_fmt_lock]; - adjusted_time = this->lss_token_line->get_timeval(); - strftime(buffer, sizeof(buffer), - fmt, - gmtime_r(&adjusted_time.tv_sec, &adjusted_tm)); - - sbr.share(this->lss_share_manager, - (char *)this->lss_token_value.c_str(), this->lss_token_value.size()); - format->annotate(sbr, sa, line_values); + sbr.share(this->lss_share_manager, + (char *)this->lss_token_value.c_str(), this->lss_token_value.size()); + format->annotate(sbr, this->lss_token_attrs, this->lss_token_values); + if ((this->lss_token_file->is_time_adjusted() || + format->lf_timestamp_flags & ETF_MACHINE_ORIENTED) && + format->lf_date_time.dts_fmt_lock != -1) { struct line_range time_range; - time_range = find_string_attr_range(sa, &logline::L_TIMESTAMP); - if (time_range.lr_start != -1) { + time_range = find_string_attr_range( + this->lss_token_attrs, &logline::L_TIMESTAMP); + if (time_range.is_valid()) { + struct timeval adjusted_time; + struct tm adjusted_tm; + char buffer[128]; + const char *fmt; + + if (format->lf_timestamp_flags & ETF_MACHINE_ORIENTED) { + format->lf_date_time.convert_to_timeval( + &this->lss_token_value.c_str()[time_range.lr_start], + time_range.length(), + adjusted_time); + fmt = "%Y-%m-%d %H:%M:%S."; + } + else { + fmt = PTIMEC_FORMAT_STR[format->lf_date_time.dts_fmt_lock]; + adjusted_time = this->lss_token_line->get_timeval(); + } + strftime(buffer, sizeof(buffer), + fmt, + gmtime_r(&adjusted_time.tv_sec, &adjusted_tm)); + + if (format->lf_timestamp_flags & ETF_MACHINE_ORIENTED) { + size_t buffer_len = strlen(buffer); + + snprintf(&buffer[buffer_len], sizeof(buffer) - buffer_len, + "%06d", + adjusted_time.tv_usec); + } + const char *last = value_out.c_str(); - int len = strlen(buffer); + ssize_t len = strlen(buffer); if ((last[time_range.lr_start + len] == '.' || - last[time_range.lr_start + len] == ',') && + last[time_range.lr_start + len] == ',') && len + 4 <= time_range.length()) { - snprintf(&buffer[len], sizeof(buffer) - len, - ".%03d", - this->lss_token_line->get_millis()); + len = snprintf(&buffer[len], sizeof(buffer) - len, + ".%03d", + this->lss_token_line->get_millis()); + } + + if (len > time_range.length()) { + ssize_t padding = len - time_range.length(); + + value_out.insert(time_range.lr_start, + padding, + ' '); + shift_string_attrs(this->lss_token_attrs, + time_range.lr_start, + padding); } value_out.replace(time_range.lr_start, strlen(buffer), @@ -213,7 +240,7 @@ void logfile_sub_source::text_attrs_for_line(textview_curses &lv, int time_offset_end = 0; int attrs = 0; - value_out.clear(); + value_out = this->lss_token_attrs; switch (this->lss_token_line->get_msg_level()) { case logline::LEVEL_FATAL: case logline::LEVEL_CRITICAL: @@ -240,22 +267,13 @@ void logfile_sub_source::text_attrs_for_line(textview_curses &lv, attrs |= A_UNDERLINE; } - log_format *format = this->lss_token_file->get_format(); - std::vector line_values; - - if (!this->lss_token_line->is_continued()) { - shared_buffer_ref sbr; - - sbr.share(this->lss_share_manager, - (char *)this->lss_token_value.c_str(), this->lss_token_value.size()); - format->annotate(sbr, value_out, line_values); - } + std::vector &line_values = this->lss_token_values; lr.lr_start = 0; lr.lr_end = this->lss_token_value.length(); value_out.push_back(string_attr(lr, &textview_curses::SA_ORIGINAL_LINE)); - lr.lr_start = time_offset_end + this->lss_token_date_end; + lr.lr_start = time_offset_end; lr.lr_end = -1; value_out.push_back(string_attr(lr, &view_curses::VC_STYLE, attrs)); @@ -275,16 +293,7 @@ void logfile_sub_source::text_attrs_for_line(textview_curses &lv, } if (this->lss_files.size() > 1) { - for (string_attrs_t::iterator iter = value_out.begin(); - iter != value_out.end(); - ++iter) { - struct line_range *existing_lr = &iter->sa_range; - - existing_lr->lr_start += 1; - if (existing_lr->lr_end != -1) { - existing_lr->lr_end += 1; - } - } + shift_string_attrs(value_out, 0, 1); lr.lr_start = 0; lr.lr_end = 1; diff --git a/src/logfile_sub_source.hh b/src/logfile_sub_source.hh index 5ff8fea8..6411ba27 100644 --- a/src/logfile_sub_source.hh +++ b/src/logfile_sub_source.hh @@ -593,8 +593,9 @@ private: logfile * lss_token_file; std::string lss_token_value; + string_attrs_t lss_token_attrs; + std::vector lss_token_values; shared_buffer lss_share_manager; - int lss_token_date_end; logfile::iterator lss_token_line; std::pair lss_line_size_cache[LINE_SIZE_CACHE_SIZE]; logline::level_t lss_min_log_level; diff --git a/src/ptimec.cc b/src/ptimec.cc index 84302991..6ffae691 100644 --- a/src/ptimec.cc +++ b/src/ptimec.cc @@ -78,6 +78,10 @@ int main(int argc, char *argv[]) } arg += 1; break; + case '@': + printf(" if (!ptime_at(dst, str, off, len)) return false;\n"); + arg += 1; + break; default: printf(" if (!ptime_%c(dst, str, off, len)) return false;\n", arg[index + 1]); diff --git a/src/ptimec.hh b/src/ptimec.hh index 8ca632fc..6ea1222c 100644 --- a/src/ptimec.hh +++ b/src/ptimec.hh @@ -46,12 +46,16 @@ enum exttm_bits_t { ETB_YEAR_SET, ETB_MONTH_SET, ETB_DAY_SET, + ETB_MACHINE_ORIENTED, + ETB_EPOCH_TIME, }; enum exttm_flags_t { ETF_YEAR_SET = (1L << ETB_YEAR_SET), ETF_MONTH_SET = (1L << ETB_MONTH_SET), ETF_DAY_SET = (1L << ETB_DAY_SET), + ETF_MACHINE_ORIENTED = (1L << ETB_MACHINE_ORIENTED), + ETF_EPOCH_TIME = (1L << ETB_EPOCH_TIME), }; struct exttm { @@ -502,6 +506,61 @@ inline bool ptime_char(char val, const char *str, off_t &off_inout, ssize_t len) return true; } +template +inline bool ptime_hex_to_quad(T &value_inout, const char quad) +{ + value_inout <<= 4; + if ('0' <= quad && quad <= '9') { + value_inout |= ((quad - '0') & 0x0f); + } + else if ('a' <= quad && quad <= 'f') { + value_inout |= 10 + ((quad - 'a') & 0x0f); + } + else if ('A' <= quad && quad <= 'F') { + value_inout |= 10 + ((quad - 'A') & 0x0f); + } + else { + return false; + } + + return true; +} + +inline bool ptime_at(struct exttm *dst, const char *str, off_t &off_inout, ssize_t len) +{ + PTIME_CONSUME(16, { + int64_t secs = 0; + + for (int lpc = 0; lpc < 16; lpc++) { + char quad = str[off_inout + lpc]; + + if (!ptime_hex_to_quad(secs, quad)) { + return false; + } + } + dst->et_nsec = 0; + + time_t small_secs = secs - 4611686018427387914ULL; + secs2tm(&small_secs, &dst->et_tm); + }); + + if ((len - off_inout) == 8) { + PTIME_CONSUME(8, { + for (int lpc = 0; lpc < 8; lpc++) { + char quad = str[off_inout + lpc]; + + if (!ptime_hex_to_quad(dst->et_nsec, quad)) { + return false; + } + } + }); + } + + dst->et_flags |= ETF_MACHINE_ORIENTED|ETF_EPOCH_TIME; + + return true; +} + typedef bool (*ptime_func)(struct exttm *dst, const char *str, off_t &off, ssize_t len); bool ptime_fmt(const char *fmt, struct exttm *dst, const char *str, off_t &off, ssize_t len); diff --git a/src/ptimec_rt.cc b/src/ptimec_rt.cc index e4284594..b8b8b0da 100644 --- a/src/ptimec_rt.cc +++ b/src/ptimec_rt.cc @@ -92,6 +92,7 @@ bool ptime_fmt(const char *fmt, struct exttm *dst, const char *str, off_t &off, FMT_CASE('Y', Y); FMT_CASE('y', y); FMT_CASE('z', z); + FMT_CASE('@', at); } } else { diff --git a/src/sql_util.cc b/src/sql_util.cc index 185a5783..5eabc757 100644 --- a/src/sql_util.cc +++ b/src/sql_util.cc @@ -707,3 +707,9 @@ int guess_type_from_pcre(const string &pattern, const char **collator) return SQLITE3_TEXT; } } + +/* XXX figure out how to do this with the template */ +void sqlite_close_wrapper(void *mem) +{ + sqlite3_close((sqlite3 *)mem); +} diff --git a/src/sql_util.hh b/src/sql_util.hh index 3dcf6dab..c906e2dd 100644 --- a/src/sql_util.hh +++ b/src/sql_util.hh @@ -84,4 +84,7 @@ void sql_execute_script(sqlite3 *db, int guess_type_from_pcre(const std::string &pattern, const char **collator); +/* XXX figure out how to do this with the template */ +void sqlite_close_wrapper(void *mem); + #endif diff --git a/src/view_curses.hh b/src/view_curses.hh index 2aabfb9a..a81bb21e 100644 --- a/src/view_curses.hh +++ b/src/view_curses.hh @@ -312,6 +312,20 @@ inline void remove_string_attr(string_attrs_t &sa, const struct line_range &lr) } } +inline void shift_string_attrs(string_attrs_t &sa, int32_t start, int32_t amount) +{ + for (string_attrs_t::iterator iter = sa.begin(); iter != sa.end(); ++iter) { + struct line_range *existing_lr = &iter->sa_range; + + if (existing_lr->lr_start >= start) { + existing_lr->lr_start += amount; + } + if (existing_lr->lr_end != -1 && start < existing_lr->lr_end) { + existing_lr->lr_end += amount; + } + } +} + /** * A line that has attributes. */ diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index f5a73a48..1acf37e6 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -7,6 +7,14 @@ add_executable(test_reltime test_reltime.cc ../src/relative_time.cc ../src/pcrepp.cc ../src/lnav_log.cc) +add_executable(test_date_time_scanner test_date_time_scanner.cc + ../src/lnav_util.cc + ../../lbuild/src/time_fmts.cc + ../src/ptimec_rt.cc + ../src/pcrepp.cc + ../src/lnav_log.cc + ../src/spookyhash/SpookyV2.cpp) link_directories(/opt/local/lib) target_link_libraries(test_pcrepp /opt/local/lib/libpcre.a) target_link_libraries(test_reltime /opt/local/lib/libpcre.a) +target_link_libraries(test_date_time_scanner /opt/local/lib/libpcre.a) diff --git a/test/Makefile.am b/test/Makefile.am index 2df97049..62143d7f 100644 --- a/test/Makefile.am +++ b/test/Makefile.am @@ -271,6 +271,7 @@ dist_noinst_DATA = \ logfile_syslog.2 \ logfile_syslog_with_access_log.0 \ logfile_syslog_with_mixed_times.0 \ + logfile_tai64n.0 \ logfile_tcf.0 \ logfile_tcf.1 \ logfile_tcsh_history.0 \ diff --git a/test/logfile_tai64n.0 b/test/logfile_tai64n.0 new file mode 100644 index 00000000..0e195bc0 --- /dev/null +++ b/test/logfile_tai64n.0 @@ -0,0 +1,10 @@ +@40000000433225833b6e1a8c tcpserver: status: 5/30 +@40000000433225833b6e2644 tcpserver: pid 26162 from 194.206.24.40 +@40000000433225840c85ba04 tcpserver: ok 26162 a.mx.jms1.net:209.114.200.128:25 :194.206.24.40::1521 +@40000000433225840c8f0cbc rblsmtpd: 194.206.24.40 pid 26162: 451 We do not accept mail from IP addresses without reverse DNS. +@40000000433225852a9ada4c tcpserver: status: 6/30 +@40000000433225852a9ae604 tcpserver: pid 26163 from 193.123.2.227 +@40000000433225852aa997bc tcpserver: ok 26163 a.mx.jms1.net:209.114.200.128:25 pixelwww.pixelpower.com:193.123.2.227::4232 +@40000000433225852aa9a374 rblsmtpd: 193.123.2.227 pid 26163: 553 Sent mail to honeypot qmmycemglyiuq@delete.net on 2005-01-04 +@400000004332258538eae27c tcpserver: end 26163 status 0 +@400000004332258538eaea4c tcpserver: status: 5/30 diff --git a/test/test_date_time_scanner.cc b/test/test_date_time_scanner.cc index eda538ba..03b22b55 100644 --- a/test/test_date_time_scanner.cc +++ b/test/test_date_time_scanner.cc @@ -41,11 +41,27 @@ static const char *BAD_TIMES[] = { "2013-22-01 12:01:22", "2013-00-01 12:01:22", + "@4000000043", + NULL }; int main(int argc, char *argv[]) { + { + date_time_scanner dts; + struct timeval tv; + + dts.convert_to_timeval("@40000000433225833b6e1a8c", -1, tv); + assert(tv.tv_sec == 1127334665); + assert(tv.tv_usec == 997071); + + memset(&tv, 0, sizeof(tv)); + dts.convert_to_timeval("@4000000043322583", -1, tv); + assert(tv.tv_sec == 1127334665); + assert(tv.tv_usec == 0); + } + for (int lpc = 0; BAD_TIMES[lpc]; lpc++) { date_time_scanner dts; struct timeval tv; diff --git a/test/test_logfile.sh b/test/test_logfile.sh index a102bb1f..01b935d2 100644 --- a/test/test_logfile.sh +++ b/test/test_logfile.sh @@ -115,6 +115,21 @@ Jul 20 22:59:29 2009 -- 000 Jul 20 22:59:29 2009 -- 000 EOF +run_test ./drive_logfile -t -f generic_log ${srcdir}/logfile_tai64n.0 + +check_output "tai64n timestamps interpreted incorrectly?" <