[formats] add windows event log tabular format

Related to #557

Author: tstack

src/CMakeLists.txt

@@ -119,6 +119,7 @@ set(TIME_FORMATS
         "%m/%e/%Y %l:%M:%S %p%z"
         "%m/%e/%Y %l:%M:%S %p %z"
         "%m/%e/%Y %I:%M:%S %p"
+        "%m/%e/%Y %l:%M:%S %p"
         "%m/%e/%Y %l:%M:%S%p"
         "%m/%d/%y %H:%M:%S"
         "%m/%d/%Y %H:%M:%S"
@@ -240,6 +241,7 @@ set(FORMAT_FILES
         formats/vmw_vc_svc_log.json
         formats/vmw_py_log.json
         formats/vpostgres_log.json
+        formats/windows_event_log.json
         formats/xmlrpc_log.json
         formats/zookeeper_log.json
 )

src/base/file_range.hh

@@ -67,7 +67,7 @@ public:
         this->fr_size = 0;
     }
 
-    ssize_t next_offset() const { return this->fr_offset + this->fr_size; }
+    file_ssize_t next_offset() const { return this->fr_offset + this->fr_size; }
 
     bool empty() const { return this->fr_size == 0; }
 };

src/formats/formats.am

@@ -68,6 +68,7 @@ FORMAT_FILES = \
     $(srcdir)/%reldir%/vmw_py_log.json \
     $(srcdir)/%reldir%/vpostgres_log.json \
     $(srcdir)/%reldir%/web_robot_log.json \
+    $(srcdir)/%reldir%/windows_event_log.json \
     $(srcdir)/%reldir%/xmlrpc_log.json \
     $(srcdir)/%reldir%/zap_console_log.json \
     $(srcdir)/%reldir%/zellij_log.json \

src/formats/windows_event_log.json

@@ -0,0 +1,103 @@
+{
+    "$schema": "https://lnav.org/schemas/format-v1.schema.json",
+    "windows_event_log": {
+        "title": "Windows Event Log (PowerShell CSV)",
+        "description": "Windows event log exported via `Get-WinEvent | Export-Csv -NoTypeInformation`. Multi-line `Message` cells need to be flattened to a single line before export, e.g. `Get-WinEvent ... | Select-Object *, @{n='Message';e={$_.Message -replace '[\\r\\n]+',' '}} -ExcludeProperty Message | Export-Csv ...`.",
+        "url": "https://learn.microsoft.com/en-us/powershell/module/microsoft.powershell.diagnostics/get-winevent",
+        "file-type": "tabular",
+        "timestamp-field": "TimeCreated",
+        "level-field": "LevelDisplayName",
+        "body-field": "Message",
+        "opid-field": "ActivityId",
+        "value": {
+            "Message": {
+                "kind": "string"
+            },
+            "Id": {
+                "kind": "integer",
+                "identifier": true
+            },
+            "Version": {
+                "kind": "integer"
+            },
+            "Qualifiers": {
+                "kind": "integer"
+            },
+            "Level": {
+                "kind": "integer"
+            },
+            "Task": {
+                "kind": "integer"
+            },
+            "Opcode": {
+                "kind": "integer"
+            },
+            "Keywords": {
+                "kind": "string"
+            },
+            "RecordId": {
+                "kind": "integer",
+                "foreign-key": true
+            },
+            "ProviderName": {
+                "kind": "string",
+                "identifier": true
+            },
+            "ProviderId": {
+                "kind": "string"
+            },
+            "LogName": {
+                "kind": "string",
+                "identifier": true
+            },
+            "ProcessId": {
+                "kind": "integer",
+                "identifier": true
+            },
+            "ThreadId": {
+                "kind": "integer",
+                "identifier": true
+            },
+            "MachineName": {
+                "kind": "string",
+                "identifier": true
+            },
+            "UserId": {
+                "kind": "string",
+                "identifier": true
+            },
+            "TimeCreated": {
+                "kind": "string"
+            },
+            "ActivityId": {
+                "kind": "string",
+                "identifier": true
+            },
+            "RelatedActivityId": {
+                "kind": "string",
+                "identifier": true
+            },
+            "ContainerLog": {
+                "kind": "string"
+            },
+            "MatchedQueryIds": {
+                "kind": "string"
+            },
+            "Bookmark": {
+                "kind": "string"
+            },
+            "LevelDisplayName": {
+                "kind": "string"
+            },
+            "OpcodeDisplayName": {
+                "kind": "string"
+            },
+            "TaskDisplayName": {
+                "kind": "string"
+            },
+            "KeywordsDisplayNames": {
+                "kind": "string"
+            }
+        }
+    }
+}

