Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(scanner): dynamic reordering of successful matchers #124

Merged
merged 2 commits into from
Dec 5, 2024

Conversation

aybabtme
Copy link
Collaborator

@aybabtme aybabtme commented Nov 10, 2024

do not merge until there's more tests and benchmarks available.

To add a plethora more matching rules, I suspect that performance will degrade for the least frequently used matchers. The ordering in which we match lines is set at build time, and based on my guess as to which format is seen most often.

I suspect that:

  • most program will use the same logging format thorough
  • programs that use >1 format (not that uncommon, libraries using their own logger, etc) will still reuse mostly the same few formats
  • keeping matchers in the order of their most recent use should work well, as I suspect that the probability of log line N being of format A is highly related to line N-1 also being of format A.

@aybabtme aybabtme force-pushed the adaptive-matcher-ordering branch from 06c1514 to 5ba165b Compare December 5, 2024 14:13
@aybabtme
Copy link
Collaborator Author

aybabtme commented Dec 5, 2024

With benchmarks:

goos: darwin
goarch: arm64
pkg: github.com/humanlogio/humanlog
cpu: Apple M1 Pro
                                                    │  /tmp/old   │               /tmp/new                │
                                                    │   sec/op    │    sec/op      vs base                │
Harness/test/benchmark/c-cpp-glog-10                  2.916m ± 2%    3.067m ±  1%   +5.17% (p=0.000 n=10)
Harness/test/benchmark/c-cpp-spdlog-10                941.0µ ± 1%   1143.1µ ±  1%  +21.47% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-10                 1.743m ± 6%    2.145m ±  1%  +23.07% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-csv-10             1.412m ± 2%    1.550m ±  1%   +9.83% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-json-10            511.6m ± 2%    525.7m ±  3%   +2.75% (p=0.011 n=10)
Harness/test/benchmark/csharp-serilog-10              1.565m ± 4%    1.854m ±  1%  +18.48% (p=0.000 n=10)
Harness/test/benchmark/csharp-serilog-json-10         8.022m ± 3%    9.333m ±  1%  +16.35% (p=0.000 n=10)
Harness/test/benchmark/golang-gin-10                  883.1µ ± 1%   1055.4µ ±  1%  +19.52% (p=0.000 n=10)
Harness/test/benchmark/golang-logrus-10               3.036m ± 3%    2.664m ±  4%  -12.26% (p=0.000 n=10)
Harness/test/benchmark/golang-logrus-json-10          683.9m ± 1%    732.6m ±  3%   +7.11% (p=0.000 n=10)
Harness/test/benchmark/golang-slog-json-10             1.378 ± 1%     1.417 ±  6%        ~ (p=0.190 n=10)
Harness/test/benchmark/golang-zap-10                  5.158m ± 2%    5.704m ± 11%  +10.59% (p=0.035 n=10)
Harness/test/benchmark/golang-zerolog-10              3.467m ± 3%    2.897m ±  2%  -16.44% (p=0.000 n=10)
Harness/test/benchmark/golang-zerolog-json-10         5.662m ± 1%    5.364m ±  2%   -5.26% (p=0.000 n=10)
Harness/test/benchmark/java-log4j2-10                 1.895m ± 4%    1.874m ±  5%        ~ (p=0.393 n=10)
Harness/test/benchmark/java-log4j2-json-10            11.16m ± 2%    10.55m ±  1%   -5.45% (p=0.000 n=10)
Harness/test/benchmark/java-logback-10                2.173m ± 2%    2.059m ±  2%   -5.25% (p=0.000 n=10)
Harness/test/benchmark/java-logback-ext-10            2.633m ± 2%    2.498m ±  1%   -5.16% (p=0.000 n=10)
Harness/test/benchmark/java-logback-ext-json-10       14.52m ± 2%    14.05m ±  2%   -3.24% (p=0.000 n=10)
Harness/test/benchmark/java-logback-json-10           14.48m ± 1%    13.98m ±  1%   -3.45% (p=0.000 n=10)
Harness/test/benchmark/java-logback-mdc-10            2.469m ± 2%    2.319m ±  1%   -6.08% (p=0.000 n=10)
Harness/test/benchmark/java-logback-mdc-json-10       14.50m ± 2%    13.94m ±  3%   -3.82% (p=0.000 n=10)
Harness/test/benchmark/js-ts-bunyan-10                14.57m ± 2%    14.21m ±  3%   -2.45% (p=0.019 n=10)
Harness/test/benchmark/js-ts-pino-10                  8.076m ± 1%    8.015m ±  1%        ~ (p=0.579 n=10)
Harness/test/benchmark/js-ts-winston-10               13.57m ± 2%    13.08m ±  2%   -3.61% (p=0.000 n=10)
Harness/test/benchmark/opentelemetry-10               1.384m ± 4%    1.374m ±  1%        ~ (p=0.579 n=10)
Harness/test/benchmark/opentelemetry-json-10          15.29m ± 3%    14.27m ±  1%   -6.66% (p=0.000 n=10)
Harness/test/benchmark/python-loguru-10               4.128m ± 3%    4.115m ±  1%        ~ (p=0.481 n=10)
Harness/test/benchmark/python-loguru-json-10          13.43m ± 3%    12.52m ±  2%   -6.77% (p=0.000 n=10)
Harness/test/benchmark/python-structlog-10            1.351m ± 4%    1.301m ±  1%   -3.69% (p=0.003 n=10)
Harness/test/benchmark/ruby-semantic-logger-10        2.120m ± 2%    2.139m ±  2%        ~ (p=0.052 n=10)
Harness/test/benchmark/ruby-semantic-logger-json-10   9.135m ± 4%    8.289m ±  3%   -9.26% (p=0.000 n=10)
Harness/test/benchmark/ruby-std-logger-10             1.728m ± 5%    1.584m ±  1%   -8.32% (p=0.000 n=10)
Harness/test/benchmark/rust-log4rs-10                 2.004m ± 1%    1.748m ±  2%  -12.78% (p=0.000 n=10)
geomean                                               6.324m         6.323m         -0.02%

                                                    │   /tmp/old    │               /tmp/new                │
                                                    │      B/s      │      B/s       vs base                │
