[json_log] auto detect the required width for a column

Related to #1146

NEWS.md

@@ -7,6 +7,15 @@ Features:
   operate on the selected line instead.
 * Added CTRL-D and CTRL-U hotkeys to move down/up by half
   a page.
+* Added an `auto-width` flag to the elements of the
+  `line-format` array that indicates that the width of the
+  field should automatically be determined by the observed
+  values.
+* Number fields used in a `line-format` now default to
+  being right-aligned.
+
+Bug Fixes:
+* Hidden values in JSON logs are now hidden by default.
 
 ## lnav v0.11.1
 

docs/schemas/format-v1.schema.json

@@ -472,6 +472,11 @@
                                 "type": "integer",
                                 "minimum": 0
                             },
+                            "auto-width": {
+                                "title": "/<format_name>/line-format/auto-width",
+                                "description": "Automatically detect the necessary width of the field based on the observed values",
+                                "type": "boolean"
+                            },
                             "max-width": {
                                 "title": "/<format_name>/line-format/max-width",
                                 "description": "The maximum width of the field",

docs/source/formats.rst

@@ -138,7 +138,7 @@ object with the following fields:
   converted from the raw JSON encoding into this format.  Each element
   is either an object that defines which fields should be inserted into
   the final message string and or a string constant that should be
-  inserted.  For example, the following configuration will tranform each
+  inserted.  For example, the following configuration will transform each
   log message object into a string that contains the timestamp, followed
   by a space, and then the message body:
 
@@ -164,6 +164,8 @@ object with the following fields:
   :max-width: The maximum width for the field.  If the value for the field
     in a given log message is longer, the overflow algorithm will be applied
     to try and shorten the field. (v0.8.2+)
+  :auto-width: Flag that indicates that the width of the field should
+    automatically be set to the widest value seen. (v0.11.2)
   :align: Specifies the alignment for the field, either "left" or "right".
     If "left", padding to meet the minimum-width will be added on the right.
     If "right", padding will be added on the left. (v0.8.2+)

src/log_format.cc

@@ -459,17 +459,27 @@ read_json_bool(yajlpp_parse_context* ypc, int val)
 }
 
 static int
-read_json_int(yajlpp_parse_context* ypc, long long val)
+read_json_number(yajlpp_parse_context* ypc,
+                 const char* numberVal,
+                 size_t numberLen)
 {
     json_log_userdata* jlu = (json_log_userdata*) ypc->ypc_userdata;
     const intern_string_t field_name = ypc->get_path();
 
+    auto number_frag = string_fragment::from_bytes(numberVal, numberLen);
+    auto scan_res = scn::scan_value<double>(number_frag.to_string_view());
+    if (!scan_res) {
+        log_error("invalid number %.*s", numberLen, numberVal);
+        return 0;
+    }
+
+    auto val = scan_res.value();
     if (jlu->jlu_format->lf_timestamp_field == field_name) {
         long long divisor = jlu->jlu_format->elf_timestamp_divisor;
         struct timeval tv;
 
         tv.tv_sec = val / divisor;
-        tv.tv_usec = (val % divisor) * (1000000.0 / divisor);
+        tv.tv_usec = fmod(val, divisor) * (1000000.0 / divisor);
         if (jlu->jlu_format->lf_date_time.dts_local_time) {
             struct tm ltm;
             localtime_r(&tv.tv_sec, &ltm);
@@ -488,34 +498,26 @@ read_json_int(yajlpp_parse_context* ypc, long long val)
                 break;
             case log_format::subsecond_unit::micro:
                 millis = std::chrono::duration_cast<std::chrono::milliseconds>(
-                             std::chrono::microseconds(val))
+                             std::chrono::microseconds((int64_t) val))
                              .count();
                 break;
             case log_format::subsecond_unit::nano:
                 millis = std::chrono::duration_cast<std::chrono::milliseconds>(
-                             std::chrono::nanoseconds(val))
+                             std::chrono::nanoseconds((int64_t) val))
                              .count();
                 break;
         }
         jlu->jlu_base_line->set_millis(millis);
     } else if (jlu->jlu_format->elf_level_field == field_name) {
         if (jlu->jlu_format->elf_level_pairs.empty()) {
-            char level_buf[128];
-
-            snprintf(level_buf, sizeof(level_buf), "%lld", val);
-
             jlu->jlu_base_line->set_level(jlu->jlu_format->convert_level(
-                string_fragment::from_c_str(level_buf),
+                number_frag, jlu->jlu_batch_context));
-                jlu->jlu_batch_context));
         } else {
-            std::vector<std::pair<int64_t, log_level_t>>::iterator iter;
+            int64_t level_int = val;
 
-            for (iter = jlu->jlu_format->elf_level_pairs.begin();
+            for (const auto& pair : jlu->jlu_format->elf_level_pairs) {
-                 iter != jlu->jlu_format->elf_level_pairs.end();
+                if (pair.first == level_int) {
-                 ++iter)
+                    jlu->jlu_base_line->set_level(pair.second);
-            {
-                if (iter->first == val) {
-                    jlu->jlu_base_line->set_level(iter->second);
                     break;
                 }
             }
@@ -523,7 +525,11 @@ read_json_int(yajlpp_parse_context* ypc, long long val)
     }
 
     jlu->jlu_sub_line_count
-        += jlu->jlu_format->value_line_count(field_name, ypc->is_level(1));
+        += jlu->jlu_format->value_line_count(field_name,
+                                             ypc->is_level(1),
+                                             val,
+                                             (const unsigned char*) numberVal,
+                                             numberLen);
 
     return 1;
 }
@@ -553,7 +559,7 @@ read_json_double(yajlpp_parse_context* ypc, double val)
     }
 
     jlu->jlu_sub_line_count
