Make INFO log level less verbose

[mitasov-ra]

Describe the feature request INFO log level provides only informative logs, not everything.

What you are trying to do I have maybe a hundred or so of tests, and only 10 to 15 of them use Mockserver.

If I enable log level INFO I'd get around 50k lines of log where major part of messages is garbage:

  INFO request:
    <100+ lines of request headers and body>
  didn't match expectation:
    <100+ lines of expectation description>
  because:
    method matched
    path didn't match

And there's literally a half a thousand of messages with the above pattern for every request trying to match every expectation!

This is insane! This shouldn't be an INFO, it's definitely a TRACE logs.

The solution you'd like What really would be great is INFO logs indicating only matching requests or requests that didn't match at all:

INFO request <method> <URL> matched expectation <id>

INFO request <method> <URL> didn't match any of expectations

DEBUG logs may contain more verbose information about request and expectation:

DEBUG request
    <JSON request info with body and everything>
  matched expectation:
    <JSON info about expectation>

DEBUG request
    <JSON request info with body and everything>
  didn't match any of expectations

The current behaviour may lay in TRACE level.

Also, I would love to see any option to log non-2xx answers in WARN level, it would be really helpful.

[Drevoed]

Are reactions prohibited? +1.

[jamesdbloom]

I don't think I understand what you are proposing. I not sure how is MockServer expected to know which expectations a request is intended to match against? It sounds like you are requesting that MockServer doesn't log for each expectation but knows which expectation a request is intended to match against and only details for that. Can you please explain how that could be achieved?

[mitasov-ra]

Hi again, sorry for lack of clearness, I'll try to explain better.

How it works now

INFO request
    <JSON of request>
  didn't match expectation
    <JSON of the first expectation>
  because:
    <list of reasons>
INFO
    <JSON of the very same request>
  didn't match expectation
    <JSON of the second expectation>
  because:
    <list of reasons>
...
INFO
    <still JSON of this request>
  didn't match expectation
    <JSON of the (n-1)th expectation>
  because:
    <list of reasons>
INFO
    <JSON of the request, again>
  matched expectation
    <finally the matched expectation>

I assume mockserver just iterates over registered expectations and tries to match the request, but such format of logs has obvious downsides as a lot of "didn't match" messages before successful "matched expectation" and repeating JSON of request over and over again. Such approach skyrockets logs size and makes navigating through logs merely impossible.

What I propose

TRACE request
    <JSON of request>
  didn't match expectation
    <JSON of the first expectation>
  because:
    <list of reasons>
TRACE
    <JSON of the very same request>
  didn't match expectation
    <JSON of the second expectation>
  because:
    <list of reasons>
...
TRACE
    <still JSON of this request>
  didn't match expectation
    <JSON of the (n-1)th expectation>
  because:
    <list of reasons>
INFO request <method> <url> matched expectation <expectation id>
TRACE
    <JSON of the request, again>
  matched expectation
    <finally the matched expectation>

OR

TRACE request
    <JSON of request>
  didn't match expectation
    <JSON of the first expectation>
  because:
    <list of reasons>
...
TRACE
    <still JSON of this request>
  didn't match expectation
    <JSON of the LAST expectation>
  because:
    <list of reasons>
INFO request <method> <url> didn't match any expectations

Then, I can easily filter out INFO logs with grep (line by line)

INFO request <method> <url 1> matched expectation <expectation id>
INFO request <method> <url 2> matched expectation <expectation id>
INFO request <method> <url 3> didn't match any expectations

And immediately see what's going on.

Possible improvement to current verbose variant

Even if my proposal would be accepted, the problem of navigation through verbose logs due to rich multiline JSON format, which leads to inability to filter out "didn't match expectation" logs from the resulting log file.

// BEFORE

TRACE request
    <JSON of request>
  didn't match expectation
    <JSON of the first expectation>
  because:
    <list of reasons>
TRACE
    <JSON of the very same request>
  didn't match expectation
    <JSON of the second expectation>
  because:
    <list of reasons>
TRACE
    <JSON of the request, again>
  matched expectation
    <finally the matched expectation>

// AFTER I filter out "didn't match expectation"

TRACE request
    <JSON of request>
    <JSON of the first expectation>
  because:
    <list of reasons>
TRACE
    <JSON of the very same request>
    <JSON of the second expectation>
  because:
    <list of reasons>
TRACE
    <JSON of the request, again>
  matched expectation
    <finally the matched expectation>

As you can see above the result is just useless garbage. If there would be any setting to disable multiline messages, things already could become much better:

// BEFORE

TRACE request <one line JSON request> didn't match expectation <one line JSON expectation>
TRACE request <one line JSON request> didn't match expectation <one line JSON expectation>
TRACE request <one line JSON request> didn't match expectation <one line JSON expectation>
TRACE request <one line JSON request> matched expectation <one line JSON expectation>

// AFTER I filter out "didn't match expectation"

TRACE request <one line JSON request> matched expectation <one line JSON expectation>

P.S. Hope now the problem is more clear for you, best regards!

[mitasov-ra]

And another waaay more powerful improvement is possible

To get rid of repeating response JSON info, it can be separated out into new message:

// INSTEAD OF
TRACE request <JSON request> didn't match expectation <JSON expectation>
TRACE request <JSON request> didn't match expectation <JSON expectation>
TRACE request <JSON request> didn't match expectation <JSON expectation>
TRACE request <JSON request> matched expectation <JSON expectation>

// IT CAN BE
TRACE start of matching request <JSON request> as <short correlation id>
TRACE request <correlation id> didn't match expectation <JSON expectation>
TRACE request <correlation id> matched expectation <JSON expectation>

// FOR EXAMPLE
TRACE
  start of matching request
    {
      "method": "GET",
      "headers": [
         ...
      ],
      "body": {
        ...
      }
    }
  as 73dd66b9-652c-4b63-b146-933d1806ea30
TRACE request 73dd66b9-652c-4b63-b146-933d1806ea30
  didn't match expectation ...

[sean8601]

This issue has been bothering me for a long time. My mock server integrates with numerous microservices, approximately hundreds of systems. As a result, my log files are exceptionally large, filling up the entire disk space in just one day. While not printing logs makes it challenging to troubleshoot issues, logging extensively becomes impractical due to the sheer volume. Therefore, I endorse the suggestion given by the previous contributor.

[mitasov-ra]

Any updates on that?

Just for the record, currently i'm debugging my test with 2 expectations and 2 requests and MockServer INFO logs generated almost a thousand lines.

This is unusable. Completely.