Add binary logging test

CHANGELOG.md

@@ -3,6 +3,8 @@
 ## [Unreleased]
 ### Added
 - Binary data escaping in `listener` module (enhancing `Get Binary File` keyword logging), by @HardNorth
+### Changed
+- Client version updated on [5.5.5](https://github.com/reportportal/client-Python/releases/tag/5.5.5), by @HardNorth
 
 ## [5.5.1]
 ### Changed

examples/binary_file_read.robot

@@ -0,0 +1,16 @@
+*** Settings ***
+Documentation  Example of logging on binary file read
+Library        OperatingSystem
+
+*** Variables ***
+${PUG_IMAGE}        res/pug/lucky.jpg
+
+*** Keywords ***
+Read Binary File
+    [Arguments]     ${file}
+    ${data}         Get Binary File     ${file}
+    Log             ${data}
+
+*** Test Cases ***
+Read Pug Image
+    Read Binary File    ${PUG_IMAGE}

robotframework_reportportal/listener.py

@@ -14,39 +14,79 @@
 
 """This module includes Robot Framework listener interfaces."""
 
+import binascii
 import logging
 import os
+import re
 from functools import wraps
 from mimetypes import guess_type
+from types import MappingProxyType
 from typing import Optional, Dict, Union, Any
 from warnings import warn
 
-from reportportal_client.helpers import gen_attributes, LifoQueue
+from reportportal_client.helpers import gen_attributes, LifoQueue, is_binary, guess_content_type_from_bytes
 
 from .model import Keyword, Launch, Test, LogMessage, Suite
 from .service import RobotService
 from .static import MAIN_SUITE_ID, PABOT_WIHOUT_LAUNCH_ID_MSG
 from .variables import Variables
 
 logger = logging.getLogger(__name__)
-DATA_SIGN = '${data} = '
+VARIABLE_PATTERN = r'^\s*\${[^}]*}\s*=\s*'
 TRUNCATION_SIGN = "...'"
-
-
-def is_binary(iterable: Union[bytes, bytearray, str]) -> bool:
-    """Check if given iterable is binary.
-
-    :param iterable: iterable to check
-    :return: True if iterable contains binary bytes, False otherwise
-    """
-    if isinstance(iterable, str):
-        byte_iterable = iterable.encode('utf-8')
-    else:
-        byte_iterable = iterable
-
-    if 0x00 in byte_iterable:
-        return True
-    return False
+CONTENT_TYPE_TO_EXTENSIONS = MappingProxyType({
+    'application/pdf': 'pdf',
+    'application/zip': 'zip',
+    'application/java-archive': 'jar',
+    'image/jpeg': 'jpg',
+    'image/png': 'png',
+    'image/gif': 'gif',
+    'image/bmp': 'bmp',
+    'image/vnd.microsoft.icon': 'ico',
+    'image/webp': 'webp',
+    'audio/mpeg': 'mp3',
+    'audio/wav': 'wav',
+    'video/mpeg': 'mpeg',
+    'video/avi': 'avi',
+    'video/webm': 'webm',
+    'text/plain': 'txt',
+    'application/octet-stream': 'bin'
+})
+
+
+def unescape(binary_string: str, stop_at: int = -1):
+    result = bytearray()
+    join_list = list()
+    join_idx = -3
+    skip_next = False
+    for i, b in enumerate(binary_string):
+        if skip_next:
+            skip_next = False
+            continue
+        if i < join_idx + 2:
+            join_list.append(b)
+            continue
+        else:
+            if len(join_list) > 0:
+                for bb in binascii.unhexlify(''.join(join_list)):
+                    result.append(bb)
+                    if stop_at > 0:
+                        if len(result) >= stop_at:
+                            break
+                join_list = list()
+        if b == '\\' and binary_string[i + 1] == 'x':
+            skip_next = True
+            join_idx = i + 2
+            continue
+        for bb in b.encode('utf-8'):
+            result.append(bb)
+            if stop_at > 0:
+                if len(result) >= stop_at:
+                    break
+    if len(join_list) > 0:
+        for bb in binascii.unhexlify(''.join(join_list)):
+            result.append(bb)
+    return result
 
 
 def check_rp_enabled(func):
@@ -111,11 +151,20 @@ def log_message(self, message: Dict) -> None:
         :param message: Message passed by the Robot Framework
         """
         msg = self._build_msg_struct(message)
-        if msg.message.startswith(DATA_SIGN):
-            msg_content = msg.message[len(DATA_SIGN):]
-            if is_binary(msg_content):
+        if is_binary(msg.message):
+            variable_match = re.search(VARIABLE_PATTERN, msg.message)
+            if variable_match:
+                # Treat as partial binary data
+                msg_content = msg.message[variable_match.end():]
                 # remove trailing `'"...`, add `...'`
-                msg.message = DATA_SIGN + str(msg_content.encode('utf-8'))[:-5] + TRUNCATION_SIGN
+                msg.message = (msg.message[variable_match.start():variable_match.end()]
+                               + str(msg_content.encode('utf-8'))[:-5] + TRUNCATION_SIGN)
+            else:
+                # Do not log full binary data, since it's usually corrupted
+                content_type = guess_content_type_from_bytes(unescape(msg.message, 128))
+                msg.message = (f'Binary data of type "{content_type}" logging skipped, as it was processed as text and '
+                               'hence corrupted.')
+                msg.level = 'WARN'
         logger.debug('ReportPortal - Log Message: {0}'.format(message))
         self.service.log(message=msg)
 
@@ -228,8 +277,7 @@ def start_test(self, name: str, attributes: Dict, ts: Optional[Any] = None) -> N
             attributes['source'] = getattr(self.current_item, 'source', None)
         test = Test(name=name, attributes=attributes)
         logger.debug('ReportPortal - Start Test: {0}'.format(attributes))
-        test.attributes = gen_attributes(
-            self.variables.test_attributes + test.tags)
+        test.attributes = gen_attributes(self.variables.test_attributes + test.tags)
         test.rp_parent_item_id = self.parent_id
         test.rp_item_id = self.service.start_test(test=test, ts=ts)
         self._add_current_item(test)

tests/helpers/utils.py

@@ -16,10 +16,11 @@
 
 import random
 import time
+from typing import List, Optional, Dict, Any, Tuple
 
 from robot.run import RobotFramework
 
-DEFAULT_VARIABLES = {
+DEFAULT_VARIABLES: Dict[str, Any] = {
     'RP_LAUNCH': 'Robot Framework',
     'RP_ENDPOINT': 'http://localhost:8080',
     'RP_PROJECT': 'default_personal',
@@ -28,8 +29,10 @@
 }
 
 
-def run_robot_tests(tests, listener='robotframework_reportportal.listener',
-                    variables=None, arguments=None):
+def run_robot_tests(tests: List[str],
+                    listener: str = 'robotframework_reportportal.listener',
+                    variables: Optional[Dict[str, Any]] = None,
+                    arguments: Optional[Dict[str, Any]] = None) -> int:
     cmd_arguments = ['--listener', listener]
     if arguments:
         for k, v in arguments.items():
@@ -51,11 +54,15 @@ def run_robot_tests(tests, listener='robotframework_reportportal.listener',
     return RobotFramework().execute_cli(cmd_arguments, False)
 
 
-def get_launch_log_calls(mock):
+def get_launch_log_calls(mock) -> List[Tuple[List[Any], Dict[str, Any]]]:
     return [e for e in mock.log.call_args_list
             if 'item_id' in e[1] and e[1]['item_id'] is None]
 
 
-def item_id_gen(**kwargs):
+def get_log_calls(mock) -> List[Tuple[List[Any], Dict[str, Any]]]:
+    return [e for e in mock.log.call_args_list if 'item_id' in e[1] and e[1]['item_id']]
+
+
+def item_id_gen(**kwargs) -> str:
     return "{}-{}-{}".format(kwargs['name'], str(round(time.time() * 1000)),
                              random.randint(0, 9999))

tests/integration/test_logger.py

@@ -29,3 +29,17 @@ def test_launch_log(mock_client_init):
 
     messages = set(map(lambda x: x[1]['message'], calls))
     assert messages == {'Hello, world!', 'Goodbye, world!', 'Enjoy my pug!'}
+
+
+@mock.patch(REPORT_PORTAL_SERVICE)
+def test_binary_file_log(mock_client_init):
+    result = utils.run_robot_tests(['examples/binary_file_read.robot'])
+    assert result == 0  # the test successfully passed
+
+    mock_client = mock_client_init.return_value
+    calls = utils.get_log_calls(mock_client)
+    assert len(calls) == 3
+
+    messages = set(map(lambda x: x[1]['message'], calls))
+    error_message = 'Binary data of type "image/jpeg" logging skipped, as it was processed as text and hence corrupted.'
+    assert error_message in messages