-        += jlu->jlu_format->value_line_count(field_name, ypc->is_level(1));
+        += jlu->jlu_format->value_line_count(field_name, ypc->is_level(1), val);
 
     return 1;
 }
@@ -599,8 +605,7 @@ static const struct json_path_container json_log_handlers = {
     yajlpp::pattern_property_handler("\\w+")
         .add_cb(read_json_null)
         .add_cb(read_json_bool)
-        .add_cb(read_json_int)
+        .add_cb(read_json_number)
-        .add_cb(read_json_double)
         .add_cb(read_json_field),
 };
 
@@ -965,6 +970,23 @@ external_log_format::scan(logfile& lf,
             }
         }
 
+        for (const auto& ivd : fpat->p_value_by_index) {
+            if (!ivd.ivd_value_def->vd_meta.lvm_values_index) {
+                continue;
+            }
+
+            auto cap = md[ivd.ivd_index];
+
+            if (cap && cap->is_valid()) {
+                auto& lvs = this->lf_value_stats[ivd.ivd_value_def->vd_meta
+                                                     .lvm_values_index.value()];
+
+                if (cap->length() > lvs.lvs_width) {
+                    lvs.lvs_width = cap->length();
+                }
+            }
+        }
+
         for (auto value_index : fpat->p_numeric_value_indexes) {
             const indexed_value_def& ivd = fpat->p_value_by_index[value_index];
             const value_def& vd = *ivd.ivd_value_def;
@@ -996,7 +1018,8 @@ external_log_format::scan(logfile& lf,
                     if (scaling != nullptr) {
                         scaling->scale(dvalue);
                     }
-                    this->lf_value_stats[vd.vd_values_index].add_value(dvalue);
+                    this->lf_value_stats[vd.vd_meta.lvm_values_index.value()]
+                        .add_value(dvalue);
                 }
             }
         }
@@ -1344,7 +1367,7 @@ read_json_field(yajlpp_parse_context* ypc, const unsigned char* str, size_t len)
     }
 
     jlu->jlu_sub_line_count += jlu->jlu_format->value_line_count(
-        field_name, ypc->is_level(1), str, len);
+        field_name, ypc->is_level(1), nonstd::nullopt, str, len);
 
     return 1;
 }
