AMBARI-16958. Prefix command execution log lines in agent log (smohanty)

ambari-agent/src/main/python/ambari_agent/ActionQueue.py

@@ -346,14 +346,14 @@ class ActionQueue(threading.Thread):
         if roleResult['stdout'] != '':
             logger.info("Begin command output log for command with id = " + str(command['taskId']) + ", role = "
                         + command['role'] + ", roleCommand = " + command['roleCommand'])
-            self.log_command_output(roleResult['stdout'])
+            self.log_command_output(roleResult['stdout'], str(command['taskId']))
             logger.info("End command output log for command with id = " + str(command['taskId']) + ", role = "
                         + command['role'] + ", roleCommand = " + command['roleCommand'])
 
         if roleResult['stderr'] != '':
             logger.info("Begin command stderr log for command with id = " + str(command['taskId']) + ", role = "
                         + command['role'] + ", roleCommand = " + command['roleCommand'])
-            self.log_command_output(roleResult['stderr'])
+            self.log_command_output(roleResult['stderr'], str(command['taskId']))
             logger.info("End command stderr log for command with id = " + str(command['taskId']) + ", role = "
                         + command['role'] + ", roleCommand = " + command['roleCommand'])
 
@@ -427,7 +427,7 @@ class ActionQueue(threading.Thread):
 
     self.commandStatuses.put_command_status(command, roleResult)
 
-  def log_command_output(self, text):
+  def log_command_output(self, text, taskId):
     """
     Logs a message as multiple enumerated log messages every of which is not larger than MAX_SYMBOLS_PER_LOG_MESSAGE.
 
@@ -437,9 +437,9 @@ class ActionQueue(threading.Thread):
     chunks = split_on_chunks(text, MAX_SYMBOLS_PER_LOG_MESSAGE)
     if len(chunks) > 1:
       for i in range(len(chunks)):
-        logger.info("Chunk {0}/{1} of log for command: \n".format(i+1, len(chunks)) + chunks[i])
+        logger.info("Cmd log for taskId={0} and chunk {1}/{2} of log for command: \n".format(taskId, i+1, len(chunks)) + chunks[i])
     else:
-      logger.info(text)
+      logger.info("Cmd log for taskId={0}: ".format(taskId), text)
 
   def get_retry_delay(self, last_delay):
     """

ambari-agent/src/test/python/ambari_agent/TestActionQueue.py

@@ -338,13 +338,14 @@ class TestActionQueue(TestCase):
     actionQueue.process_command(execution_command)
     self.assertTrue(log_exc_mock.called)
 
+  @patch.object(ActionQueue, "log_command_output")
   @patch.object(OSCheck, "os_distribution", new = MagicMock(return_value = os_distro_value))
   @patch.object(CustomServiceOrchestrator, "runCommand")
   @patch("CommandStatusDict.CommandStatusDict")
   @patch.object(ActionQueue, "status_update_callback")
   def test_log_execution_commands(self, status_update_callback_mock,
                                   command_status_dict_mock,
-                                  cso_runCommand_mock):
+                                  cso_runCommand_mock, mock_log_command_output):
     custom_service_orchestrator_execution_result_dict = {
         'stdout': 'out',
         'stderr': 'stderr',
@@ -377,6 +378,7 @@ class TestActionQueue(TestCase):
                 'customCommand': 'RESTART',
                 'exitCode': 0}
     # Agent caches configurationTags if custom_command RESTART completed
+    mock_log_command_output.assert_has_calls([call("out\n\nCommand completed successfully!\n", "9"), call("stderr", "9")], any_order=True)
     self.assertEqual(len(report['reports']), 1)
     self.assertEqual(expected, report['reports'][0])