Issue with logging in behavior with yaml style formatting

[dcconner]

I have a repeatable issue with errors if a Logger.loginfo message has yaml style formatting in the message

2595.511000000 ERROR [topics.py:723(_invoke_callback) [topics: /clock, /rosout, /turtlebot/flexbe/log] bad callback: <function callback at 0x7f7c49fd6050>
Traceback (most recent call last):
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rospy/topics.py", line 720, in _invoke_callback
    cb(msg)
  File "<string>", line 10, in callback
  File "/usr/lib/python2.7/dist-packages/yaml/__init__.py", line 71, in load
    return loader.get_single_data()
  File "/usr/lib/python2.7/dist-packages/yaml/constructor.py", line 37, in get_single_data
    node = self.get_single_node()
  File "/usr/lib/python2.7/dist-packages/yaml/composer.py", line 36, in get_single_node
    document = self.compose_document()
  File "/usr/lib/python2.7/dist-packages/yaml/composer.py", line 55, in compose_document
    node = self.compose_node(None, None)
  File "/usr/lib/python2.7/dist-packages/yaml/composer.py", line 84, in compose_node
    node = self.compose_mapping_node(anchor)
  File "/usr/lib/python2.7/dist-packages/yaml/composer.py", line 127, in compose_mapping_node
    while not self.check_event(MappingEndEvent):
  File "/usr/lib/python2.7/dist-packages/yaml/parser.py", line 98, in check_event
    self.current_event = self.state()
  File "/usr/lib/python2.7/dist-packages/yaml/parser.py", line 428, in parse_block_mapping_key
    if self.check_token(KeyToken):
  File "/usr/lib/python2.7/dist-packages/yaml/scanner.py", line 116, in check_token
    self.fetch_more_tokens()
  File "/usr/lib/python2.7/dist-packages/yaml/scanner.py", line 220, in fetch_more_tokens
    return self.fetch_value()
  File "/usr/lib/python2.7/dist-packages/yaml/scanner.py", line 576, in fetch_value
    self.get_mark())
ScannerError: mapping values are not allowed here
  in "<string>", line 1, column 21:
    text: [Receive Goal]: Input new goal ...
                        ^

The formatting was to use [%s]: Input new goal. I tried [%s] - Input but that gave a similar error (different message shown)

  File "/usr/lib/python2.7/dist-packages/yaml/scanner.py", line 490, in fetch_block_entry
    self.get_mark())
ScannerError: sequence entries are not allowed here
  in "<string>", line 1, column 22:
    text: [Receive Path] - Requesting a plan
                         ^

I finally removed the [ ] and -, and I no longer see the issue.

The behavior executive still works, and I only had an indication if I reviewed the rosout.log file or viewed the "Show Terminal" window in FlexBE. It is possible that this error happened in the past, and is generic to ROS, but I believe it is happening on the app side when it either processes the initial behavior or when it receives the message on the the flexbe/log topic.

[dcconner]

This is repeatable with the example behavior by changing the log message to "Hello : world"

[pschillinger]

Tracing this error down, it looks like it results from here in ROS genpy. Maybe we can help to implement this TODO.

[pschillinger]

I created a PR in ros/genpy#83. If string escaping is merged there, I can fix this issue here.

[pschillinger]

Here is a quick update on the current status:

• Indigo: genpy is not yet updated with the fix, not sure when this will happen
• Kinetic: genpy version 0.6.6 has the fix and resolves this issue for me. However, only genpy 0.6.5 is installed by apt-get for now.