Merge pull request #781 from mavlink/pr-improve-logging

julianoes · web-flow · commit 78798e494120 · 2025-08-02T07:29:36.000+12:00
Improve logging of mavsdk_server
diff --git a/MAVSDK_SERVER_VERSION b/MAVSDK_SERVER_VERSION
@@ -1 +1 @@
-v3.8.0
+v3.9.0
diff --git a/examples/calibration.py b/examples/calibration.py
@@ -1,8 +1,12 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
 
diff --git a/examples/camera.py b/examples/camera.py
@@ -1,10 +1,14 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 
 from mavsdk.camera import (CameraError, Mode)
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     drone = System()
diff --git a/examples/firmware_version.py b/examples/firmware_version.py
@@ -1,8 +1,12 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     drone = System()
diff --git a/examples/gimbal.py b/examples/gimbal.py
@@ -1,9 +1,13 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 from mavsdk import System
 from mavsdk.gimbal import GimbalMode, ControlMode, SendMode
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def get_gimbals(drone, timeout=10):
     gimbals_found = []  # List to store all gimbals found
diff --git a/examples/goto.py b/examples/goto.py
@@ -1,8 +1,12 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     drone = System()
diff --git a/examples/mission.py b/examples/mission.py
@@ -1,10 +1,14 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
 
 from mavsdk import System
 from mavsdk.mission import (MissionItem, MissionPlan)
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     drone = System()
diff --git a/examples/offboard_position_ned.py b/examples/offboard_position_ned.py
@@ -9,10 +9,14 @@
 """
 
 import asyncio
+import logging
 
 from mavsdk import System
 from mavsdk.offboard import (OffboardError, PositionNedYaw)
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     """ Does Offboard control using position NED coordinates. """
diff --git a/examples/takeoff_and_land.py b/examples/takeoff_and_land.py
@@ -1,8 +1,13 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
+
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
 
diff --git a/examples/telemetry.py b/examples/telemetry.py
@@ -1,8 +1,13 @@
 #!/usr/bin/env python3
 
 import asyncio
+import logging
+
 from mavsdk import System
 
+# Enable INFO level logging by default so that INFO messages are shown
+logging.basicConfig(level=logging.INFO)
+
 
 async def run():
     # Init the drone
diff --git a/mavsdk/source/index.rst b/mavsdk/source/index.rst
@@ -69,13 +69,55 @@ The examples assume that the embedded ``mavsdk_server`` binary can be run. In so
 Debug connection issues
 -----------------------
 
-.. note::
-   By default mavsdk-python will not print any output from mavsdk-server. If you are experiencing connection issues, it can pay to enable forwarding of the mavsdk-server output into the python console. You can do so with this piece of code at the top of your file:
+MAVSDK-Python automatically captures and displays important messages from ``mavsdk_server``. Error and warning messages are shown by default, while informational messages can be enabled for more detailed debugging.
 
-  .. code:: python
+**For basic debugging (recommended):**
 
-    import logging
-    logging.basicConfig(level=logging.DEBUG)
+.. code:: python
+
+  import logging
+  logging.basicConfig(level=logging.INFO)
+
+This will show connection attempts, version information, and any errors or warnings from ``mavsdk_server``.
+
+**For detailed debugging:**
+
+.. code:: python
+
+  import logging
+  logging.basicConfig(level=logging.DEBUG)
+
+This shows all messages including internal debug information.
+
+**For server-only messages:**
+
+You can also control just the ``mavsdk_server`` output:
+
+.. code:: python
+
+  import logging
+  logging.basicConfig(level=logging.WARNING)  # Hide most messages
+  logging.getLogger('mavsdk_server').setLevel(logging.INFO)  # Show server info
+
+**To disable server messages completely:**
+
+.. code:: python
+
+  import logging
+  logging.getLogger('mavsdk_server').setLevel(logging.CRITICAL)  # Hide all server output
+
+**Common error messages:**
+
+If you see error messages like these, they indicate connection string issues:
+
+.. code:: bash
+
+  ERROR:mavsdk_server:Unknown protocol (cli_arg.cpp:62)
+  ERROR:mavsdk_server:Connection failed: Invalid connection URL
+
+Check that your connection string follows the correct format (e.g. ``udpin://0.0.0.0:14540``).
+
+**Running mavsdk_server separately:**
 
 In order to get more debugging information, it is possible to run the mavsdk_server binary separately.
 
diff --git a/mavsdk/system.py b/mavsdk/system.py
@@ -51,14 +51,64 @@
 
 
 class _LoggingThread(threading.Thread):
-    def __init__(self, pipe, log_fn):
+    def __init__(self, pipe, logger):
         super().__init__()
         self.pipe = pipe
-        self.log_fn = log_fn
+        self.logger = logger
 
     def run(self):
-        for line in self.pipe:
-            self.log_fn(line.decode("utf-8").replace("\n", ""))
+        try:
+            for line in self.pipe:
+                if not line:  # EOF reached
+                    break
+
+                try:
+                    message = line.decode("utf-8").replace("\n", "")
+
+                    # Skip empty lines
+                    if not message.strip():
+                        continue
+
+                    # Strip ANSI color codes used by MAVSDK
+                    # MAVSDK uses: \x1b[31m, \x1b[32m, \x1b[33m, \x1b[34m, \x1b[37m, \x1b[0m
+                    # Also handle \033[ variant (equivalent to \x1b[)
+                    for escape_seq in ['\x1b[', '\033[']:
+                        while escape_seq in message:
+                            start = message.find(escape_seq)
+                            if start == -1:
+                                break
+                            end = message.find('m', start)
+                            if end == -1:
+                                break
+                            message = message[:start] + message[end + 1:]
+
+                    # Parse mavsdk_server log level prefixes and map to Python logging levels
+                    # Format is: [timestamp|Level] message (filename:line)
+                    if "|Error] " in message:
+                        idx = message.find("|Error] ") + 8
+                        self.logger.error(message[idx:].strip())
+                    elif "|Warn ] " in message:
+                        idx = message.find("|Warn ] ") + 8
+                        self.logger.warning(message[idx:].strip())
+                    elif "|Info ] " in message:
+                        idx = message.find("|Info ] ") + 8
+                        self.logger.info(message[idx:].strip())
+                    elif "|Debug] " in message:
+                        idx = message.find("|Debug] ") + 8
+                        self.logger.debug(message[idx:].strip())
+                    else:
+                        # Default to debug for unprefixed messages
+                        self.logger.debug(message)
+                except UnicodeDecodeError:
+                    # Skip lines that can't be decoded
+                    continue
+        except (BrokenPipeError, OSError):
+            # Subprocess has terminated, exit gracefully
+            pass
+        finally:
+            # Ensure pipe is closed
+            if self.pipe and not self.pipe.closed:
+                self.pipe.close()
 
 class System:
     """
