Repository: apache/airflow
Pull request: 10166 : Add capability to specify gunicorn access log format for airflow
Added capability to specify airflow webserver access log format. The format can be specified in airflow.cfg file or passed as argument to airflow webserver command.

Close: #10166 

Problem statement:
Add capability to specify gunicorn access log format for airflow webserver
**Description**

Currently gunicorn access logs don't include response time. In gunicorn we can specify access-logformat to include response time. When running airflow webserver we should be able to specify this format by either defining it in airflow.cfg or passing as argument in airflow webserver command.

**Use case / motivation**

We want to monitor airlfow response time.

**Related Issues**

None

Hints from issue discussion:
Thanks for opening your first issue here! Be sure to follow the issue template!

Hi. Would you like to prepare a PR to implement this feature? I will gladly support you if you have any questions.


Hi @mik-laj , I have made the required changes. Could you please guide how I can test it?
I have run integration tests in breeze env. I want to build it locally and test the webserver.
Can you create a draft pull request?
https://github.com/apache/airflow/pull/10261 
Please take a look

Commit message: 10166 : Unit tests

Patch to review:
diff --git a/airflow/cli/cli_parser.py b/airflow/cli/cli_parser.py
index 5c043ccff1d04..bf2471e5585eb 100644
--- a/airflow/cli/cli_parser.py
+++ b/airflow/cli/cli_parser.py
@@ -504,6 +504,10 @@ def positive_int(value):
     default=conf.get('webserver', 'ERROR_LOGFILE'),
     help="The logfile to store the webserver error log. Use '-' to print to "
          "stderr")
