search

StackStorm / st2

StackStorm (aka "IFTTT for Ops") is event-driven automation for auto-remediation, incident responses, troubleshooting, deployments, and more for DevOps and SREs. Includes rules engine, workflow, 160 integration packs with 6000+ actions (see https://exchange.stackstorm.org) and ChatOps. Installer at https://docs.stackstorm.com/install/index.html
https://stackstorm.com/
Apache License 2.0
6.03k stars 745 forks source link

GELF logs do not properly render short_message #4462

Open LindsayHill opened 5 years ago

LindsayHill commented 5 years ago
SUMMARY

The short_message for GelfFormat logs does not properly render variables. It logs things like Validating rule %s for %s - i.e. it literally uses %s. full_message is logged correctly.

ISSUE TYPE
STACKSTORM VERSION

st2 2.9.1, on Python 2.7.12

OS / ENVIRONMENT / INSTALL METHOD

Ansible install, on Ubuntu 16.04.

STEPS TO REPRODUCE

Change the log configuration for ST2 services as documented here. Configure Fluentd to read those GELF-format logs, and send them to Elastic Stack. View the results in Kibana.

EXPECTED RESULTS

I expected to see properly formatted logs, with variables correctly rendered.

ACTUAL RESULTS

The short_message is not properly rendered. For example, when a rule is validated (https://github.com/StackStorm/st2/blob/master/st2reactor/st2reactor/rules/filter.py#L72), it calls the logger:

        LOG.info('Validating rule %s for %s.', self.rule.ref, self.trigger['name'],
                 extra=self._base_logger_context)

This result in a log message like this

Note these fields:

"short_message": "Validating rule %s for %s." "full_message": "Validating rule mypack.myrule for webhook.",

I expect that short_message should also be rendering %s as the actual variable.

Kami commented 5 years ago

Good catch - we should just change and use % noation instead of comma and args list everywhere.