@@ -120,7 +170,7 @@ async def connect(self, system_address=None):
 
             # add a delay to be sure resources have been freed and restart mavsdk_server
             await asyncio.sleep(1)
-            
+
 
         if self._mavsdk_server_address is None:
             self._mavsdk_server_address = 'localhost'
@@ -456,13 +506,14 @@ def _start_mavsdk_server(system_address, port, sysid, compid):
                                      "--compid", str(compid)]
                 if system_address:
                     bin_path_and_args.append(system_address)
+
                 p = subprocess.Popen(bin_path_and_args,
                                      shell=False,
                                      stdout=subprocess.PIPE,
                                      stderr=subprocess.STDOUT)
 
-                logger = logging.getLogger(__name__)
-                log_thread = _LoggingThread(p.stdout, logger.debug)
+                logger = logging.getLogger('mavsdk_server')
+                log_thread = _LoggingThread(p.stdout, logger)
                 log_thread.start()
         except FileNotFoundError:
             print("""
diff --git a/mavsdk/telemetry.py b/mavsdk/telemetry.py
@@ -4739,7 +4739,7 @@ async def scaled_imu(self):
 
     async def raw_imu(self):
         """
-         Subscribe to 'Raw IMU' updates.
+         Subscribe to 'Raw IMU' updates (note that units are are incorrect and "raw" as provided by the sensor)
 
          Yields
          -------
diff --git a/mavsdk/telemetry_pb2_grpc.py b/mavsdk/telemetry_pb2_grpc.py
@@ -511,7 +511,7 @@ def SubscribeScaledImu(self, request, context):
         raise NotImplementedError('Method not implemented!')
 
     def SubscribeRawImu(self, request, context):
-        """Subscribe to 'Raw IMU' updates.
+        """Subscribe to 'Raw IMU' updates (note that units are are incorrect and "raw" as provided by the sensor)
         """
         context.set_code(grpc.StatusCode.UNIMPLEMENTED)
         context.set_details('Method not implemented!')
diff --git a/proto b/proto
@@ -1 +1 @@
-Subproject commit 61b1b1a197966faed181f8c7c5f2fa57d832cf1f
+Subproject commit 7bc04403dbf03ed7a313f1669f59774f13cf12a9