@@ -1579,9 +1602,18 @@ external_log_format::get_subline(const logline& ll,
                                     }
                                 }
                             } else {
+                                value_def* vd = nullptr;
+
+                                if (lv_iter->lv_meta.lvm_values_index) {
+                                    vd = this->elf_value_def_order
+                                             [lv_iter->lv_meta.lvm_values_index
+                                                  .value()]
+                                                 .get();
+                                }
                                 sub_offset
-                                    += count(str.begin(), str.end(), '\n');
+                                    += std::count(str.begin(), str.end(), '\n');
-                                this->json_append(jfe, str.c_str(), str.size());
+                                this->json_append(
+                                    jfe, vd, str.c_str(), str.size());
                             }
 
                             if (nl_pos == std::string::npos || full_message) {
@@ -1650,9 +1682,11 @@ external_log_format::get_subline(const logline& ll,
                                    || jfe.jfe_value.pp_value
                                        == this->elf_level_field)
                         {
-                            this->json_append(jfe, ll.get_level_name(), -1);
+                            this->json_append(
+                                jfe, nullptr, ll.get_level_name(), -1);
                         } else {
                             this->json_append(jfe,
+                                              nullptr,
                                               jfe.jfe_default_value.c_str(),
                                               jfe.jfe_default_value.size());
                         }
@@ -2448,27 +2482,27 @@ external_log_format::build(std::vector<lnav::console::user_message>& errors)
         }
     }
 
-    for (auto& elf_value_def : this->elf_value_defs) {
+    size_t value_def_index = 0;
-        if (elf_value_def.second->vd_foreign_key
+    for (auto& elf_value_def : this->elf_value_def_order) {
-            || elf_value_def.second->vd_meta.lvm_identifier)
+        elf_value_def->vd_meta.lvm_values_index
+            = nonstd::make_optional(value_def_index++);
+
+        if (elf_value_def->vd_foreign_key
+            || elf_value_def->vd_meta.lvm_identifier)
         {
             continue;
         }
 
-        switch (elf_value_def.second->vd_meta.lvm_kind) {
+        switch (elf_value_def->vd_meta.lvm_kind) {
             case value_kind_t::VALUE_INTEGER:
             case value_kind_t::VALUE_FLOAT:
-                elf_value_def.second->vd_values_index
+                this->elf_numeric_value_defs.push_back(elf_value_def);
-                    = this->elf_numeric_value_defs.size();
-                this->elf_numeric_value_defs.push_back(elf_value_def.second);
                 break;
             default:
                 break;
         }
     }
 
-    this->lf_value_stats.resize(this->elf_numeric_value_defs.size());
-
     int format_index = 0;
     for (auto iter = this->jlf_line_format.begin();
          iter != this->jlf_line_format.end();
@@ -2522,6 +2556,20 @@ external_log_format::build(std::vector<lnav::console::user_message>& errors)
                                     .append_quoted(jfe.jfe_value.pp_value)
                                     .append(" is not a defined value"))
                             .with_snippet(jfe.jfe_value.to_snippet()));
+                } else {
+                    switch (vd_iter->second->vd_meta.lvm_kind) {
+                        case value_kind_t::VALUE_INTEGER:
+                        case value_kind_t::VALUE_FLOAT:
+                            if (jfe.jfe_align
+                                == json_format_element::align_t::NONE)
+                            {
+                                jfe.jfe_align
+                                    = json_format_element::align_t::RIGHT;
+                            }
+                            break;
+                        default:
+                            break;
+                    }
                 }
                 break;
             }
@@ -2595,6 +2643,8 @@ external_log_format::build(std::vector<lnav::console::user_message>& errors)
                 .with_attrs(attrs);
         }
     }
+
+    this->lf_value_stats.resize(this->elf_value_defs.size());
 }
 
 void
@@ -2811,7 +2861,7 @@ external_log_format::specialized(int fmt_lock)
     }
 
     this->lf_value_stats.clear();
-    this->lf_value_stats.resize(this->elf_numeric_value_defs.size());
+    this->lf_value_stats.resize(this->elf_value_defs.size());
 
     return retval;
 }
