refactor(functions): remove log_format config, add app_name parameter

- Remove external_function.log_format configuration option and --log-format CLI flag
- Standardize on JSON formatted logging for all external function applications
- Add external_function.app_name configuration option with --app-name CLI flag
- Change Application class constructor parameter from 'name=' to 'app_name=' for consistency
- Update logging configuration to use JSON formatter for both console and file output
- Improve structured logging with additional context fields (app_name, request_id, etc.)

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <[email protected]>

Author: kesmit13

singlestoredb/config.py

@@ -413,12 +413,6 @@
     environ=['SINGLESTOREDB_EXT_FUNC_LOG_FILE'],
 )
 
-register_option(
-    'external_function.log_format', 'string', check_str, '%(levelprefix)s %(message)s',
-    'Log format string for formatting log messages.',
-    environ=['SINGLESTOREDB_EXT_FUNC_LOG_FORMAT'],
-)
-
 register_option(
     'external_function.name_prefix', 'string', check_str, '',
     'Prefix to add to external function names.',
@@ -468,6 +462,12 @@
     environ=['SINGLESTOREDB_EXT_FUNC_DISABLE_METRICS'],
 )
 
+register_option(
+    'external_function.app_name', 'string', check_str, None,
+    'Name for the external function application instance.',
+    environ=['SINGLESTOREDB_EXT_FUNC_APP_NAME'],
+)
+
 #
 # Debugging options
 #

singlestoredb/functions/ext/asgi.py

@@ -91,7 +91,6 @@
 
 logger = utils.get_logger('singlestoredb.functions.ext.asgi')
 
-
 # If a number of processes is specified, create a pool of workers
 num_processes = max(0, int(os.environ.get('SINGLESTOREDB_EXT_NUM_PROCESSES', 0)))
 if num_processes > 1:
@@ -688,16 +687,12 @@ class Application(object):
         File path to write logs to instead of console. If None, logs are
         written to console. When specified, application logger handlers
         are replaced with a file handler.
-    log_format : str, optional
-        Log format string for formatting log messages. Defaults to
-        '%(levelprefix)s %(message)s'. Uses the DefaultFormatter which
-        supports the %(levelprefix)s field.
     log_level : str, optional
         Logging level for the application logger. Valid values are 'info',
         'debug', 'warning', 'error'. Defaults to 'info'.
     disable_metrics : bool, optional
         Disable logging of function call metrics. Defaults to False.
-    name : str, optional
+    app_name : str, optional
         Name for the application instance. Used to create a logger-specific
         name. If not provided, a random name will be generated.
 
