Route Tranform Behavior change in v20

[atibdialpad]

I am noticing a behavior change in the "route" transform between v19.1 and v20.

Config:

[transforms.common_log_processor]
  type = "remap"
  inputs = ["log_source"]
  source = '''
    <some common GROK'ing>
  '''

[transforms.log_event_router]
  type = "route"
  inputs = ["common_log_processor"]
  [transforms.log_event_router.route]
    foo = ".program == 'foo'" # route 1
    bar = ".program == 'bar'" # route 2

[transforms.foo_log_processor]
  inputs = ["log_event_router.foo"]
  type = "remap"
  source = '''
    <some stuff>
  '''

[transforms.bar_log_processor]
  inputs = ["log_event_router.bar"]
  type = "remap"
  source = '''
    <some stuff>
  '''

Now when I have a unit test which tests only route1 i.e insert_at=common_log_processor and extract_from=foo_log_processor,
(i.e a logevent that follows this route : common_log_processor->log_event_router.foo->foo_log_processor)

the test generates WARNINGS like:

2022-02-11T08:02:49.100665Z WARN vector::config::builder: Transform "log_event_router.bar" has no consumers. (even though bar_log_processor is a consumer of log_event_router.bar, its just that this test log event doesn't take that route)

@jszwedko

[StephenWakely]

Now when I have a unit test which tests only route1

Can you post the code to this unit test?

[atibdialpad]

sure

[[tests]]
  name = "test__1"
  [[tests.inputs]]                                                                                                                                                       
    insert_at = "common_log_processor"
    type = "raw"
    value = "2021-06-07 13:38:41,618 foo [error] some_msg"
  [[tests.outputs]]
    extract_from = "foo_log_processor"
    [[tests.outputs.conditions]]
      type = "vrl"
      source = ''' 
        .loglevel == "error" &&
        .timestamp == "2021-06-07 13:38:41,618" &&
        .program == "foo" &&
        ....
        ....
      ''' 

The common_log_processor simple GROK's the log line "2021-06-07 13:38:41,618 foo [error] some_msg" into:
'timestamp', 'program', 'loglevel' and 'message' fields

[StephenWakely]

This does look like a regression. I've raised an issue #11335 so we can investigate and fix this.

[atibdialpad]

thanks. Good thing is the tests don't fail. It just prints those WARNING logs

[wbew]

Hello @atibdialpad! To add some explanation here, the warning logs appear as an unfortunate side effect from re-implementing unit test internals and refactoring route to use some new multiple output internals. Under the hood, when unit testing, we trim out any unnecessary transforms (i.e. ones that are not involved in the test) like bar_log_processor. Meanwhile, log_event_router is preserved along with all its configured outputs. In the process of building the configuration, a standard warning is then logged that log_event_router.bar has no consumers (since we've trimmed out bar_log_processor).

Definitely confusing, so we'll be looking into fixing this (e.g. removing/hiding the logs when in unit testing contexts).

[atibdialpad]

Makes sense !!! Thanks for explanation @001wwang

[wbew]

This should be addressed by: #11345. Thanks for bringing it to our attention!