src/log_format.cc

@@ -2231,7 +2231,7 @@ external_log_format::scan_tabular(logfile& lf,
     auto sf = sbr.to_string_fragment();
     if (this->lf_specialized) {
         auto& ll = dst.back();
-        if (dst.size() <= this->tlf_header_lines) {
+        if (li.li_file_range.fr_offset < this->tlf_header_end) {
             // ignore header
             ll.set_ignore(true);
             return scan_match{1000};
@@ -2318,10 +2318,9 @@ external_log_format::scan_tabular(logfile& lf,
         }
         if (value_index >= this->elf_value_def_read_order.size()) {
             this->finalize_line(dst.back(), lfi, sbc);
+        } else if (sf.startswith("#")) {
+            ll.set_ignore(true);
         } else {
-            if (sf.startswith("#")) {
-                ll.set_ignore(true);
-            }
             ll.set_level(LEVEL_INVALID);
         }
 
@@ -2338,7 +2337,7 @@ external_log_format::scan_tabular(logfile& lf,
 
     auto header_state = tabular_header_state::reading_metadata;
     std::optional<char> sep;
-    for (auto ll_iter = dst.begin(); ll_iter != dst.end(); ++ll_iter) {
+    for (auto ll_iter = lf.begin(); ll_iter != lf.end(); ++ll_iter) {
         auto read_res = lf.read_line(ll_iter);
         if (read_res.isErr()) {
             return scan_no_match{"cannot read header"};
@@ -2356,17 +2355,11 @@ external_log_format::scan_tabular(logfile& lf,
                     return scan_error{"sep= hint missing separator character"};
                 }
                 sep = sep_sf.data()[0];
-                ll_iter->set_time(std::chrono::microseconds::zero());
-                ll_iter->set_level(LEVEL_UNKNOWN);
-                ll_iter->set_ignore(true);
                 log_info("  %ld:found 'sep=' header: %x",
                          std::distance(dst.begin(), ll_iter),
                          sep.value());
             } else if (hdr_sf.startswith("#")) {
-                ll_iter->set_time(std::chrono::microseconds::zero());
-                ll_iter->set_level(LEVEL_UNKNOWN);
-                ll_iter->set_ignore(true);
-                log_info("  %ld:ignoring comment -- %.*s",
+                log_info("  %ld:comment header -- %.*s",
                          std::distance(dst.begin(), ll_iter),
                          hdr_sf.length(),
                          hdr_sf.data());
@@ -2382,10 +2375,6 @@ external_log_format::scan_tabular(logfile& lf,
                 ss.ss_separator = sep.value();
                 uint32_t hits = 0, misses = 0;
 
-                log_info("  %ld:found header -- %.*s",
-                         std::distance(dst.begin(), ll_iter),
-                         hdr_sf.length(),
-                         hdr_sf.data());
                 this->elf_value_def_read_order.clear();
                 for (auto hdr_name : ss) {
                     auto value_iter
@@ -2403,13 +2392,25 @@ external_log_format::scan_tabular(logfile& lf,
                 if (hits <= 2) {
                     return scan_no_match{"not enough columns matched"};
                 }
+
+                for (auto prev_iter = dst.begin(); prev_iter != ll_iter;
+                     ++prev_iter)
+                {
+                    prev_iter->set_time(std::chrono::microseconds::zero());
+                    prev_iter->set_level(LEVEL_UNKNOWN);
+                    prev_iter->set_ignore(true);
+                }
+
+                log_info("  %ld:found column header -- %.*s",
+                         std::distance(dst.begin(), ll_iter),
+                         hdr_sf.length(),
+                         hdr_sf.data());
+
                 header_state = tabular_header_state::have_column_header;
-                auto& ll = dst.back();
-                ll.set_ignore(true);
-                ll.set_level(LEVEL_INVALID);
+                ll_iter->set_ignore(true);
+                ll_iter->set_level(LEVEL_INVALID);
                 this->tlf_separator = sep.value();
-                this->tlf_header_lines
-                    = std::distance(dst.begin(), ll_iter) + 1;
+                this->tlf_header_end = li.li_file_range.next_offset();
                 return scan_match{1000, misses, hits};
             }
         }
@@ -4893,7 +4894,6 @@ external_log_format::build(std::vector<lnav::console::user_message>& errors)
             yajl_config(
                 this->jlf_yajl_handle.get(), yajl_dont_validate_strings, 1);
         } else if (this->elf_type == elf_type_t::ELF_TYPE_TABULAR) {
-            this->lf_multiline = false;
             this->lf_structured = true;
         }
     } else {

src/log_format_ext.hh

@@ -523,7 +523,7 @@ public:
     std::shared_ptr<yajl_handle_t> jlf_yajl_handle;
     shared_buffer jlf_share_manager;
 
-    size_t tlf_header_lines{0};
+    file_ssize_t tlf_header_end;
     char tlf_separator{','};
 
 private:

src/logfile.cc

@@ -861,15 +861,25 @@ logfile::process_prefix(shared_buffer_ref& sbr,
         if (this->lf_format == nullptr && li.li_timestamp.tv_sec != 0) {
             last_time = to_us(li.li_timestamp);
             last_level = li.li_level;
-        } else if (!this->lf_index.empty()) {
-            const auto& ll = this->lf_index.back();
+        } else {
+            for (auto riter = this->lf_index.rbegin();
+                 riter != this->lf_index.rend();
+                 ++riter)
+            {
+                if (riter->is_ignored()
+                    || riter->get_msg_level() == LEVEL_INVALID)
+                {
+                    continue;
+                }
 
-            /*
-             * Assume this line is part of the previous one(s) and copy the
-             * metadata over.
-             */
-            last_time = ll.get_time();
-            last_level = ll.get_msg_level();
+                /*
+                 * Assume this line is part of the previous one(s) and copy the
+                 * metadata over.
+                 */
+                last_time = riter->get_time();
+                last_level = riter->get_msg_level();
+                break;
+            }
         }
         this->lf_index.emplace_back(
             li.li_file_range.fr_offset, last_time, last_level);
@@ -1313,10 +1323,16 @@ logfile::process_prefix(shared_buffer_ref& sbr,
         }
     } else if (found.is<log_format::scan_no_match>()) {
         if (this->lf_format.get() != nullptr) {
+            auto& ll = this->lf_index.back();
             if (this->lf_format->lf_multiline) {
-                this->lf_index.back().set_continued(true);
+                if (this->lf_index.size() > 1) {
+                    auto& prev_ll = this->lf_index[this->lf_index.size() - 2];
+                    if (prev_ll.is_continued() || !prev_ll.is_ignored()) {
+                        ll.set_continued(true);
+                    }
+                }
             } else {
-                this->lf_index.back().set_level(LEVEL_INVALID);
+                ll.set_level(LEVEL_INVALID);
             }
         }
     }

src/time_formats.am

@@ -88,6 +88,7 @@ TIME_FORMATS = \
     "%m/%e/%Y %l:%M:%S %p%z" \
     "%m/%e/%Y %l:%M:%S %p %z" \
     "%m/%e/%Y %I:%M:%S %p" \
+    "%m/%e/%Y %l:%M:%S %p" \
     "%m/%e/%Y %l:%M:%S%p" \
     "%m/%d/%y %H:%M:%S" \
     "%m/%d/%Y %H:%M:%S" \

src/view_helpers.cc

@@ -1501,7 +1501,7 @@ hist_index_delegate::index_line(logfile_sub_source& lss,
                                 logfile* lf,
                                 logfile::iterator ll)
 {
-    if (ll->is_continued()
+    if (!ll->is_message()
         || ll->get_time<>() == std::chrono::microseconds::zero())
     {
         return;

test/Makefile.am

@@ -463,6 +463,7 @@ dist_noinst_DATA = \
 	logfile_w3c.5 \
 	logfile_w3c.6 \
 	logfile_w3c_big.0 \
+	logfile_win_events_csv.0 \
 	logfile_with_a_really_long_name_to_test_a_bug_with_long_names.0 \
 	logfile_with_zones.0 \
 	logfile_xml_msg.0 \