[filelogreceiver] - ERROR: error finding files: no files match the configured criteria

[cwegener]

Component(s)

pkg/stanza, receiver/filelog

What happened?

Description

After upgrading the OTel Collector from 0.82.0 to 0.84.0, the filelog receiver started producing error messages when the matching rules result in NO files being matched for consuming.

Steps to Reproduce

1. Create config file:

receivers:
  filelog:
    include: [ /tmp/simple.log ]
    operators:
      - type: regex_parser
        regex: '^(?P<time>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}) (?P<sev>[A-Z]*) (?P<msg>.*)$'
        timestamp:
          parse_from: attributes.time
          layout: '%Y-%m-%d %H:%M:%S'
        severity:
          parse_from: attributes.sev
exporters:
  logging:
service:
  pipelines:
    logs:
      receivers:
        - filelog
      processors: []
      exporters:
        - logging

2. Run OTel Collector 0.82.0 with above config

3. Run OTel Collector 0.84.0 with above config

4. Compare results

Expected Result

No errors logged that zero files were matched. And 1 warning logged during startup that zero files were matched.

Actual Result

1 error per second logged that zero files were matched.

Collector version

v0.84.0

Environment information

Environment

OS: "Ubuntu 22.04", "Windows Server 2022", "Archlinux"
Compiler(if manually compiled): go 1.21.0

OpenTelemetry Collector configuration

receivers:
  filelog:
    include: [ /tmp/simple.log ]
    operators:
      - type: regex_parser
        regex: '^(?P<time>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}) (?P<sev>[A-Z]*) (?P<msg>.*)$'
        timestamp:
          parse_from: attributes.time
          layout: '%Y-%m-%d %H:%M:%S'
        severity:
          parse_from: attributes.sev
exporters:
  logging:
service:
  pipelines:
    logs:
      receivers:
        - filelog
      processors: []
      exporters:
        - logging

Log output

2023-09-08T12:11:26.478+1000    info    service/telemetry.go:84 Setting up own telemetry...                                                                                                                                                                    2023-09-08T12:11:26.478+1000    info    service/telemetry.go:201        Serving Prometheus metrics      {"address": ":8888", "level": "Basic"}                                                                                                                 2023-09-08T12:11:26.478+1000    info    exporter@v0.84.0/exporter.go:275        Development component. May change in the future.        {"kind": "exporter", "data_type": "logs", "name": "logging"}                                                           2023-09-08T12:11:26.480+1000    info    service/service.go:138  Starting otelcol-atlastix...    {"Version": "0.84.0+atlx.2", "NumCPU": 16}                                                                                                                     2023-09-08T12:11:26.480+1000    info    extensions/extensions.go:31     Starting extensions...                                                                                                                                                                 2023-09-08T12:11:26.480+1000    info    adapter/receiver.go:45  Starting stanza receiver        {"kind": "receiver", "name": "filelog", "data_type": "logs"}                                                                                                   2023-09-08T12:11:26.481+1000    warn    fileconsumer/file.go:61 finding files   {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer", "error": "no files match the configured criteria"}                                   2023-09-08T12:11:26.481+1000    info    service/service.go:161  Everything is ready. Begin running and processing data.                                                                                                                                        2023-09-08T12:11:26.682+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                         github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   2023-09-08T12:11:27.882+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                         github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   2023-09-08T12:11:29.082+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                         github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   2023-09-08T12:11:30.281+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                         github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   2023-09-08T12:11:31.282+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                         github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   2023-09-08T12:11:32.482+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                                      github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  
github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                 
        github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   
2023-09-08T12:11:33.681+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              
github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                              
        github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  
github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                 
        github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   
2023-09-08T12:11:34.682+1000    error   fileconsumer/file.go:118        error finding files: no files match the configured criteria     {"kind": "receiver", "name": "filelog", "data_type": "logs", "component": "fileconsumer"}                              
github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).poll                                                                                                                                                              
        github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:118                                                                                                                                                  
github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/fileconsumer.(*Manager).startPoller.func1                                                                                                                                                 
        github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza@v0.84.0/fileconsumer/file.go:99                                                                                                                                                   
^C2023-09-08T12:11:34.906+1000  info    otelcol/collector.go:250        Received signal from OS {"signal": "interrupt"}                                                                                                                                        
2023-09-08T12:11:34.906+1000    info    service/service.go:170  Starting shutdown...                                                                                                                                                                           
2023-09-08T12:11:34.906+1000    info    adapter/receiver.go:139 Stopping stanza receiver        {"kind": "receiver", "name": "filelog", "data_type": "logs"}                                                                                                   
2023-09-08T12:11:34.907+1000    info    extensions/extensions.go:45     Stopping extensions...                                                                                                                                                                 
2023-09-08T12:11:34.907+1000    info    service/service.go:184  Shutdown complete.

Additional context

No response

[github-actions]

Pinging code owners:

• filelogreceiver: @djaglowski
• pkg/stanza: @djaglowski
• receiver/filelog: @djaglowski

See Adding Labels via Comments if you do not have permissions to add labels yourself.

[djaglowski]

I believe this behavior has been in place for about 3 months. That said, I agree this shouldn't be an error message. I've opened #26526 to reduce this to a warning log.

[cwegener]

I believe this behavior has been in place for about 3 months.

I didn't get a chance to bisect the issue yet. A bit strange that I see the difference when going from 0.82.0 to 0.84.0, considering that the change you've identified was introduced in 0.81.0 0.80.0 0.81.0

I've opened #26526 to reduce this to a warning log

Warning sounds good, considering that it has been a warning before.

Lastly, which part determines the 1 second interval that I'm seeing? I couldn't spot anything in the filelog receiver docs that points to something happening every 1 second.

[kevinnoel-be]

Hello @djaglowski
We've seen this issue happening on our side too when upgrading from v0.76 to v0.84. Reducing to warning doesn't really works for us as we are interested in warning logs and also some of our filelog receivers check for files that are optional, appearing later etc.. Shouldn't this be an option instead? E.g. warn/error if files are required to be present, and lower severity if those files are optional? WDYT?

[djaglowski]

My opinion is that we should not add configuration at the component level to control log levels. This will lead to a lot of complexity and inconsistency across the codebase. I think we can try to choose a reasonable log level but ultimately some folks will need to manipulate or filter their telemetry to meet their needs. Info level may be reasonable, but the downside there is that new users will often miss the immediate feedback they need to get started using the collector.

warn/error if files are required to be present

I don't think the receiver should apply strong expectations in any case. There are too many legitimate situations where log files may not be present, temporarily or otherwise. Again, we can generate the telemetry but users may need to process/react to the telemetry according to their needs.

[kevinnoel-be]

I can understand from the collector side that it may not make sense to introduce|maintain this complexity. We'll drop those on our side then, thanks!