Detect when tritonserver fails to launch (#688)

* Initial changes. Unit tests failing

* Unit tests passing

* Needed to convert bytes to string depending on if output path was specified

* Adding unit test

* Fixing codeQL issues

* Second attempt at fixing codeQL error

* Updates based on review comments

Author: nv-braf

model_analyzer/analyzer.py

@@ -205,7 +205,9 @@ def _get_server_only_metrics(self, client, gpus):
 
             logger.info('Profiling server only metrics...')
             self._server.start()
-            client.wait_for_server_ready(self._config.client_max_retries)
+            client.wait_for_server_ready(
+                num_retries=self._config.client_max_retries,
+                log_file=self._server.log_file())
             self._metrics_manager.profile_server()
             self._server.stop()
 

model_analyzer/record/metrics_manager.py

@@ -103,7 +103,7 @@ def start_new_model(self):
     def _init_state(self):
         """
         Sets MetricsManager object managed
-        state variables in AnalyerState
+        state variables in AnalyzerState
         """
 
         gpu_info = self._state_manager.get_state_variable(
@@ -361,7 +361,9 @@ def _do_load_model_variant(self, variant_config):
         """
         Loads a model variant in the client
         """
-        self._client.wait_for_server_ready(self._config.client_max_retries)
+        self._client.wait_for_server_ready(
+            num_retries=self._config.client_max_retries,
+            log_file=self._server.log_file())
 
         variant_name = variant_config.get_field('name')
         if self._client.load_model(model_name=variant_name) == -1:
@@ -483,7 +485,7 @@ def _run_perf_analyzer(self, run_config, perf_output_writer):
                 perf_output_writer.write(perf_analyzer.output() + '\n',
                                          append=True)
 
-        # PerfAnalyzer run was not succesful
+        # PerfAnalyzer run was not successful
         if status == 1:
             return (None, None)
 
@@ -539,7 +541,7 @@ def _aggregate_gpu_records(self, gpu_records):
     def _get_cpu_inference_metrics(self):
         """
         Stops any monitors that just need the records to be aggregated
-        like the CPU mmetrics
+        like the CPU metrics
         """
 
         cpu_records = self._cpu_monitor.stop_recording_metrics()
@@ -558,7 +560,9 @@ def _check_triton_and_model_analyzer_gpus(self):
         """
 
         if self._config.triton_launch_mode != 'remote' and self._config.triton_launch_mode != 'c_api':
-            self._client.wait_for_server_ready(self._config.client_max_retries)
+            self._client.wait_for_server_ready(
+                num_retries=self._config.client_max_retries,
+                log_file=self._server.log_file())
 
             model_analyzer_gpus = [gpu.device_uuid() for gpu in self._gpus]
             triton_gpus = self._get_triton_metrics_gpus()

model_analyzer/triton/client/client.py

@@ -28,14 +28,23 @@ class TritonClient:
     TritonClientFactory
     """
 
-    def wait_for_server_ready(self, num_retries, sleep_time=1):
+    def wait_for_server_ready(
+        self,
+        num_retries,
+        sleep_time=1,
+        log_file=None,
+    ):
         """
         Parameters
         ----------
         num_retries : int
             number of times to send a ready status
             request to the server before raising
             an exception
+        sleep_time: int
+            amount of time in seconds to sleep between retries
+        log_file: TextIOWrapper
+            file that contains the server's output log
         Raises
         ------
         TritonModelAnalyzerException
@@ -50,9 +59,11 @@ def wait_for_server_ready(self, num_retries, sleep_time=1):
                     time.sleep(sleep_time)
                     return
                 else:
+                    self._check_for_triton_log_errors(log_file)
                     time.sleep(sleep_time)
                     retries -= 1
             except Exception as e:
+                self._check_for_triton_log_errors(log_file)
                 time.sleep(sleep_time)
                 retries -= 1
                 if retries == 0:
@@ -162,7 +173,7 @@ def get_model_config(self, model_name, num_retries):
         Returns
         -------
         dict or None
-            A dictionary containg the model config.
+            A dictionary containing the model config.
         """
 
         self.wait_for_model_ready(model_name, num_retries)
@@ -174,3 +185,20 @@ def is_server_ready(self):
         Returns true if the server is ready. Else False
         """
         return self._client.is_server_ready()
+
+    def _check_for_triton_log_errors(self, log_file):
+        if not log_file:
+            return
+
+        log_file.seek(0)
+        log_output = log_file.read()
+
+        if not type(log_output) == str:
+            log_output = log_output.decode('utf-8')
+
+        if log_output:
+            if "Unexpected argument:" in log_output:
+                error_start = log_output.find("Unexpected argument:")
+                raise TritonModelAnalyzerException(
+                    f'Error: TritonServer did not launch successfully\n\n{log_output[error_start:]}'
+                )

model_analyzer/triton/client/grpc_client.py

@@ -68,7 +68,7 @@ def get_model_config(self, model_name, num_retries):
         Returns
         -------
         dict
-            A dictionary containg the model config.
+            A dictionary containing the model config.
         """
 
         self.wait_for_model_ready(model_name, num_retries)

model_analyzer/triton/model/model_config.py

@@ -138,7 +138,8 @@ def _get_default_config_from_server(config, client, gpus, model_name,
             config, gpus, use_model_repository=True)
 
         server.start()
-        client.wait_for_server_ready(config.client_max_retries)
+        client.wait_for_server_ready(num_retries=config.client_max_retries,
+                                     log_file=server.log_file())
 
         if (client.load_model(model_name) == -1):
             server.stop()

model_analyzer/triton/server/server.py

@@ -13,6 +13,7 @@
 # limitations under the License.
 
 from abc import ABC, abstractmethod
+from io import TextIOWrapper
 
 
 class TritonServer(ABC):
@@ -38,6 +39,12 @@ def stop(self):
         Stops and cleans up after the server
         """
 
+    @abstractmethod
+    def log_file(self) -> TextIOWrapper:
+        """
+        Returns the server's log file
+        """
+
     @abstractmethod
     def cpu_stats(self):
         """

model_analyzer/triton/server/server_docker.py

@@ -21,6 +21,8 @@
 from model_analyzer.model_analyzer_exceptions \
     import TritonModelAnalyzerException
 
+from io import TextIOWrapper
+
 LOCAL_HTTP_PORT = 8000
 LOCAL_GRPC_PORT = 8001
 LOCAL_METRICS_PORT = 8002
@@ -205,3 +207,6 @@ def cpu_stats(self):
         # Divide by 1.0e6 to convert from kilobytes to MB
         return float(used_mem_bytes.decode("utf-8")) // 1.0e3, float(
             available_mem_bytes.decode("utf-8")) // 1.0e3
+
+    def log_file(self) -> TextIOWrapper:
+        return self._log_file

model_analyzer/triton/server/server_local.py

@@ -20,7 +20,9 @@
 from subprocess import Popen, DEVNULL, STDOUT, TimeoutExpired
 import psutil
 import logging
+import tempfile
 import os
+from io import TextIOWrapper
 
 logger = logging.getLogger(LOGGER_NAME)
 
@@ -50,6 +52,8 @@ def __init__(self, path, config, gpus, log_path):
         self._server_path = path
         self._gpus = gpus
         self._log_path = log_path
+        self._log_file = DEVNULL
+        self._is_first_time_starting_server = True
 
         assert self._server_config['model-repository'], \
             "Triton Server requires --model-repository argument to be set."
@@ -82,11 +86,16 @@ def start(self, env=None):
 
             if self._log_path:
                 try:
+                    if self._is_first_time_starting_server:
+                        if os.path.exists(self._log_path):
+                            os.remove(self._log_path)
                     self._log_file = open(self._log_path, 'a+')
                 except OSError as e:
                     raise TritonModelAnalyzerException(e)
             else:
-                self._log_file = DEVNULL
+                self._log_file = tempfile.NamedTemporaryFile()
+
+            self._is_first_time_starting_server = False
 
             # Construct Popen command
             try:
@@ -135,3 +144,6 @@ def cpu_stats(self):
                     1.0e6), (system_memory_info.available // 1.0e6)
         else:
             return 0.0, 0.0
+
+    def log_file(self) -> TextIOWrapper:
+        return self._log_file

tests/mocks/mock_server.py

@@ -24,7 +24,7 @@ class MockServerMethods(MockBase):
     """
 
     @abstractmethod
-    def assert_server_process_start_called_with(self, **args):
+    def assert_server_process_start_called_with(self, *args, **kwargs):
         """
         Asserts that the tritonserver process was started with
         the supplied arguments

tests/mocks/mock_server_local.py

@@ -69,7 +69,10 @@ def _fill_patchers(self):
         self._patchers.append(self.patcher_pipe)
         self._patchers.append(self.patcher_psutil)
 
-    def assert_server_process_start_called_with(self, cmd, gpus):
+    def assert_server_process_start_called_with(self,
+                                                cmd,
+                                                gpus,
+                                                stdout=MagicMock()):
         """
         Asserts that Popen was called
         with the cmd provided.
@@ -80,7 +83,7 @@ def assert_server_process_start_called_with(self, cmd, gpus):
             [gpu.device_uuid() for gpu in gpus])
 
         self.popen_mock.assert_called_once_with(cmd,
-                                                stdout=self.pipe_mock,
+                                                stdout=stdout,
                                                 stderr=self.stdout_mock,
                                                 start_new_session=True,
                                                 universal_newlines=True,