@@ -867,10 +862,10 @@ def __init__(
         name_suffix: str = get_option('external_function.name_suffix'),
         function_database: Optional[str] = None,
         log_file: Optional[str] = get_option('external_function.log_file'),
-        log_format: str = get_option('external_function.log_format'),
+
         log_level: str = get_option('external_function.log_level'),
         disable_metrics: bool = get_option('external_function.disable_metrics'),
-        name: Optional[str] = None,
+        app_name: Optional[str] = get_option('external_function.app_name'),
     ) -> None:
         if link_name and (link_config or link_credentials):
             raise ValueError(
@@ -888,10 +883,10 @@ def __init__(
             ) or None
 
         # Generate application name if not provided
-        if name is None:
-            name = f'ext_app_{secrets.token_hex(4)}'
+        if app_name is None:
+            app_name = f'udf_app_{secrets.token_hex(4)}'
 
-        self.name = name
+        self.name = app_name
 
         # Create logger instance specific to this application
         self.logger = utils.get_logger(f'singlestoredb.functions.ext.asgi.{self.name}')
@@ -988,33 +983,41 @@ def __init__(
         self.external_functions = external_functions
         self.function_database = function_database
         self.log_file = log_file
-        self.log_format = log_format
         self.log_level = log_level
         self.disable_metrics = disable_metrics
 
         # Configure logging
         self._configure_logging()
 
     def _configure_logging(self) -> None:
-        """Configure logging based on the log_file and log_format settings."""
+        """Configure logging based on the log_file settings."""
         # Set logger level
         self.logger.setLevel(getattr(logging, self.log_level.upper()))
 
+        # Remove all existing handlers to ensure clean configuration
+        self.logger.handlers.clear()
+
         # Configure log file if specified
         if self.log_file:
-            # Remove existing handlers
-            self.logger.handlers.clear()
-
             # Create file handler
             file_handler = logging.FileHandler(self.log_file)
             file_handler.setLevel(getattr(logging, self.log_level.upper()))
 
-            # Create formatter
-            formatter = utils.DefaultFormatter(self.log_format)
+            # Use JSON formatter for file logging
+            formatter = utils.JSONFormatter()
             file_handler.setFormatter(formatter)
 
             # Add the handler to the logger
             self.logger.addHandler(file_handler)
+        else:
+            # For console logging, create a new stream handler with JSON formatter
+            console_handler = logging.StreamHandler()
+            console_handler.setLevel(getattr(logging, self.log_level.upper()))
+            console_handler.setFormatter(utils.JSONFormatter())
+            self.logger.addHandler(console_handler)
+
+        # Prevent propagation to avoid duplicate or differently formatted messages
+        self.logger.propagate = False
 
     async def __call__(
         self,
@@ -1038,19 +1041,22 @@ async def __call__(
         request_id = str(uuid.uuid4())
 
         timer = Timer(
+            app_name=self.name,
             id=request_id,
             timestamp=datetime.datetime.now(
                 datetime.timezone.utc,
             ).strftime('%Y-%m-%dT%H:%M:%S.%fZ'),
         )
         call_timer = Timer(
+            app_name=self.name,
             id=request_id,
             timestamp=datetime.datetime.now(
                 datetime.timezone.utc,
             ).strftime('%Y-%m-%dT%H:%M:%S.%fZ'),
         )
 
-        assert scope['type'] == 'http'
+        if scope['type'] != 'http':
+            raise ValueError(f"Expected HTTP scope, got {scope['type']}")
 
         method = scope['method']
         path = tuple(x for x in scope['path'].split('/') if x)
@@ -1077,13 +1083,14 @@ async def __call__(
         if method == 'POST' and func is not None and path == self.invoke_path:
 
             self.logger.info(
-                json.dumps({
-                    'type': 'function_call',
-                    'id': request_id,
-                    'name': func_name.decode('utf-8'),
+                'Function call initiated',
+                extra={
+                    'app_name': self.name,
+                    'request_id': request_id,
+                    'function_name': func_name.decode('utf-8'),
                     'content_type': content_type.decode('utf-8'),
                     'accepts': accepts.decode('utf-8'),
-                }),
+                },
             )
 
             args_data_format = func_info['args_data_format']
@@ -1164,7 +1171,13 @@ async def __call__(
 
             except asyncio.TimeoutError:
                 self.logger.exception(
-                    'Timeout in function call: ' + func_name.decode('utf-8'),
+                    'Function call timeout',
+                    extra={
+                        'app_name': self.name,
+                        'request_id': request_id,
+                        'function_name': func_name.decode('utf-8'),
+                        'timeout': func_info['timeout'],
+                    },
                 )
                 body = (
                     '[TimeoutError] Function call timed out after ' +
@@ -1175,14 +1188,25 @@ async def __call__(
 
             except asyncio.CancelledError:
                 self.logger.exception(
-                    'Function call cancelled: ' + func_name.decode('utf-8'),
+                    'Function call cancelled',
+                    extra={
+                        'app_name': self.name,
+                        'request_id': request_id,
+                        'function_name': func_name.decode('utf-8'),
+                    },
                 )
                 body = b'[CancelledError] Function call was cancelled'
                 await send(self.error_response_dict)
 
             except Exception as e:
                 self.logger.exception(
-                    'Error in function call: ' + func_name.decode('utf-8'),
+                    'Function call error',
+                    extra={
+                        'app_name': self.name,
+                        'request_id': request_id,
+                        'function_name': func_name.decode('utf-8'),
+                        'exception_type': type(e).__name__,
+                    },
                 )
                 body = f'[{type(e).__name__}] {str(e).strip()}'.encode('utf-8')
                 await send(self.error_response_dict)
@@ -1236,7 +1260,16 @@ async def __call__(
             timer.metrics[k] = v
 
         if not self.disable_metrics:
-            self.logger.info(json.dumps(timer.finish()))
+            metrics = timer.finish()
+            self.logger.info(
+                'Function call metrics',
+                extra={
+                    'app_name': self.name,
+                    'request_id': request_id,
+                    'function_name': timer.metadata.get('function', ''),
+                    'metrics': metrics,
+                },
+            )
 
     def _create_link(
         self,
@@ -1348,8 +1381,12 @@ def get_function_info(
 
                 except Exception as e:
                     self.logger.warning(
-                        f'Could not parse docstring for function '
-                        f'{key.decode("utf-8")}: {e}',
+                        'Could not parse docstring for function',
+                        extra={
+                            'app_name': self.name,
+                            'function_name': key.decode('utf-8'),
+                            'error': str(e),
+                        },
                     )
 
             if not func_name or key == func_name:
@@ -1812,14 +1849,7 @@ def main(argv: Optional[List[str]] = None) -> None:
             ),
             help='File path to write logs to instead of console',
         )
-        parser.add_argument(
-            '--log-format', metavar='format',
-            default=defaults.get(
-                'log_format',
-                get_option('external_function.log_format'),
-            ),
-            help='Log format string for formatting log messages',
-        )
+
         parser.add_argument(
             '--disable-metrics', action='store_true',
             default=defaults.get(
@@ -1852,6 +1882,14 @@ def main(argv: Optional[List[str]] = None) -> None:
             ),
             help='Database to use for the function definition',
         )
+        parser.add_argument(
+            '--app-name', metavar='app_name',
+            default=defaults.get(
+                'app_name',
+                get_option('external_function.app_name'),
+            ),
+            help='Name for the application instance',
+        )
         parser.add_argument(
             'functions', metavar='module.or.func.path', nargs='*',
             help='functions or modules to export in UDF server',
@@ -1951,9 +1989,9 @@ def main(argv: Optional[List[str]] = None) -> None:
         name_suffix=args.name_suffix,
         function_database=args.function_database or None,
         log_file=args.log_file,
-        log_format=args.log_format,
         log_level=args.log_level,
         disable_metrics=args.disable_metrics,
+        app_name=args.app_name,
     )
 
     funcs = app.get_create_functions(replace=args.replace_existing)
@@ -1965,7 +2003,7 @@ def main(argv: Optional[List[str]] = None) -> None:
 
     try:
         if args.db:
-            logger.info('registering functions with database')
+            logger.info('Registering functions with database')
             app.register_functions(
                 args.db,
                 replace=args.replace_existing,
@@ -1980,43 +2018,48 @@ def main(argv: Optional[List[str]] = None) -> None:
             ).items() if v is not None
         }
 
-        # Configure uvicorn logging to use the same log file if specified
-        if args.log_file:
-            log_config = {
-                'version': 1,
-                'disable_existing_loggers': False,
-                'formatters': {
-                    'default': {
-                        '()': 'singlestoredb.functions.ext.utils.DefaultFormatter',
-                        'fmt': args.log_format,
-                    },
+        # Configure uvicorn logging to use JSON format
+        log_config = {
+            'version': 1,
+            'disable_existing_loggers': False,
+            'formatters': {
+                'json': {
+                    '()': 'singlestoredb.functions.ext.utils.JSONFormatter',
                 },
-                'handlers': {
-                    'file': {
-                        'class': 'logging.FileHandler',
-                        'formatter': 'default',
-                        'filename': args.log_file,
-                    },
+            },
+            'handlers': {
+                'default': {
+                    'class': (
+                        'logging.FileHandler' if args.log_file
+                        else 'logging.StreamHandler'
+                    ),
+                    'formatter': 'json',
                 },
-                'loggers': {
-                    'uvicorn': {
-                        'handlers': ['file'],
-                        'level': args.log_level.upper(),
-                        'propagate': False,
-                    },
-                    'uvicorn.error': {
-                        'handlers': ['file'],
-                        'level': args.log_level.upper(),
-                        'propagate': False,
-                    },
-                    'uvicorn.access': {
-                        'handlers': ['file'],
-                        'level': args.log_level.upper(),
-                        'propagate': False,
-                    },
+            },
+            'loggers': {
+                'uvicorn': {
+                    'handlers': ['default'],
+                    'level': args.log_level.upper(),
+                    'propagate': False,
+                },
+                'uvicorn.error': {
+                    'handlers': ['default'],
+                    'level': args.log_level.upper(),
+                    'propagate': False,
                 },
-            }
-            app_args['log_config'] = log_config
+                'uvicorn.access': {
+                    'handlers': ['default'],
+                    'level': args.log_level.upper(),
+                    'propagate': False,
+                },
+            },
+        }
+
+        # Add filename to file handler if log file is specified
+        if args.log_file:
+            log_config['handlers']['default']['filename'] = args.log_file  # type: ignore
+
+        app_args['log_config'] = log_config
 
         if use_async:
             asyncio.create_task(_run_uvicorn(uvicorn, app, app_args, db=args.db))
@@ -2025,7 +2068,7 @@ def main(argv: Optional[List[str]] = None) -> None:
 
     finally:
         if not use_async and args.db:
-            logger.info('dropping functions from database')
+            logger.info('Dropping functions from database')
             app.drop_functions(args.db)
 
 
@@ -2038,7 +2081,7 @@ async def _run_uvicorn(
     """Run uvicorn server and clean up functions after shutdown."""
     await uvicorn.Server(uvicorn.Config(app, **app_args)).serve()
     if db:
-        logger.info('dropping functions from database')
+        logger.info('Dropping functions from database')
         app.drop_functions(db)