Bug 1095914 - Log messages are being interpolated by syslog_logger.rb, causing random app operation failures
Summary: Log messages are being interpolated by syslog_logger.rb, causing random app o...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Online
Classification: Red Hat
Component: Containers
Version: 2.x
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: ---
Assignee: Dan Mace
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks: 1096900
TreeView+ depends on / blocked
 
Reported: 2014-05-08 20:00 UTC by Dan Mace
Modified: 2015-05-14 23:36 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 1096900 (view as bug list)
Environment:
Last Closed: 2014-07-15 10:28:51 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Dan Mace 2014-05-08 20:00:17 UTC
Description of problem:

The syslog_logger.rb implementation in openshift-origin-node is making incorrect use of the Ruby syslog library. The code is treating the format string parameter as a formatted message parameter. This causes the raw input string (a log message) to be interpolated underneath in the syslog implementation. Any log messages dispatched via this code which contain the '%' character can result in exceptions unless followed by another character that happens to make the string conform to the printf substitution rules. These exceptions can occur anywhere in the openshift-origin-node code, or the MCollective agent.

The code should be changed to use a generic '%s' format string, passing the processed log message as the format args. This will make the call log the input verbatim.

Version-Release number of selected component (if applicable):


How reproducible:

Configure platform logging for syslog via /etc/openshift/node.conf:

PLATFORM_LOG_CLASS=SyslogLogger
PLATFORM_SYSLOG_THRESHOLD=LOG_INFO
PLATFORM_SYSLOG_TRACE_ENABLED=1
PLATFORM_LOG_FILE=/var/log/openshift/node/platform.log
PLATFORM_LOG_LEVEL=INFO
PLATFORM_TRACE_LOG_FILE=/var/log/openshift/node/platform-trace.log
PLATFORM_TRACE_LOG_LEVEL=DEBUG
PLATFORM_LOG_CONTEXT_ENABLED=1
PLATFORM_LOG_CONTEXT_ATTRS=request_id,app_uuid

One example that happens to easily produce the offending log messages is:

rhc app create sinkerror jbossas-7 -pp --no-git --noprompt --from-code=git://github.com/openshift/kitchensink-example.git

Steps to Reproduce:
1.
2.
3.

Actual results:

The MCollective agent will crash with an exception such as:

May  8 12:45:45 ex-std-node3 mcollectived[1965]: agents.rb:139:in `rescue in block in dispatch' /opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.23.9/lib/openshift-origin-node/utils/logger/syslog_logger.rb:61:in `log'
...

The app will fail to be created due to the crash.

Expected results:

Correct log output to Syslog and a successfully created application.

Additional info:

Comment 2 Meng Bo 2014-05-09 03:36:26 UTC
Checked on devenv-stage_830, issue has been fixed.

With the platform log send to syslog set as comment#0 in node.conf, created the kitchensink jbossas app several times.

And no error found in /var/log/ruby193-mcollective.log

Move bug to verified.

Comment 3 ryanj 2014-05-12 20:29:12 UTC
This command is failing frequently for me in production (estimating 80%+ failure rate):

    rhc app create eapmongo jbosseap-6 mongodb-2.4

Please include it in your test cases.


Note You need to log in before you can comment on or make changes to this bug.