+ARG_ACCESS_LOGFORMAT = Arg(
+    ("-L", "--access-logformat"),
+    default=conf.get('webserver', 'ACCESS_LOGFORMAT'),
+    help="The access log format for gunicorn logs")
 
 # scheduler
 ARG_DAG_ID_OPT = Arg(
@@ -1251,8 +1255,8 @@ class GroupCommand(NamedTuple):
         func=lazy_load_command('airflow.cli.commands.webserver_command.webserver'),
         args=(
             ARG_PORT, ARG_WORKERS, ARG_WORKERCLASS, ARG_WORKER_TIMEOUT, ARG_HOSTNAME, ARG_PID,
-            ARG_DAEMON, ARG_STDOUT, ARG_STDERR, ARG_ACCESS_LOGFILE, ARG_ERROR_LOGFILE, ARG_LOG_FILE,
-            ARG_SSL_CERT, ARG_SSL_KEY, ARG_DEBUG
+            ARG_DAEMON, ARG_STDOUT, ARG_STDERR, ARG_ACCESS_LOGFILE, ARG_ERROR_LOGFILE, ARG_ACCESS_LOGFORMAT,
+            ARG_LOG_FILE, ARG_SSL_CERT, ARG_SSL_KEY, ARG_DEBUG
         ),
     ),
     ActionCommand(
diff --git a/airflow/cli/commands/webserver_command.py b/airflow/cli/commands/webserver_command.py
index a8d4cd86f415b..7502797155415 100644
--- a/airflow/cli/commands/webserver_command.py
+++ b/airflow/cli/commands/webserver_command.py
@@ -316,6 +316,7 @@ def webserver(args):
 
     access_logfile = args.access_logfile or conf.get('webserver', 'access_logfile')
     error_logfile = args.error_logfile or conf.get('webserver', 'error_logfile')
+    access_logformat = args.access_logformat or conf.get('webserver', 'access_logformat')
     num_workers = args.workers or conf.get('webserver', 'workers')
     worker_timeout = (args.worker_timeout or
                       conf.get('webserver', 'web_server_worker_timeout'))
@@ -356,11 +357,13 @@ def webserver(args):
                 Host: {hostname}:{port}
                 Timeout: {worker_timeout}
                 Logfiles: {access_logfile} {error_logfile}
+                Access Logformat: {access_logformat}
                 =================================================================\
             '''.format(num_workers=num_workers, workerclass=args.workerclass,
                        hostname=args.hostname, port=args.port,
                        worker_timeout=worker_timeout, access_logfile=access_logfile,
-                       error_logfile=error_logfile)))
+                       error_logfile=error_logfile,
+                       access_logformat=access_logformat)))
 
         run_args = [
             'gunicorn',
@@ -379,6 +382,9 @@ def webserver(args):
         if args.error_logfile:
             run_args += ['--error-logfile', str(args.error_logfile)]
 
+        if args.access_logformat:
+            run_args += ['--access-logformat', str(args.access_logformat)]
+
         if args.daemon:
             run_args += ['--daemon']
 
diff --git a/airflow/config_templates/config.yml b/airflow/config_templates/config.yml
index 776e61f5b4510..1ca2730b035ad 100644
--- a/airflow/config_templates/config.yml
+++ b/airflow/config_templates/config.yml
@@ -861,6 +861,13 @@
       type: string
       example: ~
       default: "-"
+    - name: access_logformat
+      description: |
+        Access log format for gunicorn webserver
+      version_added: ~
+      type: string
+      example: ~
+      default: "%%(h)s %%(l)s %%(u)s %%(t)s \"%%(r)s\" %%(s)s %%(b)s \"%%(f)s\" \"%%(a)s\""
     - name: expose_config
       description: |
         Expose the configuration file in the web server
diff --git a/airflow/config_templates/default_airflow.cfg b/airflow/config_templates/default_airflow.cfg
index be8b90d1433e7..680ae18751d69 100644
--- a/airflow/config_templates/default_airflow.cfg
+++ b/airflow/config_templates/default_airflow.cfg
@@ -439,6 +439,9 @@ access_logfile = -
 # Log files for the gunicorn webserver. '-' means log to stderr.
 error_logfile = -
 
+# Access log format for gunicorn webserver.
+access_logformat = %%(h)s %%(l)s %%(u)s %%(t)s "%%(r)s" %%(s)s %%(b)s "%%(f)s" "%%(a)s"
+
 # Expose the configuration file in the web server
 expose_config = False
 
diff --git a/tests/cli/commands/test_webserver_command.py b/tests/cli/commands/test_webserver_command.py
index 479a141eaf4b0..4488c3cfcf7d9 100644
--- a/tests/cli/commands/test_webserver_command.py
+++ b/tests/cli/commands/test_webserver_command.py
@@ -15,6 +15,7 @@
 # specific language governing permissions and limitations
 # under the License.
 
+import json
 import os
 import subprocess
 import tempfile
@@ -375,3 +376,45 @@ def test_cli_webserver_debug(self):
             "webserver terminated with return code {} in debug mode".format(return_code))
         proc.terminate()
         self.assertEqual(-15, proc.wait(60))
+
+    def test_cli_webserver_access_log_format(self):
+        access_logfile = "/var/log/access.log"
+        if os.path.exists(access_logfile):
+            os.remove(access_logfile)
+
+        # json access log format
+        access_logformat = "{\"ts\":\"%(t)s\",\"remote_ip\":\"%(h)s\",\"request_id\":\"%({X-Request-Id}i)s\"," \
+                           "\"code\":\"%(s)s\",\"request_method\":\"%(m)s\",\"request_path\":\"%(U)s\",\"agent\":\"%(" \
+                           "a)s\",\"response_time\":\"%(D)s\",\"response_length\":\"%(B)s\"} "
+        with mock.patch.dict(
+            "os.environ",
+            AIRFLOW__CORE__DAGS_FOLDER="/dev/null",
+            AIRFLOW__CORE__LOAD_EXAMPLES="False",
+            AIRFLOW__WEBSERVER__WORKERS="1"
+        ):
+            # Run webserver in foreground and terminate it.
+            proc = subprocess.Popen(
+                ["airflow", "webserver", "--access-logfile", access_logfile, "--access-logformat", access_logformat])
+            self.assertEqual(None, proc.poll())
+
+        # Wait for webserver process
+        sleep(10)
+
+        proc2 = subprocess.Popen(["curl", "http://localhost:8080"])
+        proc2.wait(10)
+        self.assertTrue(os.path.isfile(access_logfile))
+        try:
+            file = open(access_logfile)
+            log = json.loads(file.read())
+            self.assertEqual('127.0.0.1', log.get('remote_ip'))
+            self.assertEqual(len(log), 9)
+            self.assertEqual('GET', log.get('request_method'))
+
+        except IOError:
+            print("access log file not found at " + access_logfile)
+
+        # Terminate webserver
+        proc.terminate()
+        # -15 - the server was stopped before it started
+        #   0 - the server terminated correctly
+        self.assertIn(proc.wait(60), (-15, 0))


Code review comments:
diff_hunk: @@ -861,6 +861,13 @@
       type: string
       example: ~
       default: "-"
+    - name: access_logformat
+      description: |
+        Access log format for gunicorn webserver
+      version_added: ~
+      type: string
+      example: ~
+      default: "%%(h)s %%(l)s %%(u)s %%(t)s \"%%(r)s\" %%(s)s %%(b)s \"%%(f)s\" \"%%(a)s\""
path: airflow/config_templates/config.yml
text: @user1:
Should we define default value? If we pass an empty value, the default value for gunicorn will not be used?

@author:
Made changes, so that we don't need to specify default config. If empty value is passed, default value for gunicorn will be used.