diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index be1fd3c0..1f7ee8a3 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -96,5 +96,5 @@ set(diag_STAT_SRCS set(lnav_SRCS lnav.cc) -include_directories(../../lbuild/src) +include_directories(../../lbuild/src /opt/local/include) add_executable(lnav ${lnav_SRCS} ${diag_STAT_SRCS}) diff --git a/src/Makefile.am b/src/Makefile.am index b35cd8a8..00881860 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -36,6 +36,7 @@ TIME_FORMATS = \ "%m/%d/%Y %I:%M:%S:%L %p %Z" \ "%N/%e/%Y %l:%M:%S %p" \ "%m%d %H:%M:%S" \ + "%H:%M:%S" \ "%M:%S" time_fmts.cc: ptimec diff --git a/src/Makefile.in b/src/Makefile.in index 0510a505..00af9b1a 100644 --- a/src/Makefile.in +++ b/src/Makefile.in @@ -370,6 +370,7 @@ TIME_FORMATS = \ "%m/%d/%Y %I:%M:%S:%L %p %Z" \ "%N/%e/%Y %l:%M:%S %p" \ "%m%d %H:%M:%S" \ + "%H:%M:%S" \ "%M:%S" AM_LDFLAGS = \ diff --git a/src/chunky_index.hh b/src/chunky_index.hh index 0d4ceccf..9082e8be 100644 --- a/src/chunky_index.hh +++ b/src/chunky_index.hh @@ -32,6 +32,7 @@ #ifndef __chunky_index_hh #define __chunky_index_hh +#include #include #include @@ -43,6 +44,48 @@ template class chunky_index { public: + + class iterator { + public: + typedef std::random_access_iterator_tag iterator_category; + typedef T value_type; + typedef T *pointer; + typedef T &reference; + typedef std::ptrdiff_t difference_type; + + iterator(chunky_index *ci = NULL, off_t offset = 0) : i_chunky(ci), i_offset(offset) { + }; + + iterator &operator++() { + this->i_offset += 1; + return *this; + }; + + T &operator*() { + return (*this->i_chunky)[this->i_offset]; + }; + + bool operator!=(const iterator &other) const { + return (this->i_chunky != other.i_chunky) || (this->i_offset != other.i_offset); + }; + + bool operator==(const iterator &other) const { + return (this->i_chunky == other.i_chunky) && (this->i_offset == other.i_offset); + }; + + difference_type operator-(const iterator &other) const { + return this->i_offset - other.i_offset; + }; + + void operator+=(difference_type n) { + this->i_offset += n; + }; + + private: + chunky_index *i_chunky; + off_t i_offset; + }; + chunky_index() : ci_generation(0), ci_merge_chunk(NULL), ci_size(0) { }; @@ -50,10 +93,22 @@ public: this->clear(); }; + iterator begin() { + return iterator(this); + }; + + iterator end() { + return iterator(this, this->ci_size); + }; + size_t size() const { return this->ci_size; }; + bool empty() const { + return this->ci_size == 0; + }; + size_t chunk_count() const { return this->ci_completed_chunks.size(); }; @@ -90,15 +145,23 @@ public: }; template - void merge_value(const T &val, Comparator comparator) { + off_t merge_value(const T &val, Comparator comparator) { + off_t retval; + this->merge_up_to(&val, comparator); + retval = (this->ci_completed_chunks.size() * CHUNK_SIZE); + if (this->ci_merge_chunk != NULL) { + retval += this->ci_merge_chunk->c_used; + } this->ci_merge_chunk->push_back(val); this->ci_size += 1; + + return retval; }; - void merge_value(const T &val) { - this->merge_value(val, less_comparator()); + off_t merge_value(const T &val) { + return this->merge_value(val, less_comparator()); }; void finish() { @@ -116,8 +179,10 @@ public: }; private: - void skip_chunks(const T *val) { - while (!this->ci_pending_chunks.empty() && this->ci_pending_chunks.front()->skippable(val)) { + template + void skip_chunks(const T *val, Comparator comparator) { + while (!this->ci_pending_chunks.empty() && + this->ci_pending_chunks.front()->skippable(val, comparator)) { struct chunk *skipped_chunk = this->ci_pending_chunks.front(); this->ci_pending_chunks.pop_front(); skipped_chunk->c_consumed = 0; @@ -133,22 +198,14 @@ private: }; struct less_comparator { - int operator()(const T &val, const T &other) const { - if (val < other) { - return -1; - } - else if (other < val) { - return 1; - } - else { - return 0; - } + bool operator()(const T &val, const T &other) const { + return (val < other); }; }; template void merge_up_to(const T *val, Comparator comparator) { - this->skip_chunks(val); + this->skip_chunks(val, comparator); do { if (this->ci_merge_chunk != NULL && this->ci_merge_chunk->full()) { @@ -161,7 +218,7 @@ private: if (!this->ci_pending_chunks.empty()) { struct chunk *next_chunk = this->ci_pending_chunks.front(); - while (((val == NULL) || (comparator(next_chunk->front(), *val) < 0)) && + while (((val == NULL) || comparator(next_chunk->front(), *val)) && !this->ci_merge_chunk->full()) { this->ci_merge_chunk->push_back(next_chunk->consume()); if (next_chunk->empty()) { @@ -189,9 +246,10 @@ private: return this->c_used == CHUNK_SIZE; }; - bool skippable(const T *val) const { + template + bool skippable(const T *val, Comparator comparator) const { return this->c_consumed == 0 && this->full() && ( - val == NULL || (this->back() <= *val)); + val == NULL || (comparator(this->back(), *val) || !comparator(*val, this->back()))); }; const T &front() const { diff --git a/src/concise_index.hh b/src/concise_index.hh index b3a80df0..e5fb3125 100644 --- a/src/concise_index.hh +++ b/src/concise_index.hh @@ -85,7 +85,9 @@ public: } if (this->ci_literal_size == LITERAL_SIZE) { - this->ensure_size(this->ci_map_size + 1); + if (!this->ensure_size(this->ci_map_size + 1)) { + return false; + } this->ci_literal_size = 0; } @@ -103,6 +105,25 @@ public: return true; }; + void pop_back() { + uint64_t &lit_or_rle_word = this->get_last_word(); + + this->ci_size -= 1; + if (this->is_rle(lit_or_rle_word)) { + this->dec_run_length(lit_or_rle_word); + if (this->run_length(lit_or_rle_word) == 0) { + lit_or_rle_word = 0; + this->ci_literal_size = 0; + } + return; + } + + this->ci_literal_size -= 1; + if (this->ci_literal_size == 0 && this->ci_map_size > 1) { + this->ci_map_size -= 1; + } + }; + bool push_back_word(uint64_t v, uint64_t len = BITS_PER_WORD) { uint64_t &lit_or_rle_word = this->get_last_word(); @@ -382,6 +403,10 @@ public: v += len; }; + void dec_run_length(uint64_t &v, uint64_t len = 1) const { + v -= len; + }; + bool have_run_length_available(uint64_t v, uint64_t len = 1) const { return (this->run_length(v) + len) < LEN_MASK; }; diff --git a/src/default-log-formats.json b/src/default-log-formats.json index 680fdbeb..a7cc3c04 100644 --- a/src/default-log-formats.json +++ b/src/default-log-formats.json @@ -419,6 +419,47 @@ } ] }, + "strace_log" : { + "title" : "Strace", + "description" : "The strace output format.", + "url" : "http://en.wikipedia.org/wiki/Strace", + "regex" : { + "std" : { + "pattern" : "^(?\\d{2}:\\d{2}:\\d{2}\\.\\d{6}) (?\\w+)\\((?.*)\\)\\s+=\\s+(?[-\\w]+)(?: (?\\w+) \\([^\\)]+\\))?(?: <(?\\d+\\.\\d+)>)?$" + } + }, + "level-field" : "errno", + "level" : { + "error" : ".+" + }, + "value" : { + "syscall" : { + "kind" : "string", + "identifier" : true + }, + "args" : { + "kind" : "string" + }, + "rc" : { + "kind" : "integer" + }, + "duration" : { + "kind" : "float" + }, + "errno" : { + "kind" : "string", + "identifier" : true + } + }, + "sample" : [ + { + "line" : "08:09:33.814936 execve(\"/bin/ls\", [\"ls\"], [/* 38 vars */]) = 0 <0.000264>" + }, + { + "line" : "08:09:33.815943 access(\"/etc/ld.so.nohwcap\", F_OK) = -1 ENOENT (No such file or directory) <0.000019>" + } + ] + }, "syslog_log" : { "title" : "Syslog", "description" : "The system logger format found on most posix systems.", diff --git a/src/line_buffer.cc b/src/line_buffer.cc index 99285504..7a897f58 100644 --- a/src/line_buffer.cc +++ b/src/line_buffer.cc @@ -562,17 +562,21 @@ throw (error) return retval; } -bool line_buffer::read_line(off_t &offset_inout, shared_buffer_ref &sbr) +bool line_buffer::read_line(off_t &offset_inout, shared_buffer_ref &sbr, line_value *lv) throw (error) { - line_value lv; + line_value lv_tmp; bool retval; + if (lv == NULL) { + lv = &lv_tmp; + } + // Clear the incoming ref right away so that an invalidate // does not cause a wasted malloc/copy. sbr.disown(); - if ((retval = this->read_line(offset_inout, lv))) { - sbr.share(this->lb_share_manager, lv.lv_start, lv.lv_len); + if ((retval = this->read_line(offset_inout, *lv))) { + sbr.share(this->lb_share_manager, lv->lv_start, lv->lv_len); } return retval; diff --git a/src/line_buffer.hh b/src/line_buffer.hh index 09f94f01..3996d9cb 100644 --- a/src/line_buffer.hh +++ b/src/line_buffer.hh @@ -126,7 +126,7 @@ public: bool include_delim = false) throw (error); - bool read_line(off_t &offset_inout, shared_buffer_ref &sbr) + bool read_line(off_t &offset_inout, shared_buffer_ref &sbr, line_value *lv = NULL) throw (error); bool read_range(off_t offset, size_t len, shared_buffer_ref &sbr) diff --git a/src/listview_curses.hh b/src/listview_curses.hh index 2132acd3..f6779172 100644 --- a/src/listview_curses.hh +++ b/src/listview_curses.hh @@ -429,7 +429,7 @@ public: }; /** This method should be called when the data source has changed. */ - void reload_data(void); + virtual void reload_data(void); /** * @param ch The input to be handled. diff --git a/src/lnav.cc b/src/lnav.cc index a0e06365..cbbc18aa 100644 --- a/src/lnav.cc +++ b/src/lnav.cc @@ -4086,7 +4086,7 @@ int main(int argc, char *argv[]) sql_install_logger(); lnav_data.ld_debug_log_name = "/dev/null"; - while ((c = getopt(argc, argv, "hHarsCc:I:f:d:nqtw:V")) != -1) { + while ((c = getopt(argc, argv, "hHarsCc:I:f:d:nqtw:VW")) != -1) { switch (c) { case 'h': usage(); @@ -4168,6 +4168,13 @@ int main(int argc, char *argv[]) stdin_out = optarg; break; + case 'W': + { + char b; + read(STDIN_FILENO, &b, 1); + } + break; + case 'V': printf("%s\n", PACKAGE_STRING); exit(0); @@ -4261,8 +4268,6 @@ int main(int argc, char *argv[]) init_lnav_commands(lnav_commands); - lnav_data.ld_log_source.add_filter(&lnav_data.ld_level_filter); - lnav_data.ld_views[LNV_HELP]. set_sub_source(new plain_text_source(help_txt)); lnav_data.ld_views[LNV_HELP].set_word_wrap(true); diff --git a/src/lnav.hh b/src/lnav.hh index 2f257269..7ca101df 100644 --- a/src/lnav.hh +++ b/src/lnav.hh @@ -132,27 +132,6 @@ void sqlite_close_wrapper(void *mem); typedef std::pair ppid_time_pair_t; typedef std::pair session_pair_t; -class level_filter : public logfile_filter { -public: - level_filter() - : logfile_filter(EXCLUDE, ""), - lf_min_level(logline::LEVEL_UNKNOWN) { - }; - - bool matches(const logline &ll, const std::string &line) - { - return (ll.get_level() & ~logline::LEVEL__FLAGS) < this->lf_min_level; - }; - - std::string to_command(void) - { - return ("set-min-log-level " + - std::string(logline::level_names[this->lf_min_level])); - }; - - logline::level_t lf_min_level; -}; - struct _lnav_data { std::string ld_session_id; time_t ld_session_time; @@ -196,7 +175,6 @@ struct _lnav_data { vis_line_t ld_search_start_line; readline_curses * ld_rl_view; - level_filter ld_level_filter; logfile_sub_source ld_log_source; hist_source ld_hist_source; int ld_hist_zoom; diff --git a/src/lnav_commands.cc b/src/lnav_commands.cc index bdea5907..480d7565 100644 --- a/src/lnav_commands.cc +++ b/src/lnav_commands.cc @@ -108,7 +108,7 @@ static string com_adjust_log_time(string cmdline, vector &args) dts.set_base_time(top_time.tv_sec); args[1] = cmdline.substr(cmdline.find(args[1], args[0].size())); - if (dts.scan(args[1].c_str(), NULL, &tm, new_time) != NULL) { + if (dts.scan(args[1].c_str(), args[1].size(), NULL, &tm, new_time) != NULL) { timersub(&new_time, &top_time, &time_diff); lf->adjust_content_time(top_content, time_diff, false); @@ -184,7 +184,7 @@ static string com_current_time(string cmdline, vector &args) struct tm localtm; string retval; time_t u_time; - int len; + size_t len; memset(&localtm, 0, sizeof(localtm)); u_time = time(NULL); @@ -215,7 +215,7 @@ static string com_goto(string cmdline, vector &args) struct exttm tm; float value; - if (dts.scan(args[1].c_str(), NULL, &tm, tv) != NULL) { + if (dts.scan(args[1].c_str(), args[1].size(), NULL, &tm, tv) != NULL) { if (tc == &lnav_data.ld_views[LNV_LOG]) { vis_line_t vl; @@ -544,24 +544,24 @@ static string com_help(string cmdline, vector &args) } class pcre_filter - : public logfile_filter { + : public text_filter { public: - pcre_filter(type_t type, const string id, pcre *code) - : logfile_filter(type, id), + pcre_filter(type_t type, const string id, size_t index, pcre *code) + : text_filter(type, id, index), pf_pcre(code) { }; virtual ~pcre_filter() { }; - bool matches(const logline &ll, const string &line) + bool matches(const logfile &lf, const logline &ll, shared_buffer_ref &line) { pcre_context_static<30> pc; - pcre_input pi(line); + pcre_input pi(line.get_data(), 0, line.length()); return this->pf_pcre.match(pc, pi); }; std::string to_command(void) { - return (this->lf_type == logfile_filter::INCLUDE ? + return (this->lf_type == text_filter::INCLUDE ? "filter-in " : "filter-out ") + this->lf_id; }; @@ -578,13 +578,15 @@ static string com_filter(string cmdline, vector &args) args.push_back("filter"); } else if (args.size() > 1) { - logfile_sub_source &lss = lnav_data.ld_log_source; + textview_curses *tc = lnav_data.ld_view_stack.top(); + text_sub_source *tss = tc->get_sub_source(); + filter_stack &fs = tss->get_filters(); const char *errptr; pcre * code; int eoff; args[1] = cmdline.substr(cmdline.find(args[1], args[0].size())); - if (lss.get_filter(args[1]) != NULL) { + if (fs.get_filter(args[1]) != NULL) { retval = "error: filter already exists"; } else if ((code = pcre_compile(args[1].c_str(), @@ -595,12 +597,13 @@ static string com_filter(string cmdline, vector &args) retval = "error: " + string(errptr); } else { - logfile_filter::type_t lt = (args[0] == "filter-out") ? - logfile_filter::EXCLUDE : - logfile_filter::INCLUDE; - auto_ptr pf(new pcre_filter(lt, args[1], code)); + text_filter::type_t lt = (args[0] == "filter-out") ? + text_filter::EXCLUDE : + text_filter::INCLUDE; + auto_ptr pf(new pcre_filter(lt, args[1], fs.next_index(), code)); - lss.add_filter(pf.release()); + fs.add_filter(pf.release()); + tss->text_filters_changed(); if (lnav_data.ld_rl_view != NULL) { lnav_data.ld_rl_view->add_possibility( LNM_COMMAND, "enabled-filter", args[1]); @@ -622,10 +625,13 @@ static string com_enable_filter(string cmdline, vector &args) args.push_back("disabled-filter"); } else if (args.size() > 1) { - logfile_filter *lf; + textview_curses *tc = lnav_data.ld_view_stack.top(); + text_sub_source *tss = tc->get_sub_source(); + filter_stack &fs = tss->get_filters(); + text_filter *lf; args[1] = cmdline.substr(cmdline.find(args[1], args[0].size())); - lf = lnav_data.ld_log_source.get_filter(args[1]); + lf = fs.get_filter(args[1]); if (lf == NULL) { retval = "error: no such filter -- " + args[1]; } @@ -633,7 +639,8 @@ static string com_enable_filter(string cmdline, vector &args) retval = "info: filter already enabled"; } else { - lnav_data.ld_log_source.set_filter_enabled(lf, true); + fs.set_filter_enabled(lf, true); + tss->text_filters_changed(); if (lnav_data.ld_rl_view != NULL) { lnav_data.ld_rl_view->rem_possibility( LNM_COMMAND, "disabled-filter", args[1]); @@ -656,10 +663,13 @@ static string com_disable_filter(string cmdline, vector &args) args.push_back("enabled-filter"); } else if (args.size() > 1) { - logfile_filter *lf; + textview_curses *tc = lnav_data.ld_view_stack.top(); + text_sub_source *tss = tc->get_sub_source(); + filter_stack &fs = tss->get_filters(); + text_filter *lf; args[1] = cmdline.substr(cmdline.find(args[1], args[0].size())); - lf = lnav_data.ld_log_source.get_filter(args[1]); + lf = fs.get_filter(args[1]); if (lf == NULL) { retval = "error: no such filter -- " + args[1]; } @@ -667,7 +677,8 @@ static string com_disable_filter(string cmdline, vector &args) retval = "info: filter already disabled"; } else { - lnav_data.ld_log_source.set_filter_enabled(lf, false); + fs.set_filter_enabled(lf, false); + tss->text_filters_changed(); if (lnav_data.ld_rl_view != NULL) { lnav_data.ld_rl_view->rem_possibility( LNM_COMMAND, "disabled-filter", args[1]); @@ -1370,16 +1381,13 @@ static string com_set_min_log_level(string cmdline, vector &args) args.push_back("levelname"); } else if (args.size() == 2) { + logfile_sub_source &lss = lnav_data.ld_log_source; logline::level_t new_level; new_level = logline::string2level( args[1].c_str(), args[1].size(), true); - if (lnav_data.ld_level_filter.lf_min_level != new_level) { - lnav_data.ld_level_filter.lf_min_level = new_level; - lnav_data.ld_log_source.filter_changed(); - - rebuild_indexes(true); - } + lss.set_min_log_level(new_level); + rebuild_indexes(true); retval = ("info: minimum log level is now -- " + string(logline::level_names[new_level])); diff --git a/src/lnav_log.cc b/src/lnav_log.cc index 2a28a1b7..94eab18f 100644 --- a/src/lnav_log.cc +++ b/src/lnav_log.cc @@ -60,6 +60,9 @@ # include #elif defined HAVE_NCURSES_H # include +#include +#include + #elif defined HAVE_CURSES_H # include #else @@ -149,6 +152,7 @@ void log_argv(int argc, char *argv[]) void log_host_info(void) { + char cwd[MAXPATHLEN]; struct utsname un; uname(&un); @@ -159,7 +163,21 @@ void log_host_info(void) log_info(" release=%s", un.release); log_info(" version=%s", un.version); log_info("Environment:"); + log_info(" HOME=%s", getenv("HOME")); + log_info(" LANG=%s", getenv("LANG")); + log_info(" PATH=%s", getenv("PATH")); log_info(" TERM=%s", getenv("TERM")); + log_info(" TZ=%s", getenv("TZ")); + log_info("Process:") + log_info(" pid=%d", getpid()); + log_info(" ppid=%d", getppid()); + log_info(" pgrp=%d", getpgrp()); + log_info(" uid=%d", getuid()); + log_info(" gid=%d", getgid()); + log_info(" euid=%d", geteuid()); + log_info(" egid=%d", getegid()); + getcwd(cwd, sizeof(cwd)); + log_info(" cwd=%s", cwd); } void log_msg(lnav_log_level_t level, const char *src_file, int line_number, @@ -167,10 +185,10 @@ void log_msg(lnav_log_level_t level, const char *src_file, int line_number, { struct timeval curr_time; struct tm localtm; - size_t prefix_size; + ssize_t prefix_size; va_list args; char *line; - int rc; + ssize_t rc; if (level < lnav_log_level) { return; diff --git a/src/lnav_util.cc b/src/lnav_util.cc index aa0185af..3deb628a 100644 --- a/src/lnav_util.cc +++ b/src/lnav_util.cc @@ -272,6 +272,7 @@ const char *std_time_fmt[] = { }; const char *date_time_scanner::scan(const char *time_dest, + size_t time_len, const char *time_fmt[], struct exttm *tm_out, struct timeval &tv_out) @@ -320,7 +321,7 @@ const char *date_time_scanner::scan(const char *time_dest, #ifdef HAVE_STRUCT_TM_TM_ZONE tm_out->et_tm.tm_zone = NULL; #endif - if (func(tm_out, time_dest, off, strlen(time_dest))) { + if (func(tm_out, time_dest, off, time_len)) { retval = &time_dest[off]; if (tm_out->et_tm.tm_year < 70) { @@ -395,19 +396,16 @@ const char *date_time_scanner::scan(const char *time_dest, if (retval != NULL) { /* Try to pull out the milli/micro-second value. */ if (retval[0] == '.' || retval[0] == ',') { - int sub_seconds = 0, sub_len = 0; - - if (sscanf(retval + 1, "%d%n", &sub_seconds, &sub_len) == 1) { - switch (sub_len) { - case 3: - tv_out.tv_usec = sub_seconds * 1000; - this->dts_fmt_len += 1 + sub_len; - break; - case 6: - tv_out.tv_usec = sub_seconds; - this->dts_fmt_len += 1 + sub_len; - break; - } + off_t off = (retval - time_dest) + 1; + int sub_seconds = 0; + + if (ptime_f(sub_seconds, time_dest, off, time_len)) { + tv_out.tv_usec = sub_seconds; + this->dts_fmt_len += 7; + } + else if (ptime_F(sub_seconds, time_dest, off, time_len)) { + tv_out.tv_usec = sub_seconds * 1000; + this->dts_fmt_len += 4; } } } diff --git a/src/lnav_util.hh b/src/lnav_util.hh index 0f0889b5..7a5a3839 100644 --- a/src/lnav_util.hh +++ b/src/lnav_util.hh @@ -204,6 +204,7 @@ struct date_time_scanner { int dts_fmt_len; const char *scan(const char *time_src, + size_t time_len, const char *time_fmt[], struct exttm *tm_out, struct timeval &tv_out); diff --git a/src/log_format.cc b/src/log_format.cc index 41972d35..0d60ef99 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -76,27 +76,20 @@ const char *logline::level_names[LEVEL__MAX + 1] = { NULL }; +static pcrepp LEVEL_RE( + "(?i)(TRACE|VERBOSE|DEBUG|INFO|WARN(?:ING)?|ERROR|CRITICAL|SEVERE|FATAL)"); + static int strncasestr_i(const char *s1, const char *s2, size_t len) { return strcasestr(s1, s2) == NULL; } -logline::level_t logline::string2level(const char *levelstr, size_t len, bool exact) +logline::level_t logline::string2level(const char *levelstr, ssize_t len, bool exact) { logline::level_t retval = logline::LEVEL_UNKNOWN; - int (*cmpfunc)(const char *, const char *, size_t); - - require(len == (size_t)-1 || (len != (size_t)-1 && exact)); - - if (len == (size_t)-1) + if (len == (size_t)-1) { len = strlen(levelstr); - - if (exact) { - cmpfunc = strncasecmp; - } - else{ - cmpfunc = strncasestr_i; } if (((len == 1) || ((len > 1) && (levelstr[1] == ' '))) && @@ -104,68 +97,45 @@ logline::level_t logline::string2level(const char *levelstr, size_t len, bool ex return retval; } - if (cmpfunc(levelstr, "TRACE", len) == 0) { - retval = logline::LEVEL_TRACE; - } - else if (cmpfunc(levelstr, "VERBOSE", len) == 0) { - retval = logline::LEVEL_DEBUG; - } - else if (cmpfunc(levelstr, "DEBUG", len) == 0) { - retval = logline::LEVEL_DEBUG; - } - else if (cmpfunc(levelstr, "INFO", len) == 0) { - retval = logline::LEVEL_INFO; - } - else if (cmpfunc(levelstr, "WARNING", len) == 0) { - retval = logline::LEVEL_WARNING; - } - else if (cmpfunc(levelstr, "ERROR", len) == 0) { - retval = logline::LEVEL_ERROR; - } - else if (cmpfunc(levelstr, "CRITICAL", len) == 0) { - retval = logline::LEVEL_CRITICAL; - } - else if (cmpfunc(levelstr, "SEVERE", len) == 0) { - retval = logline::LEVEL_CRITICAL; - } - else if (cmpfunc(levelstr, "FATAL", len) == 0) { - retval = logline::LEVEL_FATAL; + pcre_input pi(levelstr, 0, len); + pcre_context_static<10> pc; + + if (LEVEL_RE.match(pc, pi)) { + retval = abbrev2level(pi.get_substr_start(pc.begin()), 1); } return retval; } -logline::level_t logline::abbrev2level(const char *levelstr, size_t len) +logline::level_t logline::abbrev2level(const char *levelstr, ssize_t len) { - if (len == -1) { - len = strlen(levelstr); - } - - if (len == 0) { + if (levelstr[0] == '\0') { return LEVEL_UNKNOWN; } switch (toupper(levelstr[0])) { case 'T': - return LEVEL_TRACE; + return LEVEL_TRACE; case 'D': - return LEVEL_DEBUG; + return LEVEL_DEBUG; case 'I': - return LEVEL_INFO; + return LEVEL_INFO; case 'W': - return LEVEL_WARNING; + return LEVEL_WARNING; case 'E': - return LEVEL_ERROR; + return LEVEL_ERROR; case 'C': - return LEVEL_CRITICAL; + return LEVEL_CRITICAL; + case 'S': + return LEVEL_CRITICAL; case 'F': - return LEVEL_FATAL; + return LEVEL_FATAL; + default: + return LEVEL_UNKNOWN; } - - return LEVEL_UNKNOWN; } -int logline::levelcmp(const char *l1, size_t l1_len, const char *l2, size_t l2_len) +int logline::levelcmp(const char *l1, ssize_t l1_len, const char *l2, ssize_t l2_len) { return abbrev2level(l1, l1_len) - abbrev2level(l2, l2_len); } @@ -232,11 +202,30 @@ static bool next_format(const std::vector &patte return retval; } +bool log_format::next_format(pcre_format *fmt, int &index, int &locked_index) +{ + bool retval = true; + + if (locked_index == -1) { + index += 1; + if (fmt[index].name == NULL) { + retval = false; + } + } + else if (index == locked_index) { + retval = false; + } + else { + index = locked_index; + } + + return retval; +} + const char *log_format::log_scanf(const char *line, - const char *fmt[], - int expected_matches, + size_t len, + pcre_format *fmt, const char *time_fmt[], - char *time_dest, struct exttm *tm_out, struct timeval &tv_out, ...) @@ -244,23 +233,30 @@ const char *log_format::log_scanf(const char *line, int curr_fmt = -1; const char * retval = NULL; bool done = false; + pcre_input pi(line, 0, len); + pcre_context_static<128> pc; va_list args; while (!done && next_format(fmt, curr_fmt, this->lf_fmt_lock)) { va_start(args, tv_out); - int matches; - time_dest[0] = '\0'; - - matches = vsscanf(line, fmt[curr_fmt], args); - if (matches < expected_matches) { - retval = NULL; - } - else if (time_dest[0] == '\0') { + if (!fmt[curr_fmt].pcre.match(pc, pi)) { retval = NULL; } else { - retval = this->lf_date_time.scan(time_dest, time_fmt, tm_out, tv_out); + pcre_context::capture_t *ts = pc["timestamp"]; + + for (pcre_context::iterator iter = pc.begin(); + iter != pc.end(); + ++iter) { + pcre_context::capture_t *cap = va_arg( + args, pcre_context::capture_t *); + + *cap = *iter; + } + + retval = this->lf_date_time.scan( + pi.get_substr_start(ts), ts->length(), NULL, tm_out, tv_out); if (retval) { this->lf_fmt_lock = curr_fmt; @@ -530,8 +526,7 @@ static struct json_path_handler json_log_rewrite_handlers[] = { bool external_log_format::scan(std::vector &dst, off_t offset, - char *prefix, - int len) + shared_buffer_ref &sbr) { if (this->jlf_json) { auto_mem handle(yajl_free); @@ -550,10 +545,10 @@ bool external_log_format::scan(std::vector &dst, ypc.ypc_alt_callbacks.yajl_start_map = json_array_start; jlu.jlu_format = this; jlu.jlu_base_line = ≪ - jlu.jlu_line_value = prefix; + jlu.jlu_line_value = sbr.get_data(); jlu.jlu_handle = handle; if (yajl_parse(handle.in(), - (const unsigned char *)prefix, len) == yajl_status_ok && + (const unsigned char *)sbr.get_data(), sbr.length()) == yajl_status_ok && yajl_complete_parse(handle.in()) == yajl_status_ok) { for (int lpc = 0; lpc < jlu.jlu_sub_line_count; lpc++) { ll.set_sub_offset(lpc); @@ -569,12 +564,12 @@ bool external_log_format::scan(std::vector &dst, return retval; } - pcre_input pi(prefix, 0, len); + pcre_input pi(sbr.get_data(), 0, sbr.length()); pcre_context_static<128> pc; bool retval = false; int curr_fmt = -1; - while (next_format(this->elf_pattern_order, curr_fmt, this->lf_fmt_lock)) { + while (::next_format(this->elf_pattern_order, curr_fmt, this->lf_fmt_lock)) { pcrepp *pat = this->elf_pattern_order[curr_fmt]->p_pcre; if (!pat->match(pc, pi)) { @@ -597,6 +592,7 @@ bool external_log_format::scan(std::vector &dst, logline::level_t level = logline::LEVEL_INFO; if ((last = this->lf_date_time.scan(ts_str, + ts->length(), NULL, &log_time_tm, log_tv)) == NULL) { @@ -722,7 +718,7 @@ static int read_json_field(yajlpp_parse_context *ypc, const unsigned char *str, struct timeval tv_out; if (field_name == jlu->jlu_format->lf_timestamp_field) { - jlu->jlu_format->lf_date_time.scan((const char *)str, NULL, &tm_out, tv_out); + jlu->jlu_format->lf_date_time.scan((const char *)str, len, NULL, &tm_out, tv_out); jlu->jlu_base_line->set_time(tv_out); } else if (field_name == jlu->jlu_format->elf_level_field) { @@ -1074,12 +1070,13 @@ void external_log_format::build(std::vector &errors) if (pat.p_pcre->match(pc, pi)) { const char *ts = pi.get_substr_start( pc[this->lf_timestamp_field]); + ssize_t ts_len = pc[this->lf_timestamp_field]->length(); date_time_scanner dts; struct timeval tv; struct exttm tm; found = true; - if (dts.scan(ts, NULL, &tm, tv) == NULL) { + if (ts_len == -1 || dts.scan(ts, ts_len, NULL, &tm, tv) == NULL) { errors.push_back("error:" + this->elf_name + ":invalid sample -- " + @@ -1091,8 +1088,7 @@ void external_log_format::build(std::vector &errors) for (int lpc = 0; PTIMEC_FORMATS[lpc].pf_fmt != NULL; lpc++) { off_t off = 0; - PTIMEC_FORMATS[lpc].pf_func(&tm, ts, off, - pc[this->lf_timestamp_field]->length()); + PTIMEC_FORMATS[lpc].pf_func(&tm, ts, off, ts_len); errors.push_back(" format: " + string(PTIMEC_FORMATS[lpc].pf_fmt) + "; matched: " + string(ts, off)); } diff --git a/src/log_format.hh b/src/log_format.hh index 4dad69e9..f87f75ae 100644 --- a/src/log_format.hh +++ b/src/log_format.hh @@ -53,49 +53,6 @@ #include "view_curses.hh" #include "shared_buffer.hh" -class logline; - -class logfile_filter { -public: - typedef enum { - MAYBE, - INCLUDE, - EXCLUDE, - - LFT__MAX, - - LFT__MASK = (MAYBE|INCLUDE|EXCLUDE) - } type_t; - - logfile_filter(type_t type, const std::string id) - : lf_enabled(true), - lf_type(type), - lf_id(id) { }; - virtual ~logfile_filter() { }; - - type_t get_type(void) const { return this->lf_type; }; - std::string get_id(void) const { return this->lf_id; }; - - bool is_enabled(void) { return this->lf_enabled; }; - void enable(void) { this->lf_enabled = true; }; - void disable(void) { this->lf_enabled = false; }; - - virtual bool matches(const logline &ll, const std::string &line) = 0; - - virtual std::string to_command(void) = 0; - - bool operator==(const std::string &rhs) { - return this->lf_id == rhs; - }; - -protected: - bool lf_enabled; - type_t lf_type; - std::string lf_id; -}; - -typedef std::vector filter_stack_t; - /** * Metadata for a single line in a log file. */ @@ -130,12 +87,12 @@ public: static const char *level_names[LEVEL__MAX + 1]; - static level_t string2level(const char *levelstr, size_t len = -1, bool exact = false); + static level_t string2level(const char *levelstr, ssize_t len = -1, bool exact = false); - static level_t abbrev2level(const char *levelstr, size_t len = -1); + static level_t abbrev2level(const char *levelstr, ssize_t len = -1); - static int levelcmp(const char *l1, size_t l1_len, - const char *l2, size_t l2_len); + static int levelcmp(const char *l1, ssize_t l1_len, + const char *l2, ssize_t l2_len); /** * Construct a logline object with the given values. @@ -153,7 +110,6 @@ public: ll_time(t), ll_millis(millis), ll_level(l), - ll_filter_state(logfile_filter::MAYBE), ll_sub_offset(0) { memset(this->ll_schema, 0, sizeof(this->ll_schema)); @@ -165,7 +121,6 @@ public: uint8_t m = 0) : ll_offset(off), ll_level(l), - ll_filter_state(logfile_filter::MAYBE), ll_sub_offset(0) { this->set_time(tv); @@ -221,6 +176,10 @@ public: /** @return The logging level. */ level_t get_level() const { return (level_t)(this->ll_level & 0xff); }; + level_t get_msg_level() const { + return (level_t)(this->ll_level & ~LEVEL__FLAGS); + }; + const char *get_level_name() const { return level_names[this->ll_level & 0x0f]; @@ -230,19 +189,6 @@ public: return this->get_level() & LEVEL_CONTINUED; }; - uint8_t get_filter_generation(void) const { - return this->ll_filter_state >> 2; - }; - - logfile_filter::type_t get_filter_state(void) const { - return (logfile_filter::type_t)(this->ll_filter_state & - logfile_filter::LFT__MASK); - }; - - void set_filter_state(uint8_t generation, logfile_filter::type_t filter) { - this->ll_filter_state = (generation << 2) | filter; - }; - /** * @return True if there is a schema value set for this log line. */ @@ -302,7 +248,6 @@ private: time_t ll_time; uint16_t ll_millis; uint8_t ll_level; - uint8_t ll_filter_state; uint16_t ll_sub_offset; char ll_schema[4]; }; @@ -588,8 +533,7 @@ public: */ virtual bool scan(std::vector &dst, off_t offset, - char *prefix, - int len) = 0; + shared_buffer_ref &sbr) = 0; /** * Remove redundant data from the log line string. @@ -638,11 +582,17 @@ public: protected: static std::vector lf_root_formats; + struct pcre_format { + const char *name; + pcrepp pcre; + }; + + static bool next_format(pcre_format *fmt, int &index, int &locked_index); + const char *log_scanf(const char *line, - const char *fmt[], - int expected_matches, + size_t len, + pcre_format *fmt, const char *time_fmt[], - char *time_dest, struct exttm *tm_out, struct timeval &tv_out, ...); @@ -727,8 +677,7 @@ public: bool scan(std::vector &dst, off_t offset, - char *prefix, - int len); + shared_buffer_ref &sbr); void annotate(shared_buffer_ref &line, string_attrs_t &sa, diff --git a/src/log_format_impls.cc b/src/log_format_impls.cc index c4186fea..4c70ce12 100644 --- a/src/log_format_impls.cc +++ b/src/log_format_impls.cc @@ -76,137 +76,6 @@ static string scrub_rdns(const string &str) return retval; } -class strace_log_format : public log_format { - static pcrepp &value_pattern(void) - { - static pcrepp VALUE_PATTERN( - "([0-9:.]*) ([a-zA-Z_][a-zA-Z_0-9]*)\\(" - "(.*)\\)" - "\\s+= ([-xa-fA-F\\d\\?]+)[^<]+(?:<(\\d+\\.\\d+)>)?"); - - return VALUE_PATTERN; - }; - - string get_name() const { return "strace_log"; }; - - bool scan(vector &dst, - off_t offset, - char *prefix, - int len) - { - static const char *log_fmt[] = { - "%63[0-9:].%d", - NULL - }; - - static const char *time_fmt[] = { - "%H:%M:%S", - NULL - }; - - bool retval = false; - struct exttm log_time; - char timestr[64]; - struct timeval log_tv; - int usecs; - - if (this->log_scanf(prefix, - log_fmt, - 2, - time_fmt, - timestr, - &log_time, - log_tv, - - timestr, - &usecs)) { - logline::level_t level = logline::LEVEL_UNKNOWN; - const char * eq; - - if ((eq = strrchr(prefix, '=')) != NULL) { - int rc; - - if (sscanf(eq, "= %d", &rc) == 1 && rc < 0) { - level = logline::LEVEL_ERROR; - } - } - - if (!dst.empty() && (log_tv.tv_sec < dst.back().get_time())) { - log_tv.tv_sec += (24 * 60 * 60); - } - log_tv.tv_usec = usecs; - dst.push_back(logline(offset, log_tv, level)); - retval = true; - } - - return retval; - }; - - auto_ptr specialized() - { - auto_ptr retval((log_format *) - new strace_log_format(*this)); - - return retval; - }; - - void annotate(shared_buffer_ref &line, - string_attrs_t &sa, - std::vector &values) const - { - pcre_context_static<30> pc; - pcre_input pi(line.get_data(), 0, line.length()); - - if (value_pattern().match(pc, pi)) { - static struct { - const char * name; - logline_value::kind_t kind; - } columns[] = { - { "", logline_value::VALUE_TEXT }, - { "funcname", logline_value::VALUE_TEXT }, - { "args", logline_value::VALUE_TEXT }, - { "result", logline_value::VALUE_TEXT }, - { "duration", logline_value::VALUE_FLOAT }, - - { NULL, logline_value::VALUE_UNKNOWN }, - }; - - pcre_context::iterator iter; - struct line_range lr; - - iter = pc.begin(); - if (iter->c_begin != -1) { - lr.lr_start = iter->c_begin; - lr.lr_end = iter->c_end; - sa.push_back(string_attr(lr, &logline::L_TIMESTAMP)); - } - - lr.lr_start = 0; - lr.lr_end = line.length(); - sa.push_back(string_attr(lr, &logline::L_PREFIX)); - - lr.lr_start = line.length(); - lr.lr_end = line.length(); - sa.push_back(string_attr(lr, &textview_curses::SA_BODY)); - - for (int lpc = 0; columns[lpc].name; lpc++) { - pcre_context::iterator cap = pc.begin() + lpc; - shared_buffer_ref value_str; - - if (columns[lpc].name[0] == '\0') { - continue; - } - value_str.subset(line, cap->c_begin, cap->length()); - values.push_back(logline_value(columns[lpc].name, - columns[lpc].kind, - value_str)); - } - } - }; -}; - -log_format::register_root_format strace_log_instance; - class generic_log_format : public log_format { static pcrepp &scrub_pattern(void) { @@ -216,43 +85,19 @@ class generic_log_format : public log_format { return SCRUB_PATTERN; } - static const char **get_log_formats() - { - static const char *log_fmt[] = { - "%63[0-9TZ: ,.-]%63[^:]%n", - "%63[a-zA-Z0-9:-+/.] [%*x %63[^\n]%n", - "%63[a-zA-Z0-9:.,-/] %63[^\n]%n", - "%63[a-zA-Z0-9: .,-/] [%*[^]]]%63[^:]%n", - "%63[a-zA-Z0-9: .,-/] %63[^\n]%n", - "[%63[0-9: .-] %*s %63[^\n]%n", - "[%63[a-zA-Z0-9: -+/]] %63[^\n]%n", - "[%63[a-zA-Z0-9: -+/]] [%63[a-zA-Z]]%n", - "[%63[a-zA-Z0-9: .-+/] %*s %63[^\n]%n", - "[%63[a-zA-Z0-9: -+/]] (%*d) %63[^\n]%n", - NULL - }; - - return log_fmt; - }; - - struct pcre_format { - const char *name; - pcrepp pcre; - }; - static pcre_format *get_pcre_log_formats() { static pcre_format log_fmt[] = { - { "", pcrepp("([\\dTZ: ,\\.-]+)([^:]+)") }, - { "", pcrepp("([\\w:+/\\.-]+) \\[\\w (.*)") }, - { "", pcrepp("([\\w:,/\\.-]+) (.*)") }, - { "", pcrepp("([\\w: \\.,/-]+) \\[[^\\]+](.*)") }, - { "", pcrepp("([\\w: \\.,/-]+) (.*)") }, - - { "", pcrepp("\\[([\\d: \\.-]+) \\w+ (.*)") }, - { "", pcrepp("\\[([\\w: +/-]+)\\] (.*)") }, - { "", pcrepp("\\[([\\w: +/-]+)\\] \\[(\\w+)\\]") }, - { "", pcrepp("\\[([\\w: \\.+/-]+)\\] \\w+ (.*)") }, - { "", pcrepp("\\[([\\w: +/-]+)\\] \\(\\d+\\) (.*)") }, + { "", pcrepp("(?[\\dTZ: ,\\.-]+)([^:]+)") }, + { "", pcrepp("(?[\\w:+/\\.-]+) \\[\\w (.*)") }, + { "", pcrepp("(?[\\w:,/\\.-]+) (.*)") }, + { "", pcrepp("(?[\\w: \\.,/-]+) \\[[^\\]+](.*)") }, + { "", pcrepp("(?[\\w: \\.,/-]+) (.*)") }, + + { "", pcrepp("\\[(?[\\d: \\.-]+) \\w+ (.*)") }, + { "", pcrepp("\\[(?[\\w: +/-]+)\\] (.*)") }, + { "", pcrepp("\\[(?[\\w: +/-]+)\\] \\[(\\w+)\\]") }, + { "", pcrepp("\\[(?[\\w: \\.+/-]+)\\] \\w+ (.*)") }, + { "", pcrepp("\\[(?[\\w: +/-]+)\\] \\(\\d+\\) (.*)") }, { NULL, pcrepp("") } }; @@ -281,44 +126,31 @@ class generic_log_format : public log_format { bool scan(vector &dst, off_t offset, - char *prefix, - int len) + shared_buffer_ref &sbr) { bool retval = false; struct exttm log_time; - char timestr[64 + 32]; struct timeval log_tv; - char level[64]; + pcre_context::capture_t ts, level; const char *last_pos; - int prefix_len; - - if ((last_pos = this->log_scanf(prefix, - get_log_formats(), - 2, - NULL, - timestr, - &log_time, - log_tv, - - timestr, - level, - &prefix_len)) != NULL) { - uint16_t millis = 0; - - if (last_pos[0] == ',' || last_pos[0] == '.') { - int subsec_len = 0; - - sscanf(last_pos + 1, "%hd%n", &millis, &subsec_len); - if (millis >= 1000) { - millis = 0; - } - this->lf_date_time.dts_fmt_len += 1 + subsec_len; - } + + if ((last_pos = this->log_scanf( + sbr.get_data(), + sbr.length(), + get_pcre_log_formats(), + NULL, + &log_time, + log_tv, + + &ts, + &level)) != NULL) { + const char *level_str = &sbr.get_data()[level.c_begin]; + logline::level_t level_val = logline::string2level( + level_str, level.length()); + this->check_for_new_year(dst, log_tv); - dst.push_back(logline(offset, - log_tv, - logline::string2level(level))); + dst.push_back(logline(offset, log_tv, level_val)); retval = true; } diff --git a/src/log_format_loader.cc b/src/log_format_loader.cc index 0a88fe7e..af496c09 100644 --- a/src/log_format_loader.cc +++ b/src/log_format_loader.cc @@ -73,6 +73,7 @@ static int read_format_regex(yajlpp_parse_context *ypc, const unsigned char *str string regex_name = ypc->get_path_fragment(2); string value = string((const char *)str, len); + log_debug("regex: %s", value.c_str()); elf->elf_patterns[regex_name].p_string = value; return 1; diff --git a/src/log_vtab_impl.cc b/src/log_vtab_impl.cc index 1380f10a..c63692b7 100644 --- a/src/log_vtab_impl.cc +++ b/src/log_vtab_impl.cc @@ -144,6 +144,8 @@ static int vt_create(sqlite3 *db, /* Success. Set *pp_vt and return */ *pp_vt = &p_vt->base; + log_debug("create %s -> %p", argv[3], p_vt); + return rc; } @@ -461,8 +463,10 @@ void log_cursor::update(unsigned char op, vis_line_t vl, bool exact) { switch (op) { case SQLITE_INDEX_CONSTRAINT_EQ: - this->lc_curr_line = vl; - this->lc_end_line = vis_line_t(this->lc_curr_line + 1); + if (vl < this->lc_end_line) { + this->lc_curr_line = vl; + this->lc_end_line = vis_line_t(this->lc_curr_line + 1); + } break; case SQLITE_INDEX_CONSTRAINT_GE: this->lc_curr_line = vl; @@ -488,13 +492,13 @@ static int vt_filter(sqlite3_vtab_cursor *p_vtc, sqlite3_index_info::sqlite3_index_constraint *index = ( sqlite3_index_info::sqlite3_index_constraint *)idxStr; - log_info("filter called: %d", idxNum); + log_info("(%p) filter called: %d", vt, idxNum); + p_cur->log_cursor.lc_curr_line = vis_line_t(0); + p_cur->log_cursor.lc_end_line = vis_line_t(vt->lss->text_line_count()); if (!idxNum) { return SQLITE_OK; } - p_cur->log_cursor.lc_curr_line = vis_line_t(0); - p_cur->log_cursor.lc_end_line = vis_line_t(vt->lss->text_line_count()); for (int lpc = 0; lpc < idxNum; lpc++) { switch (index[lpc].iColumn) { case VT_COL_LINE_NUMBER: @@ -509,7 +513,7 @@ static int vt_filter(sqlite3_vtab_cursor *p_vtc, struct exttm mytm; vis_line_t vl; - dts.scan((const char *)datestr, NULL, &mytm, tv); + dts.scan((const char *)datestr, strlen((const char *)datestr), NULL, &mytm, tv); if ((vl = vt->lss->find_from_time(tv)) == -1) { p_cur->log_cursor.lc_curr_line = p_cur->log_cursor.lc_end_line; } @@ -530,7 +534,7 @@ static int vt_best_index(sqlite3_vtab *tab, sqlite3_index_info *p_info) std::vector indexes; int argvInUse = 0; - log_info("best index called: nConstraint=%d", p_info->nConstraint); + log_info("(%p) best index called: nConstraint=%d", tab, p_info->nConstraint); for (int lpc = 0; lpc < p_info->nConstraint; lpc++) { if (!p_info->aConstraint[lpc].usable || p_info->aConstraint[lpc].op == SQLITE_INDEX_CONSTRAINT_MATCH) { diff --git a/src/logfile.cc b/src/logfile.cc index e21f0f18..80a97012 100644 --- a/src/logfile.cc +++ b/src/logfile.cc @@ -56,9 +56,10 @@ throw (error) : lf_filename(filename), lf_index_time(0), lf_index_size(0), - lf_is_closed(false) + lf_is_closed(false), + lf_logline_observer(NULL) { - int reserve_size = 100; + ssize_t reserve_size = 100; require(filename.size() > 0); @@ -136,14 +137,13 @@ void logfile::set_format_base_time(log_format *lf) lf->lf_date_time.set_base_time(file_time); } -void logfile::process_prefix(off_t offset, char *prefix, int len) +void logfile::process_prefix(off_t offset, shared_buffer_ref &sbr) { bool found = false; if (this->lf_format.get() != NULL) { /* We've locked onto a format, just use that scanner. */ - this->set_format_base_time(this->lf_format.get()); - found = this->lf_format->scan(this->lf_index, offset, prefix, len); + found = this->lf_format->scan(this->lf_index, offset, sbr); } else if (this->lf_index.size() < MAX_UNRECOGNIZED_LINES) { vector &root_formats = @@ -163,7 +163,7 @@ void logfile::process_prefix(off_t offset, char *prefix, int len) (*iter)->clear(); this->set_format_base_time(*iter); - if (!(*iter)->scan(this->lf_index, offset, prefix, len)) { + if (!(*iter)->scan(this->lf_index, offset, sbr)) { log_debug("%s:%d:log format does not match -- %s", this->lf_filename.c_str(), this->lf_index.size(), @@ -182,7 +182,8 @@ void logfile::process_prefix(off_t offset, char *prefix, int len) this->lf_format = auto_ptr((*iter)->specialized()); - this->lf_content_id = hash_string(string(prefix, len)); + this->set_format_base_time(this->lf_format.get()); + this->lf_content_id = hash_string(string(sbr.get_data(), sbr.length())); found = true; /* @@ -251,6 +252,8 @@ throw (line_buffer::error, logfile::error) /* Check for new data based on the file size. */ if (this->lf_index_size < st.st_size) { + bool has_format = this->lf_format.get() != NULL; + shared_buffer_ref sbr; off_t last_off, off; line_value lv; @@ -270,21 +273,39 @@ throw (line_buffer::error, logfile::error) off = 0; } last_off = off; - while (this->lf_line_buffer.read_line(off, lv)) { - char tmp = lv.lv_start[lv.lv_len]; + if (this->lf_logline_observer != NULL) { + this->lf_logline_observer->logline_restart(*this); + } + while (this->lf_line_buffer.read_line(off, sbr, &lv)) { + size_t old_size = this->lf_index.size(); this->lf_partial_line = lv.lv_partial; - lv.lv_start[lv.lv_len] = '\0'; - this->process_prefix(last_off, lv.lv_start, lv.lv_len); - lv.lv_start[lv.lv_len] = tmp; + this->process_prefix(last_off, sbr); last_off = off; + for (logfile::iterator iter = this->begin() + old_size; + iter != this->end(); ++iter) { + if (this->lf_format.get() != NULL) { + this->lf_format->get_subline(*iter, sbr); + } + if (this->lf_logline_observer != NULL) { + this->lf_logline_observer->logline_new_line(*this, iter, sbr); + } + } + if (lo != NULL) { lo->logfile_indexing( *this, this->lf_line_buffer.get_read_offset(off), st.st_size); } + + if (!has_format && this->lf_format.get() != NULL) { + break; + } + } + if (this->lf_logline_observer != NULL) { + this->lf_logline_observer->logline_eof(*this); } /* @@ -294,8 +315,6 @@ throw (line_buffer::error, logfile::error) */ this->lf_index_size = off; - // this->lf_line_buffer.invalidate(); - retval = true; } @@ -307,63 +326,6 @@ throw (line_buffer::error, logfile::error) return retval; } -logfile_filter::type_t logfile::check_filter(iterator ll, - uint8_t generation, - const filter_stack_t &filters) -{ - logfile_filter::type_t retval; - uint8_t this_generation = ll->get_filter_generation(); - - if (this_generation == generation) { - return ll->get_filter_state(); - } - else { - retval = logfile_filter::MAYBE; - } - - string line_value; - - for (size_t lpc = 0; lpc < filters.size(); lpc++) { - logfile_filter *filter = filters[lpc]; - bool matched; - - if (!filter->is_enabled()) - continue; - - if (line_value.empty()) - this->read_line(ll, line_value); - matched = filter->matches(*ll, line_value); - - switch (filter->get_type()) { - case logfile_filter::INCLUDE: - if (matched) { - // Always prefer including something. - retval = logfile_filter::INCLUDE; - } - else if (retval == logfile_filter::MAYBE) { - // Only exclude if we haven't made a decision yet. - retval = logfile_filter::EXCLUDE; - } - break; - - case logfile_filter::EXCLUDE: - if (matched && retval == logfile_filter::MAYBE) { - // Only exclude if we haven't decide to include the line. - retval = logfile_filter::EXCLUDE; - } - break; - - default: - require(0); - break; - } - } - - ll->set_filter_state(generation, retval); - - return retval; -} - void logfile::read_line(logfile::iterator ll, string &line_out) { try { @@ -463,3 +425,22 @@ void logfile::read_full_message(logfile::iterator ll, /* ... */ } } + +void logfile::set_logline_observer(logline_observer *llo) +{ + this->lf_logline_observer = llo; + this->reobserve_from(this->begin()); +} + +void logfile::reobserve_from(iterator iter) +{ + if (this->lf_logline_observer != NULL) { + for (; iter != this->end(); ++iter) { + shared_buffer_ref sbr; + + this->read_line(iter, sbr); + this->lf_logline_observer->logline_new_line(*this, iter, sbr); + } + this->lf_logline_observer->logline_eof(*this); + } +} diff --git a/src/logfile.hh b/src/logfile.hh index 114bf5e4..b8b1ba4a 100644 --- a/src/logfile.hh +++ b/src/logfile.hh @@ -48,6 +48,7 @@ #include "shared_buffer.hh" class logfile; +class logline_observer; /** * Observer interface for logfile indexing progress. @@ -181,12 +182,12 @@ public: const_iterator end() const { return this->lf_index.end(); } /** @return The number of lines in the index. */ - size_t size() { return this->lf_index.size(); } + size_t size() const { return this->lf_index.size(); } logline &operator[](int index) { return this->lf_index[index]; }; /** @return True if this log file still exists. */ - bool exists() const; + bool exists(void) const; void close() { this->lf_is_closed = true; @@ -278,25 +279,9 @@ public: bool rebuild_index(logfile_observer *lo = NULL) throw (line_buffer::error, logfile::error); - /** - * Check a line to see if it should be filtered out or not. - * - * XXX This code doesn't really belong here, it's something more - * approprtiate for the logfile_sub_source. The reason it is here right - * now is because we cache the result of the check in the logline object. - * - * @param ll The log line to check. - * @param generation The "generation" that the given filters belong to. - * If the cached value for this check is from the same - * filter generation, then we just return the cached - * value. - * @param filters The filters to apply. - * @return Whether or not the line should be included in the - * view. - */ - logfile_filter::type_t check_filter(iterator ll, - uint8_t generation, - const filter_stack_t &filters); + void reobserve_from(iterator iter); + + void set_logline_observer(logline_observer *llo); bool operator<(const logfile &rhs) const { @@ -332,7 +317,7 @@ protected: * @param prefix The contents of the line. * @param len The length of the 'prefix' string. */ - void process_prefix(off_t offset, char *prefix, int len); + void process_prefix(off_t offset, shared_buffer_ref &sbr); void set_format_base_time(log_format *lf); @@ -349,5 +334,18 @@ protected: struct timeval lf_time_offset; bool lf_is_closed; bool lf_partial_line; + logline_observer *lf_logline_observer; }; + +class logline_observer { +public: + virtual ~logline_observer() { }; + + virtual void logline_restart(const logfile &lf) = 0; + + virtual void logline_new_line(const logfile &lf, logfile::const_iterator ll, shared_buffer_ref &sbr) = 0; + + virtual void logline_eof(const logfile &lf) = 0; +}; + #endif diff --git a/src/logfile_sub_source.cc b/src/logfile_sub_source.cc index 0d39da44..25076c0f 100644 --- a/src/logfile_sub_source.cc +++ b/src/logfile_sub_source.cc @@ -38,89 +38,14 @@ using namespace std; -#if 0 -/* XXX */ -class logfile_scrub_map { -public: - - static logfile_scrub_map &singleton() - { - static logfile_scrub_map s_lsm; - - return s_lsm; - }; - - const pcre *include(logfile::format_t format) const - { - map::const_iterator iter; - pcre *retval = NULL; - - if ((iter = this->lsm_include.find(format)) != - this->lsm_include.end()) { - retval = iter->second; - } - - return retval; - }; - - const pcre *exclude(logfile::format_t format) const - { - map::const_iterator iter; - pcre *retval = NULL; - - if ((iter = this->lsm_exclude.find(format)) != - this->lsm_exclude.end()) { - retval = iter->second; - } - - return retval; - }; - -private: - - pcre *build_pcre(const char *pattern) - { - const char *errptr; - pcre * retval; - int eoff; - - retval = pcre_compile(pattern, PCRE_CASELESS, &errptr, &eoff, NULL); - if (retval == NULL) { - throw errptr; - } - - return retval; - }; - - logfile_scrub_map() - { - this->lsm_include[logfile::FORMAT_JBOSS] = this-> - build_pcre( - "\\d+-(\\d+-\\d+ \\d+:\\d+:\\d+),\\d+ [^ ]+( .*)"); - this->lsm_exclude[logfile::FORMAT_JBOSS] = this-> - build_pcre("(?:" - "\\[((?:[0-9a-zA-Z]+\\.)+)\\w+" - "|\\[[\\w: ]+ ((?:[0-9a-zA-Z]+\\.)+)\\w+[^ \\]]+" - "| ((?:[0-9a-zA-Z]+\\.)+)\\w+\\])"); - - this->lsm_include[logfile::FORMAT_SYSLOG] = this-> - build_pcre( - "(\\w+\\s[\\s\\d]\\d \\d+:\\d+:\\d+) \\w+( .*)"); - }; - - map lsm_include; - map lsm_exclude; -}; -#endif - bookmark_type_t logfile_sub_source::BM_ERRORS; bookmark_type_t logfile_sub_source::BM_WARNINGS; bookmark_type_t logfile_sub_source::BM_FILES; logfile_sub_source::logfile_sub_source() : lss_flags(0), - lss_filter_generation(1), - lss_filtered_count(0) + lss_filtered_count(0), + lss_min_log_level(logline::LEVEL_UNKNOWN) { this->clear_line_size_cache(); } @@ -131,15 +56,19 @@ logfile_sub_source::~logfile_sub_source() logfile *logfile_sub_source::find(const char *fn, content_line_t &line_base) { - std::vector::iterator iter; + iterator iter; logfile *retval = NULL; line_base = content_line_t(0); for (iter = this->lss_files.begin(); iter != this->lss_files.end() && retval == NULL; iter++) { - if (strcmp(iter->ld_file->get_filename().c_str(), fn) == 0) { - retval = iter->ld_file; + logfile_data &ld = *(*iter); + if (ld.get_file() == NULL) { + continue; + } + if (strcmp(ld.get_file()->get_filename().c_str(), fn) == 0) { + retval = ld.get_file(); } else { line_base += content_line_t(MAX_LINES_PER_FILE); @@ -151,7 +80,7 @@ logfile *logfile_sub_source::find(const char *fn, vis_line_t logfile_sub_source::find_from_time(const struct timeval &start) { - vector::iterator lb; + chunky_index::iterator lb; vis_line_t retval(-1); lb = lower_bound(this->lss_index.begin(), @@ -173,7 +102,7 @@ void logfile_sub_source::text_value_for_line(textview_curses &tc, content_line_t line(0); require(row >= 0); - require((size_t)row < this->lss_index.size()); + require((size_t)row < this->lss_filtered_index.size()); line = this->at(vis_line_t(row)); this->lss_token_file = this->find(line); @@ -328,7 +257,7 @@ void logfile_sub_source::text_attrs_for_line(textview_curses &lv, break; } - if ((row + 1) < (int)this->lss_index.size()) { + if ((row + 1) < (int)this->lss_filtered_index.size()) { next_line = this->find_line(this->at(vis_line_t(row + 1))); } @@ -438,7 +367,7 @@ void logfile_sub_source::text_attrs_for_line(textview_curses &lv, bool logfile_sub_source::rebuild_index(observer *obs, bool force) { - std::vector::iterator iter; + iterator iter; size_t total_lines = 0; bool retval = force; int file_count = 0; @@ -446,54 +375,50 @@ bool logfile_sub_source::rebuild_index(observer *obs, bool force) for (iter = this->lss_files.begin(); iter != this->lss_files.end(); iter++) { - if (iter->ld_file == NULL) { - if (iter->ld_lines_indexed > 0) { + if ((*iter)->get_file() == NULL) { + if ((*iter)->ld_lines_indexed > 0) { force = true; retval = true; } } else { - if (iter->ld_file->rebuild_index(obs)) { + if ((*iter)->get_file()->rebuild_index(obs)) { retval = true; } file_count += 1; - total_lines += iter->ld_file->size(); + total_lines += (*iter)->get_file()->size(); } } if (force) { for (iter = this->lss_files.begin(); iter != this->lss_files.end(); iter++) { - iter->ld_lines_indexed = 0; + (*iter)->ld_lines_indexed = 0; } + + this->lss_index.clear(); + this->lss_filtered_index.clear(); + this->lss_filtered_count = 0; } if (retval || force) { - size_t index_size = 0; - - if (force) { - this->lss_index.clear(); - this->lss_filtered_count = 0; - } + size_t index_size = 0, start_size = this->lss_index.size(); kmerge_tree_c merge(file_count); for (iter = this->lss_files.begin(); iter != this->lss_files.end(); iter++) { - if (iter->ld_file == NULL) + if ((*iter)->get_file() == NULL) continue; - merge.add(&(*iter), - iter->ld_file->begin() + iter->ld_lines_indexed, - iter->ld_file->end()); - index_size += iter->ld_file->size(); + merge.add((*iter), + (*iter)->get_file()->begin() + (*iter)->ld_lines_indexed, + (*iter)->get_file()->end()); + index_size += (*iter)->get_file()->size(); } - this->lss_index.reserve(index_size); - - logfile_filter::type_t action_for_prev_line = logfile_filter::MAYBE; - logfile_data *last_owner = NULL; + this->lss_index.reset(); merge.execute(); for (;;) { @@ -504,30 +429,12 @@ bool logfile_sub_source::rebuild_index(observer *obs, bool force) break; } - int file_index = ld - &(*this->lss_files.begin()); - int line_index = lf_iter - ld->ld_file->begin(); + int file_index = ld->ld_file_index; + int line_index = lf_iter - ld->get_file()->begin(); content_line_t con_line(file_index * MAX_LINES_PER_FILE + line_index); - if (!(lf_iter->get_level() & logline::LEVEL_CONTINUED)) { - if (last_owner != NULL) { - if (action_for_prev_line != logfile_filter::EXCLUDE) { - // Append all of the lines from the previous message. - while (last_owner->ld_indexing.ld_start <= - last_owner->ld_indexing.ld_last) { - this->lss_index.push_back(last_owner->ld_indexing.ld_start); - ++last_owner->ld_indexing.ld_start; - } - } - else { - this->lss_filtered_count += 1; - } - } - ld->ld_indexing.ld_start = con_line; - action_for_prev_line = logfile_filter::MAYBE; - } - if (obs != NULL) { obs->logfile_sub_source_filtering( *this, @@ -535,22 +442,13 @@ bool logfile_sub_source::rebuild_index(observer *obs, bool force) total_lines); } - ld->ld_indexing.ld_last = con_line; - if (action_for_prev_line != logfile_filter::INCLUDE) { - // We haven't decided to include yet, so check the filter again. - // Once we decide to include a sub-line, the whole log message will - // always be included. - logfile_filter::type_t action_for_this_line = ld->ld_file->check_filter( - lf_iter, this->lss_filter_generation, this->lss_filters); - - // Only record the filter results for this line if it's not decisive. - if (action_for_this_line != logfile_filter::MAYBE) { - action_for_prev_line = action_for_this_line; - } + off_t insert_point = this->lss_index.merge_value( + con_line, logline_cmp(*this)); + if (insert_point < start_size) { + start_size = 0; + this->lss_filtered_index.clear(); } - last_owner = ld; - merge.next(); } if (obs != NULL) { @@ -559,26 +457,33 @@ bool logfile_sub_source::rebuild_index(observer *obs, bool force) total_lines); } - if (last_owner != NULL) { - if (action_for_prev_line != logfile_filter::EXCLUDE) { - while (last_owner->ld_indexing.ld_start <= - last_owner->ld_indexing.ld_last) { - this->lss_index.push_back(last_owner->ld_indexing.ld_start); - ++last_owner->ld_indexing.ld_start; - } - } - else { - this->lss_filtered_count += 1; - } - } - for (iter = this->lss_files.begin(); iter != this->lss_files.end(); iter++) { - if (iter->ld_file == NULL) + if ((*iter)->get_file() == NULL) continue; - iter->ld_lines_indexed = iter->ld_file->size(); + (*iter)->ld_lines_indexed = (*iter)->get_file()->size(); + } + + this->lss_index.finish(); + + this->lss_filtered_index.reserve(this->lss_index.size()); + + uint32_t enabled_mask = this->get_filters().get_enabled_mask(); + + for (size_t index_index = start_size; + index_index < this->lss_index.size(); + index_index++) { + content_line_t cl = (content_line_t) this->lss_index[index_index]; + uint64_t line_number; + logfile_data *ld = this->find_data(cl, line_number); + + if (!ld->ld_filter_state.excluded(enabled_mask, line_number) && + (*(ld->get_file()->begin() + line_number)).get_msg_level() >= + this->lss_min_log_level) { + this->lss_filtered_index.push_back(index_index); + } } } @@ -601,7 +506,7 @@ void logfile_sub_source::text_update_marks(vis_bookmarks &bm) bm[iter->first].clear(); } - for (; vl < (int)this->lss_index.size(); ++vl) { + for (; vl < (int)this->lss_filtered_index.size(); ++vl) { const content_line_t orig_cl = this->at(vl); content_line_t cl = orig_cl; logfile * lf; @@ -671,70 +576,29 @@ log_accel::direction_t logfile_sub_source::get_line_accel_direction( return la.get_direction(); } -#if 0 -void logfile_sub_source::handle_scroll(listview_curses *lc) +void logfile_sub_source::text_filters_changed() { - printf("hello, world!\n"); - return; - - vis_line_t top = lc->get_top(); + for (iterator iter = this->begin(); iter != this->end(); ++iter) { + logfile_data *ld = *iter; + logfile *lf = ld->get_file(); - if (this->lss_index.empty()) { - this->lss_top_time = -1; - this->lss_bottom_time = -1; + if (lf != NULL) { + lf->reobserve_from(lf->begin() + ld->ld_filter_state.get_min_count(lf->size())); + } } - else { - time_t top_day, bottom_day, today, yesterday, now = time(NULL); - vis_line_t bottom(0), height(0); - - unsigned long width; - char status[32]; - logline * ll; - - today = day_num(now); - yesterday = today - 1; - - lc->get_dimensions(height, width); - ll = this->find_line(this->lss_index[top]); - this->lss_top_time = ll->get_time(); + uint32_t enabled_mask = this->get_filters().get_enabled_mask(); - bottom = min(top + height - vis_line_t(1), - vis_line_t(this->lss_index.size() - 1)); + this->lss_filtered_index.clear(); + for (size_t index_index = 0; index_index < this->lss_index.size(); index_index++) { + content_line_t cl = (content_line_t) this->lss_index[index_index]; + uint64_t line_number; + logfile_data *ld = this->find_data(cl, line_number); - ll = this->find_line(this->lss_index[bottom]); - this->lss_bottom_time = ll->get_time(); - - top_day = day_num(this->lss_top_time); - bottom_day = day_num(this->lss_bottom_time); - if (top_day == today) { - snprintf(status, sizeof(status), "Today"); - } - else if (top_day == yesterday) { - snprintf(status, sizeof(status), "Yesterday"); - } - else { - strftime(status, sizeof(status), - "%a %b %d", - gmtime(&this->lss_top_time)); + if (!ld->ld_filter_state.excluded(enabled_mask, line_number) && + (*(ld->get_file()->begin() + line_number)).get_msg_level() >= + this->lss_min_log_level) { + this->lss_filtered_index.push_back(index_index); } - if (top_day != bottom_day) { - int len = strlen(status); - - if (bottom_day == today) { - snprintf(&status[len], sizeof(status) - len, " - Today"); - } - else if (bottom_day == yesterday) { - snprintf(&status[len], sizeof(status) - len, " - Yesterday"); - } - else { - strftime(&status[len], sizeof(status) - len, - " - %b %d", - gmtime(&this->lss_bottom_time)); - } - } - - this->lss_date_field.set_value(string(status)); } } -#endif diff --git a/src/logfile_sub_source.hh b/src/logfile_sub_source.hh index 1e98329f..db5e1a0b 100644 --- a/src/logfile_sub_source.hh +++ b/src/logfile_sub_source.hh @@ -45,10 +45,69 @@ #include "strong_int.hh" #include "logfile.hh" #include "bookmarks.hh" +#include "chunky_index.hh" #include "textview_curses.hh" STRONG_INT_TYPE(uint64_t, content_line); +class line_filter_observer : public logline_observer { +public: + line_filter_observer(filter_stack &fs, logfile *lf) + : lfo_filter_stack(fs), lfo_filter_state(lf) { + + }; + + void logline_restart(const logfile &lf) { + for (filter_stack::iterator iter = this->lfo_filter_stack.begin(); + iter != this->lfo_filter_stack.end(); + ++iter) { + (*iter)->revert_to_last(this->lfo_filter_state); + } + }; + + void logline_new_line(const logfile &lf, logfile::const_iterator ll, shared_buffer_ref &sbr) { + long offset = std::distance(lf.begin(), ll); + + require(&lf == this->lfo_filter_state.tfs_logfile); + + this->lfo_filter_state.resize(lf.size()); + for (filter_stack::iterator iter = this->lfo_filter_stack.begin(); + iter != this->lfo_filter_stack.end(); + ++iter) { + if (offset >= this->lfo_filter_state.tfs_filter_count[(*iter)->get_index()]) { + (*iter)->add_line(this->lfo_filter_state, ll, sbr); + } + } + }; + + void logline_eof(const logfile &lf) { + for (filter_stack::iterator iter = this->lfo_filter_stack.begin(); + iter != this->lfo_filter_stack.end(); + ++iter) { + (*iter)->end_of_message(this->lfo_filter_state); + } + }; + + bool excluded(uint32_t enabled_mask, size_t offset) const { + return (this->lfo_filter_state.tfs_mask[offset] & enabled_mask) != 0; + }; + + size_t get_min_count(size_t max) const { + size_t retval = max; + + for (filter_stack::iterator iter = this->lfo_filter_stack.begin(); + iter != this->lfo_filter_stack.end(); + ++iter) { + retval = std::min(retval, this->lfo_filter_state.tfs_filter_count[(*iter)->get_index()]); + } + + return retval; + }; + + filter_stack &lfo_filter_stack; + logfile_filter_state lfo_filter_state; +}; + /** * Delegate class that merges the contents of multiple log files into a single * source of data for a text view. @@ -69,53 +128,11 @@ public: static bookmark_type_t BM_WARNINGS; static bookmark_type_t BM_FILES; + virtual void text_filters_changed(); + logfile_sub_source(); virtual ~logfile_sub_source(); - const filter_stack_t &get_filters(void) const - { - return this->lss_filters; - }; - - void add_filter(logfile_filter *filter) { - this->lss_filters.push_back(filter); - this->lss_filter_generation += 1; - }; - - void clear_filters(void) { - this->lss_filters.clear(); - this->lss_filter_generation += 1; - }; - - void filter_changed(void) { - this->lss_filter_generation += 1; - }; - - void set_filter_enabled(logfile_filter *filter, bool enabled) { - if (enabled) { - filter->enable(); - } - else { - filter->disable(); - } - this->lss_filter_generation += 1; - } - - logfile_filter *get_filter(std::string id) - { - filter_stack_t::iterator iter; - logfile_filter * retval = NULL; - - for (iter = this->lss_filters.begin(); - iter != this->lss_filters.end() && (*iter)->get_id() != id; - iter++) { } - if (iter != this->lss_filters.end()) { - retval = *iter; - } - - return retval; - }; - void toggle_scrub(void) { this->lss_flags ^= F_SCRUB; this->clear_line_size_cache(); @@ -135,15 +152,26 @@ public: }; bool is_time_offset_enabled(void) const { - return this->lss_flags & F_TIME_OFFSET; + return (bool) (this->lss_flags & F_TIME_OFFSET); + }; + + logline::level_t get_min_log_level(void) const { + return this->lss_min_log_level; + }; + + void set_min_log_level(logline::level_t level) { + if (this->lss_min_log_level != level) { + this->lss_min_log_level = level; + this->text_filters_changed(); + } }; size_t text_line_count() { - return this->lss_index.size(); + return this->lss_filtered_index.size(); }; - bool empty() const { return this->lss_index.empty(); }; + bool empty() const { return this->lss_filtered_index.empty(); }; void text_value_for_line(textview_curses &tc, int row, @@ -208,7 +236,7 @@ public: bool insert_file(logfile *lf) { - std::vector::iterator existing; + iterator existing; require(lf->size() < MAX_LINES_PER_FILE); @@ -220,11 +248,10 @@ public: return false; } - this->lss_files.push_back(logfile_data(lf)); - this->lss_index.clear(); + this->lss_files.push_back(new logfile_data(this->lss_files.size(), this->get_filters(), lf)); } else { - existing->ld_file = lf; + (*existing)->set_file(lf); } return true; @@ -232,7 +259,7 @@ public: void remove_file(logfile *lf) { - std::vector::iterator iter; + iterator iter; iter = std::find_if(this->lss_files.begin(), this->lss_files.end(), @@ -241,7 +268,7 @@ public: bookmarks::type::iterator mark_iter; int file_index = iter - this->lss_files.begin(); - iter->clear(); + (*iter)->clear(); for (mark_iter = this->lss_user_marks.begin(); mark_iter != this->lss_user_marks.end(); ++mark_iter) { @@ -291,7 +318,7 @@ public: { logfile *retval; - retval = this->lss_files[line / MAX_LINES_PER_FILE].ld_file; + retval = this->lss_files[line / MAX_LINES_PER_FILE]->get_file(); line = content_line_t(line % MAX_LINES_PER_FILE); return retval; @@ -320,7 +347,7 @@ public: }; content_line_t at(vis_line_t vl) { - return this->lss_index[vl]; + return this->lss_index[this->lss_filtered_index[vl]]; }; content_line_t at_base(vis_line_t vl) { @@ -338,16 +365,27 @@ public: * logfile have been indexed. */ struct logfile_data { - logfile_data(logfile *lf = NULL) - : ld_file(lf), - ld_lines_indexed(0) { }; + logfile_data(size_t index, filter_stack &fs, logfile *lf) + : ld_file_index(index), + ld_filter_state(fs, lf), + ld_lines_indexed(0) { + lf->set_logline_observer(&this->ld_filter_state); + }; void clear(void) { - this->ld_file = NULL; + this->ld_filter_state.lfo_filter_state.clear(); + }; + + void set_file(logfile *lf) { + this->ld_filter_state.lfo_filter_state.tfs_logfile = lf; + lf->set_logline_observer(&this->ld_filter_state); }; - logfile *ld_file; + logfile *get_file() const { return this->ld_filter_state.lfo_filter_state.tfs_logfile; }; + + size_t ld_file_index; + line_filter_observer ld_filter_state; size_t ld_lines_indexed; struct { content_line_t ld_start; @@ -355,7 +393,7 @@ public: } ld_indexing; }; - typedef std::vector::iterator iterator; + typedef std::vector::iterator iterator; iterator begin() { @@ -367,6 +405,16 @@ public: return this->lss_files.end(); }; + logfile_data *find_data(content_line_t line, uint64_t &offset_out) + { + logfile_data *retval; + + retval = this->lss_files[line / MAX_LINES_PER_FILE]; + offset_out = line % MAX_LINES_PER_FILE; + + return retval; + }; + content_line_t get_file_base_content_line(iterator iter) { int index = std::distance(this->begin(), iter); @@ -392,11 +440,15 @@ private: }; struct __attribute__((__packed__)) indexed_content { + indexed_content() { + + }; + indexed_content(content_line_t cl) : ic_value(cl) { }; - operator content_line_t () { + operator content_line_t () const { return content_line_t(this->ic_value); }; @@ -406,13 +458,14 @@ private: struct logline_cmp { logline_cmp(logfile_sub_source & lc) : llss_controller(lc) { }; - bool operator()(const content_line_t &lhs, const content_line_t &rhs) + bool operator()(const content_line_t &lhs, const content_line_t &rhs) const { logline *ll_lhs = this->llss_controller.find_line(lhs); logline *ll_rhs = this->llss_controller.find_line(rhs); return (*ll_lhs) < (*ll_rhs); }; + #if 0 bool operator()(const indexed_content &lhs, const indexed_content &rhs) { @@ -422,13 +475,13 @@ private: return (*ll_lhs) < (*ll_rhs); }; #endif - bool operator()(const content_line_t &lhs, const time_t &rhs) + bool operator()(const content_line_t &lhs, const time_t &rhs) const { logline *ll_lhs = this->llss_controller.find_line(lhs); return *ll_lhs < rhs; }; - bool operator()(const content_line_t &lhs, const struct timeval &rhs) + bool operator()(const content_line_t &lhs, const struct timeval &rhs) const { logline *ll_lhs = this->llss_controller.find_line(lhs); @@ -444,9 +497,9 @@ private: struct logfile_data_eq { logfile_data_eq(logfile *lf) : lde_file(lf) { }; - bool operator()(const logfile_data &ld) + bool operator()(const logfile_data *ld) { - return this->lde_file == ld.ld_file; + return this->lde_file == ld->get_file(); } logfile *lde_file; @@ -458,13 +511,12 @@ private: }; unsigned long lss_flags; - std::vector lss_files; + std::vector lss_files; - filter_stack_t lss_filters; - uint8_t lss_filter_generation; int lss_filtered_count; - std::vector lss_index; + chunky_index lss_index; + std::vector lss_filtered_index; bookmarks::type lss_user_marks; std::map lss_user_mark_metadata; @@ -477,5 +529,6 @@ private: 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; }; #endif diff --git a/src/ptimec.hh b/src/ptimec.hh index 88c3fcf6..a54bb956 100644 --- a/src/ptimec.hh +++ b/src/ptimec.hh @@ -34,7 +34,7 @@ // XXX #include - +#include #include #include #include @@ -361,6 +361,7 @@ inline bool ptime_y(struct exttm *dst, const char *str, off_t &off_inout, size_t } return true; } + return false; }); return true; @@ -390,13 +391,45 @@ inline bool ptime_z(struct exttm *dst, const char *str, off_t &off_inout, size_t mins = ( (str[off_inout + 2] - '0') * 10 + (str[off_inout + 3] - '0') * 1) * 60; - dst->et_tm.tm_gmtoff = hours + mins; + dst->et_tm.tm_gmtoff = sign * (hours + mins); }); #endif return true; } +inline bool ptime_f(int &sub_seconds, const char *str, off_t &off_inout, size_t len) +{ + PTIME_CONSUME(6, { + for (int lpc = 0; lpc < 6; lpc++) { + if (str[off_inout + lpc] < '0' || str[off_inout + lpc] > '9') { + return false; + } + } + sub_seconds = ( + (str[off_inout + 0] - '0') * 100000 + + (str[off_inout + 1] - '0') * 10000 + + (str[off_inout + 2] - '0') * 1000 + + (str[off_inout + 3] - '0') * 100 + + (str[off_inout + 4] - '0') * 10 + + (str[off_inout + 5] - '0') * 1); + }); + + return true; +} + +inline bool ptime_F(int &sub_seconds, const char *str, off_t &off_inout, size_t len) +{ + PTIME_CONSUME(3, { + sub_seconds = ( + (str[off_inout + 0] - '0') * 100 + + (str[off_inout + 1] - '0') * 10 + + (str[off_inout + 2] - '0') * 1); + }); + + return true; +} + inline bool ptime_char(char val, const char *str, off_t &off_inout, size_t len) { PTIME_CONSUME(1, { diff --git a/src/session_data.cc b/src/session_data.cc index d0edca4a..24d445c2 100644 --- a/src/session_data.cc +++ b/src/session_data.cc @@ -375,7 +375,7 @@ static void load_time_bookmarks(void) file_iter != lnav_data.ld_log_source.end(); ++file_iter) { char low_timestamp[64], high_timestamp[64]; - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); content_line_t base_content_line; if (lf == NULL) @@ -459,7 +459,7 @@ static void load_time_bookmarks(void) continue; } - if (!dts.scan(log_time, NULL, &log_tm, log_tv)) { + if (!dts.scan(log_time, strlen(log_time), NULL, &log_tm, log_tv)) { continue; } @@ -534,7 +534,7 @@ static void load_time_bookmarks(void) file_iter != lnav_data.ld_log_source.end(); ++file_iter) { char low_timestamp[64], high_timestamp[64]; - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); content_line_t base_content_line; if (lf == NULL) @@ -617,7 +617,7 @@ static void load_time_bookmarks(void) continue; } - if (!dts.scan(log_time, NULL, &log_tm, log_tv)) { + if (!dts.scan(log_time, strlen(log_time), NULL, &log_tm, log_tv)) { continue; } @@ -944,7 +944,7 @@ static void save_time_bookmarks(void) for (file_iter = lnav_data.ld_log_source.begin(); file_iter != lnav_data.ld_log_source.end(); ++file_iter) { - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); content_line_t base_content_line; if (lf == NULL) @@ -1031,7 +1031,7 @@ static void save_time_bookmarks(void) for (file_iter = lnav_data.ld_log_source.begin(); file_iter != lnav_data.ld_log_source.end(); ++file_iter) { - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); content_line_t base_content_line; if (lf == NULL) @@ -1072,10 +1072,10 @@ static void save_time_bookmarks(void) ++file_iter) { logfile::iterator line_iter; - if (file_iter->ld_file == NULL) + if ((*file_iter)->get_file() == NULL) continue; - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); if (!lf->is_time_adjusted()) continue; @@ -1236,41 +1236,48 @@ void save_session(void) view_map.gen("word_wrap"); view_map.gen(tc.get_word_wrap()); - } - } - root_map.gen("commands"); + text_sub_source *tss = tc.get_sub_source(); + if (tss == NULL) { + continue; + } - { - filter_stack_t::const_iterator filter_iter; - logfile_sub_source &lss = lnav_data.ld_log_source; - const filter_stack_t &fs = lss.get_filters(); + filter_stack::iterator filter_iter; + filter_stack &fs = tss->get_filters(); - yajlpp_array cmd_array(handle); + view_map.gen("commands"); + yajlpp_array cmd_array(handle); - for (filter_iter = fs.begin(); - filter_iter != fs.end(); - ++filter_iter) { - if (!(*filter_iter)->is_enabled()) { - continue; - } + for (filter_iter = fs.begin(); + filter_iter != fs.end(); + ++filter_iter) { + if (!(*filter_iter)->is_enabled()) { + continue; + } - cmd_array.gen((*filter_iter)->to_command()); - } + cmd_array.gen((*filter_iter)->to_command()); + } - textview_curses::highlight_map_t &hmap = - lnav_data.ld_views[LNV_LOG].get_highlights(); - textview_curses::highlight_map_t::iterator hl_iter; + textview_curses::highlight_map_t &hmap = + lnav_data.ld_views[LNV_LOG].get_highlights(); + textview_curses::highlight_map_t::iterator hl_iter; - for (hl_iter = hmap.begin(); - hl_iter != hmap.end(); - ++hl_iter) { - if (hl_iter->first[0] == '$') { - continue; + for (hl_iter = hmap.begin(); + hl_iter != hmap.end(); + ++hl_iter) { + if (hl_iter->first[0] == '$') { + continue; + } + cmd_array.gen("highlight " + hl_iter->first); } - cmd_array.gen("highlight " + hl_iter->first); } } + + root_map.gen("commands"); + + { + + } } yajl_gen_clear(handle); @@ -1305,18 +1312,18 @@ void reset_session(void) } } - lnav_data.ld_log_source.clear_filters(); - logfile_sub_source::iterator file_iter; for (file_iter = lnav_data.ld_log_source.begin(); file_iter != lnav_data.ld_log_source.end(); ++file_iter) { - logfile *lf = file_iter->ld_file; + logfile *lf = (*file_iter)->get_file(); lf->clear_time_offset(); } + lnav_data.ld_log_source.get_filters().clear_filters(); + lss.get_user_bookmarks()[&textview_curses::BM_USER].clear(); lss.get_user_bookmarks()[&textview_curses::BM_PARTITION].clear(); } diff --git a/src/textview_curses.cc b/src/textview_curses.cc index 23fa92fc..013c1130 100644 --- a/src/textview_curses.cc +++ b/src/textview_curses.cc @@ -36,10 +36,23 @@ #include "lnav_util.hh" #include "data_parser.hh" #include "ansi_scrubber.hh" +#include "log_format.hh" #include "textview_curses.hh" using namespace std; +void text_filter::add_line( + logfile_filter_state &lfs, logfile::const_iterator ll, shared_buffer_ref &line) { + bool match_state = this->matches(*lfs.tfs_logfile, *ll, line); + + if (!ll->is_continued()) { + this->end_of_message(lfs); + } + + this->lf_message_matched = this->lf_message_matched || match_state; + this->lf_lines_for_message += 1; +} + bookmark_type_t textview_curses::BM_USER; bookmark_type_t textview_curses::BM_PARTITION; bookmark_type_t textview_curses::BM_SEARCH; diff --git a/src/textview_curses.hh b/src/textview_curses.hh index 763822dd..fbd0fb1c 100644 --- a/src/textview_curses.hh +++ b/src/textview_curses.hh @@ -38,9 +38,216 @@ #include "bookmarks.hh" #include "listview_curses.hh" #include "lnav_log.hh" +#include "concise_index.hh" +#include "logfile.hh" +class logfile; +class logline; class textview_curses; +class logfile_filter_state { +public: + logfile_filter_state(logfile *lf = NULL) : tfs_logfile(lf) { + memset(this->tfs_filter_count, 0, sizeof(this->tfs_filter_count)); + this->tfs_mask.reserve(64 * 1024); + }; + + void clear(void) { + this->tfs_logfile = NULL; + memset(this->tfs_filter_count, 0, sizeof(this->tfs_filter_count)); + this->tfs_mask.clear(); + }; + + void resize(size_t newsize) { + size_t old_mask_size = this->tfs_mask.size(); + + this->tfs_mask.resize(newsize); + memset(&this->tfs_mask[old_mask_size], 0, sizeof(uint32_t) * (newsize - old_mask_size)); + }; + + const static int MAX_FILTERS = 32; + + logfile *tfs_logfile; + size_t tfs_filter_count[MAX_FILTERS]; + std::vector tfs_mask; +}; + +class text_filter { +public: + typedef enum { + MAYBE, + INCLUDE, + EXCLUDE, + + LFT__MAX, + + LFT__MASK = (MAYBE|INCLUDE|EXCLUDE) + } type_t; + + text_filter(type_t type, const std::string id, size_t index) + : lf_message_matched(false), + lf_lines_for_message(0), + lf_enabled(true), + lf_type(type), + lf_id(id), + lf_index(index) { }; + virtual ~text_filter() { }; + + type_t get_type(void) const { return this->lf_type; }; + std::string get_id(void) const { return this->lf_id; }; + size_t get_index(void) const { return this->lf_index; }; + + bool is_enabled(void) { return this->lf_enabled; }; + void enable(void) { this->lf_enabled = true; }; + void disable(void) { this->lf_enabled = false; }; + + void revert_to_last(logfile_filter_state &lfs) { + this->lf_message_matched = this->lf_last_message_matched; + this->lf_lines_for_message = this->lf_last_lines_for_message; + + for (size_t lpc = 0; lpc < this->lf_lines_for_message; lpc++) { + lfs.tfs_filter_count[this->lf_index] -= 1; + size_t line_number = lfs.tfs_filter_count[this->lf_index]; + + lfs.tfs_mask[line_number] &= ~(((uint32_t) 1) << this->lf_index); + } + } + + void add_line(logfile_filter_state &lfs, const logfile::const_iterator ll, shared_buffer_ref &line); + + void end_of_message(logfile_filter_state &lfs) { + uint32_t mask = 0; + + switch (this->get_type()) { + case INCLUDE: + if (!this->lf_message_matched) { + mask = ((uint32_t) 1) << this->lf_index; + } + break; + case EXCLUDE: + if (this->lf_message_matched) { + mask = ((uint32_t) 1) << this->lf_index; + } + break; + default: + break; + } + + for (size_t lpc = 0; lpc < this->lf_lines_for_message; lpc++) { + size_t line_number = lfs.tfs_filter_count[this->lf_index]; + + lfs.tfs_mask[line_number] |= mask; + lfs.tfs_filter_count[this->lf_index] += 1; + } + this->lf_last_message_matched = this->lf_message_matched; + this->lf_last_lines_for_message = this->lf_lines_for_message; + this->lf_message_matched = false; + this->lf_lines_for_message = 0; + }; + + virtual bool matches(const logfile &lf, const logline &ll, shared_buffer_ref &line) = 0; + + virtual std::string to_command(void) = 0; + + bool operator==(const std::string &rhs) { + return this->lf_id == rhs; + }; + + bool lf_message_matched; + size_t lf_lines_for_message; + bool lf_last_message_matched; + size_t lf_last_lines_for_message; + +protected: + bool lf_enabled; + type_t lf_type; + std::string lf_id; + size_t lf_index; +}; + +class filter_stack { +public: + typedef std::vector::iterator iterator; + + iterator begin() { + return this->fs_filters.begin(); + } + + iterator end() { + return this->fs_filters.end(); + } + + size_t size() const { + return this->fs_filters.size(); + } + + size_t next_index() { + bool used[32]; + + memset(used, 0, sizeof(used)); + for (iterator iter = this->begin(); iter != this->end(); ++iter) { + size_t index = (*iter)->get_index(); + + require(used[index] == false); + + used[index] = true; + } + for (size_t lpc = 0; lpc < logfile_filter_state::MAX_FILTERS; lpc++) { + if (!used[lpc]) { + return lpc; + } + } + throw "No more filters"; + }; + + void add_filter(text_filter *filter) { + this->fs_filters.push_back(filter); + }; + + void clear_filters(void) { + this->fs_filters.clear(); + }; + + void set_filter_enabled(text_filter *filter, bool enabled) { + if (enabled) { + filter->enable(); + } + else { + filter->disable(); + } + } + + text_filter *get_filter(std::string id) + { + std::vector::iterator iter; + text_filter * retval = NULL; + + for (iter = this->fs_filters.begin(); + iter != this->fs_filters.end() && (*iter)->get_id() != id; + iter++) { } + if (iter != this->fs_filters.end()) { + retval = *iter; + } + + return retval; + }; + + uint32_t get_enabled_mask() { + uint32_t retval = 0; + + for (iterator iter = this->begin(); iter != this->end(); ++iter) { + if ((*iter)->is_enabled()) { + retval |= (1L << (*iter)->get_index()); + } + } + + return retval; + }; + +private: + std::vector fs_filters; +}; + /** * Source for the text to be shown in a textview_curses view. */ @@ -116,6 +323,17 @@ public: virtual std::string text_source_name(const textview_curses &tv) { return ""; }; + + filter_stack &get_filters() { + return this->tss_filters; + }; + + virtual void text_filters_changed() { + + }; + +private: + filter_stack tss_filters; }; class text_delegate { diff --git a/test/drive_data_scanner.cc b/test/drive_data_scanner.cc index ad86a389..e03556c2 100644 --- a/test/drive_data_scanner.cc +++ b/test/drive_data_scanner.cc @@ -41,6 +41,7 @@ #include "data_parser.hh" #include "log_format.hh" #include "log_format_loader.hh" +#include "../src/shared_buffer.hh" using namespace std; @@ -120,6 +121,12 @@ int main(int argc, char *argv[]) log_line = (char *)alloca(line.length()); strcpy(log_line, &line[13]); + string sub_line = line.substr(13); + struct line_range body(0, sub_line.length()); + shared_buffer share_manager; + shared_buffer_ref sbr; + + sbr.share(share_manager, (char *)sub_line.c_str(), sub_line.size()); vector &root_formats = log_format::get_root_formats(); vector::iterator iter; @@ -130,20 +137,13 @@ int main(int argc, char *argv[]) iter != root_formats.end() && !found; ++iter) { (*iter)->clear(); - if ((*iter)->scan( - index, 13, log_line, strlen(log_line))) { + if ((*iter)->scan(index, 13, sbr)) { format = (*iter)->specialized(); found = true; } } } - string sub_line = line.substr(13); - struct line_range body(0, sub_line.length()); - shared_buffer share_manager; - shared_buffer_ref sbr; - - sbr.share(share_manager, (char *)sub_line.c_str(), sub_line.size()); if (format.get() != NULL) { vector ll_values; string_attrs_t sa; diff --git a/test/drive_logfile.cc b/test/drive_logfile.cc index 59e7f777..152ac8ee 100644 --- a/test/drive_logfile.cc +++ b/test/drive_logfile.cc @@ -105,6 +105,7 @@ int main(int argc, char *argv[]) stat(argv[0], &st); assert(strcmp(argv[0], lf.get_filename().c_str()) == 0); + lf.rebuild_index(); lf.rebuild_index(); if (expected_format == "") { assert(lf.get_format() == NULL); diff --git a/test/logfile_for_join.0 b/test/logfile_for_join.0 new file mode 100644 index 00000000..b811ae97 --- /dev/null +++ b/test/logfile_for_join.0 @@ -0,0 +1,10 @@ +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: New relevant interface eth0.IPv4 for mDNS. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.1.10.103. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Registering new address record for 10.1.10.103 on eth0. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Withdrawing address record for 10.1.10.103 on eth0. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Leaving mDNS multicast group on interface eth0.IPv4 with address 10.1.10.103. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: iface.c: interface_mdns_mcast_join() called but no local address available. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Interface eth0.IPv4 no longer relevant for mDNS. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: New relevant interface eth0.IPv4 for mDNS. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.1.10.103. +Apr 28 06:53:55 tstack-centos5 avahi-daemon[2467]: Registering new address record for 10.1.10.103 on eth0. diff --git a/test/test_chunky_index.cc b/test/test_chunky_index.cc index 2182e276..5eac9d15 100644 --- a/test/test_chunky_index.cc +++ b/test/test_chunky_index.cc @@ -21,12 +21,15 @@ int main(int argc, char *argv[]) { chunky_index ci; + off_t off; ci.reset(); - ci.merge_value(1); + off = ci.merge_value(1); + assert(off == 0); ci.finish(); ci.reset(); - ci.merge_value(2); + off = ci.merge_value(2); + assert(off == 1); ci.finish(); assert(ci.size() == 2); @@ -42,6 +45,7 @@ int main(int argc, char *argv[]) { int expected[] = {0, 10, 11, 20, 30, 40, 50, 60, 70, 80, 90, 100}; chunky_index ci; + off_t off; ci.reset(); for (int lpc = 0; lpc < 11; lpc++) { @@ -49,7 +53,8 @@ int main(int argc, char *argv[]) } ci.finish(); ci.reset(); - ci.merge_value(11); + off = ci.merge_value(11); + assert(off == 2); ci.finish(); for (int lpc = 0; lpc < 12; lpc++) { assert(expected[lpc] == ci[lpc]); diff --git a/test/test_date_time_scanner.cc b/test/test_date_time_scanner.cc index 9928dc5c..8a4d7504 100644 --- a/test/test_date_time_scanner.cc +++ b/test/test_date_time_scanner.cc @@ -56,7 +56,7 @@ int main(int argc, char *argv[]) struct timeval tv; struct exttm tm; - assert(dts.scan(BAD_TIMES[lpc], NULL, &tm, tv) == NULL); + assert(dts.scan(BAD_TIMES[lpc], strlen(BAD_TIMES[lpc]), NULL, &tm, tv) == NULL); } { @@ -67,8 +67,8 @@ int main(int argc, char *argv[]) date_time_scanner dts; if (setlocale(LC_TIME, "es_ES.utf8") != NULL) { - assert(dts.scan(en_date, NULL, &en_tm, en_tv) != NULL); - assert(dts.scan(bg_date, NULL, &es_tm, es_tv) != NULL); + assert(dts.scan(en_date, strlen(en_date), NULL, &en_tm, en_tv) != NULL); + assert(dts.scan(bg_date, strlen(bg_date), NULL, &es_tm, es_tv) != NULL); } } } diff --git a/test/test_logfile.sh b/test/test_logfile.sh index 49f076bd..b93140c0 100644 --- a/test/test_logfile.sh +++ b/test/test_logfile.sh @@ -140,15 +140,15 @@ EOF run_test ./drive_logfile -v -f strace_log ${srcdir}/logfile_strace_log.0 check_output "strace_log level interpreted incorrectly?" <