@@ -2841,8 +2891,9 @@ external_log_format::match_mime_type(const file_format_t ff) const
 long
 external_log_format::value_line_count(const intern_string_t ist,
                                       bool top_level,
+                                      nonstd::optional<double> val,
                                       const unsigned char* str,
-                                      ssize_t len) const
+                                      ssize_t len)
 {
     const auto iter = this->elf_value_defs.find(ist);
     long line_count
@@ -2852,6 +2903,16 @@ external_log_format::value_line_count(const intern_string_t ist,
         return (this->jlf_hide_extra || !top_level) ? 0 : line_count;
     }
 
+    if (iter->second->vd_meta.lvm_values_index) {
+        auto& lvs = this->lf_value_stats[iter->second->vd_meta.lvm_values_index
+                                             .value()];
+        if (len > lvs.lvs_width) {
+            lvs.lvs_width = len;
+        }
+        if (val) {
+            lvs.add_value(val.value());
+        }
+    }
     if (iter->second->vd_meta.is_hidden()) {
         return 0;
     }
@@ -2951,6 +3012,7 @@ external_log_format::get_value_meta(intern_string_t field_name,
 void
 external_log_format::json_append(
     const external_log_format::json_format_element& jfe,
+    const value_def* vd,
     const char* value,
     ssize_t len)
 {
@@ -2960,12 +3022,32 @@ external_log_format::json_append(
     if (jfe.jfe_align == json_format_element::align_t::RIGHT) {
         if (len < jfe.jfe_min_width) {
             this->json_append_to_cache(jfe.jfe_min_width - len);
+        } else if (jfe.jfe_auto_width && vd != nullptr
+                   && len < this->lf_value_stats[vd->vd_meta.lvm_values_index
+                                                     .value()]
+                                .lvs_width)
+        {
+            this->json_append_to_cache(
+                this->lf_value_stats[vd->vd_meta.lvm_values_index.value()]
+                    .lvs_width
+                - len);
         }
     }
     this->json_append_to_cache(value, len);
-    if (jfe.jfe_align == json_format_element::align_t::LEFT) {
+    if (jfe.jfe_align == json_format_element::align_t::LEFT
+        || jfe.jfe_align == json_format_element::align_t::NONE)
+    {
         if (len < jfe.jfe_min_width) {
             this->json_append_to_cache(jfe.jfe_min_width - len);
+        } else if (jfe.jfe_auto_width && vd != nullptr
+                   && len < this->lf_value_stats[vd->vd_meta.lvm_values_index
+                                                     .value()]
+                                .lvs_width)
+        {
+            this->json_append_to_cache(
+                this->lf_value_stats[vd->vd_meta.lvm_values_index.value()]
+                    .lvs_width
+                - len);
         }
     }
 }
@@ -3043,6 +3125,9 @@ logline_value_stats::merge(const logline_value_stats& other)
 
     require(other.lvs_min_value <= other.lvs_max_value);
 
+    if (other.lvs_width > this->lvs_width) {
+        this->lvs_width = other.lvs_width;
+    }
     if (other.lvs_min_value < this->lvs_min_value) {
         this->lvs_min_value = other.lvs_min_value;
     }

src/log_format.hh

@@ -129,6 +129,7 @@ struct logline_value_meta {
     intern_string_t lvm_name;
     value_kind_t lvm_kind;
     int lvm_column{-1};
+    nonstd::optional<size_t> lvm_values_index;
     bool lvm_identifier{false};
     bool lvm_hidden{false};
     bool lvm_user_hidden{false};
@@ -258,6 +259,7 @@ struct logline_value_stats {
 
     void clear()
     {
+        this->lvs_width = 0;
         this->lvs_count = 0;
         this->lvs_total = 0;
         this->lvs_min_value = std::numeric_limits<double>::max();
@@ -268,6 +270,7 @@ struct logline_value_stats {
 
     void add_value(double value);
 
+    int64_t lvs_width;
     int64_t lvs_count;
     double lvs_total;
     double lvs_min_value;

src/log_format_ext.hh

@@ -71,7 +71,6 @@ public:
         bool vd_foreign_key{false};
         intern_string_t vd_unit_field;
         std::map<const intern_string_t, scaling_factor> vd_unit_scaling;
-        ssize_t vd_values_index{-1};
         bool vd_internal{false};
         std::vector<std::string> vd_action_list;
         std::string vd_rewriter;
@@ -186,18 +185,15 @@ public:
     const logline_value_stats* stats_for_value(
         const intern_string_t& name) const
     {
-        const logline_value_stats* retval = nullptr;
+        auto iter = this->elf_value_defs.find(name);
-
+        if (iter != this->elf_value_defs.end()
-        for (size_t lpc = 0; lpc < this->elf_numeric_value_defs.size(); lpc++) {
+            && iter->second->vd_meta.lvm_values_index)
-            value_def& vd = *this->elf_numeric_value_defs[lpc];
+        {
-
+            return &this->lf_value_stats[iter->second->vd_meta.lvm_values_index
-            if (vd.vd_meta.lvm_name == name) {
+                                             .value()];
-                retval = &this->lf_value_stats[lpc];
-                break;
-            }
         }
 
-        return retval;
+        return nullptr;
     }
 
     void get_subline(const logline& ll,
@@ -232,6 +228,7 @@ public:
 
     struct json_format_element {
         enum class align_t {
+            NONE,
             LEFT,
             RIGHT,
         };
@@ -253,8 +250,9 @@ public:
         positioned_property<intern_string_t> jfe_value;
         std::string jfe_default_value{"-"};
         long long jfe_min_width{0};
+        bool jfe_auto_width{false};
         long long jfe_max_width{LLONG_MAX};
-        align_t jfe_align{align_t::LEFT};
+        align_t jfe_align{align_t::NONE};
         overflow_t jfe_overflow{overflow_t::ABBREV};
         transform_t jfe_text_transform{transform_t::NONE};
         std::string jfe_ts_format;
@@ -286,8 +284,9 @@ public:
 
     long value_line_count(const intern_string_t ist,
                           bool top_level,
+                          nonstd::optional<double> val = nonstd::nullopt,
                           const unsigned char* str = nullptr,
-                          ssize_t len = -1) const;
+                          ssize_t len = -1);
 
     bool has_value_def(const intern_string_t ist) const
     {
@@ -397,6 +396,7 @@ public:
     }
 
     void json_append(const json_format_element& jfe,
+                     const value_def* vd,
                      const char* value,
                      ssize_t len);
 

src/log_format_loader.cc

@@ -480,6 +480,11 @@ static const struct json_path_container line_format_handlers = {
         .with_description("The minimum width of the field")
         .for_field(&external_log_format::json_format_element::jfe_min_width),
 
+    yajlpp::property_handler("auto-width")
+        .with_description("Automatically detect the necessary width of the "
+                          "field based on the observed values")
+        .for_field(&external_log_format::json_format_element::jfe_auto_width),
+
     yajlpp::property_handler("max-width")
         .with_min_value(0)
         .with_synopsis("<size>")

src/yajlpp/yajlpp.cc

@@ -764,6 +764,9 @@ yajlpp_parse_context::update_callbacks(const json_path_container* orig_handlers,
                 this->ypc_callbacks.yajl_integer
                     = jph.jph_callbacks.yajl_integer;
             }
+            if (jph.jph_callbacks.yajl_number != nullptr) {
+                this->ypc_callbacks.yajl_number = jph.jph_callbacks.yajl_number;
+            }
             if (jph.jph_callbacks.yajl_double != nullptr) {
                 this->ypc_callbacks.yajl_double = jph.jph_callbacks.yajl_double;
             }
@@ -1125,6 +1128,11 @@ yajlpp_parse_context::set_static_handler(const json_path_handler_base& jph)
     if (jph.jph_callbacks.yajl_integer != nullptr) {
         this->ypc_callbacks.yajl_integer = jph.jph_callbacks.yajl_integer;
     }
+    if (jph.jph_callbacks.yajl_number != nullptr) {
+        this->ypc_callbacks.yajl_number = jph.jph_callbacks.yajl_number;
+    } else {
+        this->ypc_callbacks.yajl_number = nullptr;
+    }
     if (jph.jph_callbacks.yajl_double != nullptr) {
         this->ypc_callbacks.yajl_double = jph.jph_callbacks.yajl_double;
     }

src/yajlpp/yajlpp_def.hh

@@ -79,6 +79,17 @@ struct json_path_handler : public json_path_handler_base {
         this->jph_callbacks.yajl_double = (int (*)(void*, double)) double_func;
     }
 
+    template<typename P>
+    json_path_handler(P path,
+                      int (*number_func)(yajlpp_parse_context*,
+                                         const char* numberVal,
+                                         size_t numberLen))
+        : json_path_handler_base(path)
+    {
+        this->jph_callbacks.yajl_number
+            = (int (*)(void*, const char*, size_t)) number_func;
+    }
+
     template<typename P>
     json_path_handler(P path) : json_path_handler_base(path)
     {
@@ -125,6 +136,15 @@ struct json_path_handler : public json_path_handler_base {
         return *this;
     }
 
+    json_path_handler& add_cb(int (*number_func)(yajlpp_parse_context*,
+                                                 const char*,
+                                                 size_t))
+    {
+        this->jph_callbacks.yajl_number
+            = (int (*)(void*, const char*, size_t)) number_func;
+        return *this;
+    }
+
     json_path_handler& add_cb(int (*str_func)(yajlpp_parse_context*,
                                               const unsigned char*,
                                               size_t))

test/expected/test_json_format.sh_4315a3d6124c14cbe3c474b6dbf4cc8720a9859f.out

@@ -1,3 +1,3 @@
-2017-03-24T20:06:26.240 1.1.1.1 GET 200 /example/uri/5
+2017-03-24T20:06:26.240 1.1.1.1 GET 200   443 /example/uri/5
-2017-03-24T20:12:47.764 1.1.1.1 GET 500 /example/uri/5
+2017-03-24T20:12:47.764 1.1.1.1 GET 500  4433 /example/uri/5
-2017-03-24T20:15:31.694 1.1.1.1 GET 400 /example/uri/5
+2017-03-24T20:15:31.694 1.1.1.1 GET 400 44345 /example/uri/5

test/expected/test_json_format.sh_469f005b0708d629bc95f0c48a5e390f440c1fef.out

@@ -1,29 +1,29 @@
 
-[2013-09-06T20:00:48.124] TRACE trace test
+[2013-09-06T20:00:48.124] TRACE    trace test
 
-[2013-09-06T20:00:49.124] INFO Starting up service
+[2013-09-06T20:00:49.124] INFO     Starting up service
 
-[2013-09-06T22:00:49.124] INFO Shutting down service
+[2013-09-06T22:00:49.124] INFO     Shutting down service
   user: steve@example.com
 
-[2013-09-06T22:00:59.124] DEBUG5 Details...
+[2013-09-06T22:00:59.124] DEBUG5   Details...
 
-[2013-09-06T22:00:59.124] DEBUG4 Details...
+[2013-09-06T22:00:59.124] DEBUG4   Details...
 
-[2013-09-06T22:00:59.124] DEBUG3 Details...
+[2013-09-06T22:00:59.124] DEBUG3   Details...
 
-[2013-09-06T22:00:59.124] DEBUG2 Details...
+[2013-09-06T22:00:59.124] DEBUG2   Details...
 
-[2013-09-06T22:00:59.124] DEBUG Details...
+[2013-09-06T22:00:59.124] DEBUG    Details...
 
-[2013-09-06T22:01:49.124] STATS 1 beat per second
+[2013-09-06T22:01:49.124] STATS    1 beat per second
 
-[2013-09-06T22:01:49.124] WARNING not looking good
+[2013-09-06T22:01:49.124] WARNING  not looking good
 
-[2013-09-06T22:01:49.124] ERROR looking bad
+[2013-09-06T22:01:49.124] ERROR    looking bad
 
 [2013-09-06T22:01:49.124] CRITICAL sooo bad
 
-[2013-09-06T22:01:49.124] FATAL shoot
+[2013-09-06T22:01:49.124] FATAL    shoot
   obj: { "field1" : "hi", "field2": 2 }
   arr: ["hi", {"sub1": true}]

test/expected/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out

@@ -1,4 +1,4 @@
 
-[-09-06T22:00:49.124] INFO Shutting down service
+[-09-06T22:00:49.124] INFO     Shutting down service
   user: steve@example.com
 

test/expected/test_json_format.sh_d0ec34389274affb70a5a76ba4789d51fd60f602.out

@@ -1,4 +1,4 @@
-log_line,log_part,log_time,log_idle_msecs,log_level,log_mark,log_comment,log_tags,log_filters,client_ip,request/method,request/uri,request/size,response/status,details1,details2,details3
+log_line,log_part,log_time,log_idle_msecs,log_level,log_mark,log_comment,log_tags,log_filters,client_ip,request/method,request/uri,request/size,response/status,response/size,details1,details2,details3
-0,<NULL>,2017-03-24 20:06:26.240,0,info,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,200,<NULL>,<NULL>,<NULL>
+0,<NULL>,2017-03-24 20:06:26.240,0,info,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,200,443,<NULL>,<NULL>,<NULL>
-1,<NULL>,2017-03-24 20:12:47.764,381524,critical,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,500,<NULL>,<NULL>,<NULL>
+1,<NULL>,2017-03-24 20:12:47.764,381524,critical,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,500,4433,<NULL>,<NULL>,<NULL>
-2,<NULL>,2017-03-24 20:15:31.694,163930,warning,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,400,"{""foo"": ""bar""}","{""foo"": ""bar""}","{""foo"": ""bar""}"
+2,<NULL>,2017-03-24 20:15:31.694,163930,warning,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,400,44345,"{""foo"": ""bar""}","{""foo"": ""bar""}","{""foo"": ""bar""}"

test/expected/test_json_format.sh_d7362cffc8335c2fe6b6527315de59bd6f5dcc7f.out

@@ -1,3 +1,3 @@
-2017-03-24T16:06:26.240 1.1.1.1 GET 200 /example/uri/5
+2017-03-24T16:06:26.240 1.1.1.1 GET 200   443 /example/uri/5
-2017-03-24T16:12:47.764 1.1.1.1 GET 500 /example/uri/5
+2017-03-24T16:12:47.764 1.1.1.1 GET 500  4433 /example/uri/5
-2017-03-24T16:15:31.694 1.1.1.1 GET 400 /example/uri/5
+2017-03-24T16:15:31.694 1.1.1.1 GET 400 44345 /example/uri/5

test/expected/test_json_format.sh_dfff27a651650a04d93de9a06ab5480e94ce3a79.out

@@ -1,4 +1,4 @@
-log_line,log_part,log_time,log_idle_msecs,log_level,log_mark,log_comment,log_tags,log_filters,client_ip,request/method,request/uri,request/size,response/status,details1,details2,details3
+log_line,log_part,log_time,log_idle_msecs,log_level,log_mark,log_comment,log_tags,log_filters,client_ip,request/method,request/uri,request/size,response/status,response/size,details1,details2,details3
-0,<NULL>,2017-03-24 16:06:26.240,0,info,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,200,<NULL>,<NULL>,<NULL>
+0,<NULL>,2017-03-24 16:06:26.240,0,info,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,200,443,<NULL>,<NULL>,<NULL>
-1,<NULL>,2017-03-24 16:12:47.764,381524,critical,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,500,<NULL>,<NULL>,<NULL>
+1,<NULL>,2017-03-24 16:12:47.764,381524,critical,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,500,4433,<NULL>,<NULL>,<NULL>
-2,<NULL>,2017-03-24 16:15:31.694,163930,warning,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,400,"{""foo"": ""bar""}","{""foo"": ""bar""}","{""foo"": ""bar""}"
+2,<NULL>,2017-03-24 16:15:31.694,163930,warning,0,<NULL>,<NULL>,<NULL>,1.1.1.1,GET,/example/uri/5,166,400,44345,"{""foo"": ""bar""}","{""foo"": ""bar""}","{""foo"": ""bar""}"

test/formats/jsontest/format.json

@@ -12,7 +12,8 @@
             },
             "] ",
             {
-                "field": "lvl"
+                "field": "lvl",
+                "auto-width": true
             },
             " ",
             {

test/formats/jsontest3/format.json

@@ -24,6 +24,11 @@
                 "field": "response/status"
             },
             " ",
+            {
+                "field": "response/size",
+                "auto-width": true
+            },
+            " ",
             {
                 "field": "request/uri"
             }
@@ -51,7 +56,11 @@
                 "hidden": true
             },
             "response/status": {
-                "kind": "string"
+                "kind": "integer",
+                "foreign-key": true
+            },
+            "response/size": {
+                "kind": "integer"
             },
             "details1": {
                 "hidden": true

test/logfile_json3.json

@@ -1,3 +1,3 @@
-{ "started_at": 1490385986240, "response": { "status": 200, "size": "443", "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1" }
+{ "started_at": 1490385986240, "response": { "status": 200, "size": 443, "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1" }
-{ "started_at": 1490386367764.0, "response": { "status": 500, "size": "443", "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1" }
+{ "started_at": 1490386367764.0, "response": { "status": 500, "size": 4433, "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1" }
-{ "started_at": 1490386531694, "response": { "status": 400, "size": "443", "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1", "details1": {"foo": "bar"}, "details2": {"foo": "bar"}, "details3": {"foo": "bar"} }
+{ "started_at": 1490386531694, "response": { "status": 400, "size": 44345, "headers": { "server": "nginx\/1.11.10", "content-type": "application\/json", "connection": "close", "cache-control": "max-age=0, must-revalidate, no-cache, no-store, private" } }, "request": { "method": "GET", "uri": "\/example\/uri\/5", "size": "166", "querystring": {}, "headers": { "host": "example.com" } }, "client_ip": "1.1.1.1", "details1": {"foo": "bar"}, "details2": {"foo": "bar"}, "details3": {"foo": "bar"} }