Harness/test/benchmark/c-cpp-glog-10                   31.97Mi ± 2%   30.40Mi ±  1%   -4.91% (p=0.000 n=10)
Harness/test/benchmark/c-cpp-spdlog-10                 89.06Mi ± 1%   73.31Mi ±  1%  -17.68% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-10                  68.68Mi ± 5%   55.80Mi ±  1%  -18.75% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-csv-10              71.82Mi ± 2%   65.39Mi ±  1%   -8.95% (p=0.000 n=10)
Harness/test/benchmark/csharp-nlog-json-10             43.59Mi ± 2%   42.41Mi ±  3%   -2.69% (p=0.011 n=10)
Harness/test/benchmark/csharp-serilog-10               71.84Mi ± 4%   60.63Mi ±  1%  -15.60% (p=0.000 n=10)
Harness/test/benchmark/csharp-serilog-json-10          35.97Mi ± 3%   30.92Mi ±  1%  -14.05% (p=0.000 n=10)
Harness/test/benchmark/golang-gin-10                   220.1Mi ± 1%   184.1Mi ±  1%  -16.33% (p=0.000 n=10)
Harness/test/benchmark/golang-logrus-10                77.06Mi ± 3%   87.82Mi ±  4%  +13.97% (p=0.000 n=10)
Harness/test/benchmark/golang-logrus-json-10           38.06Mi ± 1%   35.53Mi ±  3%   -6.64% (p=0.000 n=10)
Harness/test/benchmark/golang-slog-json-10             42.07Mi ± 1%   40.91Mi ±  6%        ~ (p=0.184 n=10)
Harness/test/benchmark/golang-zap-10                   37.72Mi ± 2%   34.11Mi ± 13%   -9.58% (p=0.035 n=10)
Harness/test/benchmark/golang-zerolog-10               42.26Mi ± 3%   50.56Mi ±  2%  +19.65% (p=0.000 n=10)
Harness/test/benchmark/golang-zerolog-json-10          42.61Mi ± 1%   44.98Mi ±  3%   +5.55% (p=0.000 n=10)
Harness/test/benchmark/java-log4j2-10                  73.20Mi ± 3%   74.03Mi ±  5%        ~ (p=0.393 n=10)
Harness/test/benchmark/java-log4j2-json-10             44.77Mi ± 2%   47.35Mi ±  1%   +5.76% (p=0.000 n=10)
Harness/test/benchmark/java-logback-10                 67.22Mi ± 2%   70.95Mi ±  2%   +5.55% (p=0.000 n=10)
Harness/test/benchmark/java-logback-ext-10             69.94Mi ± 2%   73.75Mi ±  1%   +5.44% (p=0.000 n=10)
Harness/test/benchmark/java-logback-ext-json-10        36.77Mi ± 2%   38.01Mi ±  2%   +3.36% (p=0.000 n=10)
Harness/test/benchmark/java-logback-json-10            36.64Mi ± 1%   37.95Mi ±  1%   +3.58% (p=0.000 n=10)
Harness/test/benchmark/java-logback-mdc-10             78.30Mi ± 2%   83.37Mi ±  1%   +6.47% (p=0.000 n=10)
Harness/test/benchmark/java-logback-mdc-json-10        36.55Mi ± 2%   38.00Mi ±  3%   +3.97% (p=0.000 n=10)
Harness/test/benchmark/js-ts-bunyan-10                 32.86Mi ± 2%   33.69Mi ±  3%   +2.51% (p=0.024 n=10)
Harness/test/benchmark/js-ts-pino-10                   31.97Mi ± 1%   32.21Mi ±  1%        ~ (p=0.579 n=10)
Harness/test/benchmark/js-ts-winston-10                35.82Mi ± 2%   37.16Mi ±  2%   +3.74% (p=0.000 n=10)
Harness/test/benchmark/opentelemetry-10                65.37Mi ± 4%   65.87Mi ±  1%        ~ (p=0.579 n=10)
Harness/test/benchmark/opentelemetry-json-10           34.36Mi ± 3%   36.81Mi ±  1%   +7.13% (p=0.000 n=10)
Harness/test/benchmark/python-loguru-10                48.35Mi ± 3%   48.50Mi ±  1%        ~ (p=0.481 n=10)
Harness/test/benchmark/python-loguru-json-10           25.86Mi ± 3%   27.74Mi ±  2%   +7.25% (p=0.000 n=10)
Harness/test/benchmark/python-structlog-10             92.77Mi ± 4%   96.33Mi ±  1%   +3.83% (p=0.003 n=10)
Harness/test/benchmark/ruby-semantic-logger-10        100.37Mi ± 2%   99.46Mi ±  2%        ~ (p=0.052 n=10)
Harness/test/benchmark/ruby-semantic-logger-json-10    35.00Mi ± 4%   38.58Mi ±  2%  +10.20% (p=0.000 n=10)
Harness/test/benchmark/ruby-std-logger-10              72.68Mi ± 4%   79.26Mi ±  1%   +9.06% (p=0.000 n=10)
Harness/test/benchmark/rust-log4rs-10                  47.52Mi ± 1%   54.48Mi ±  2%  +14.65% (p=0.000 n=10)
geomean                                                51.90Mi        51.90Mi         +0.02%

@aybabtme aybabtme merged commit 830f990 into master Dec 5, 2024
6 checks passed
@aybabtme aybabtme deleted the adaptive-matcher-ordering branch December 5, 2024 14:40
@aybabtme
Copy link
Collaborator Author

aybabtme commented Dec 6, 2024

The benchmarks having gains here are those that we want to support (logfmt, etc) and the losses on the JSON log inputs aren't big enough to justify not merging.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant