How to use Apache APISIX Observability logger plugin for API request logging

How to use Apache APISIX Observability logger plugin for API request logging

apache_apisix_file_logging

Here in this article we will see how we can tap the traffic at the API Gateway layer and get insight into our API traffic and monitor them using the Observability Plugin. We will be using the file logger plugin to capture the requests and send these request logs into a file in a specific JSON format.

Test Environment

Fedora 37 workstation
Docker
Docker Compose
curl

What is API Observability

API Observability provides us with the insight into API usage, issues and metrics. In short Observability can provides us with logging data, metrics data, and tracing data to understand more about our API applications and analyse these data to further generate insightful reports.

If you are interested in the video. Here is the YouTube video on the same step by step procedure outlined below.

https://youtu.be/6Tx2cTztFiI

Procedure

Step1: Ensure APISIX services running

As a pre-requisite step, we need to ensure that the APISIX and related services are up and running. Please follow “How to use Opensource Apache APISIX as an API Gateway” to install and configure APISIX service using Docker Compose file and ensure that its up and running.

Step2: Launch Microservices Flask Applications

Here in this step we are going to install python flask package and create a flask based microservices application. This application will be serving on port 2121 with context /postjson. It’s a very basic application which accepts a JSON request body and returns the same as response in JSON format.

Ensure flask python package is installed

[admin@fedser apisix]$ mkdir flask; cd flask
[admin@fedser flask]$ pip install Flask

Create a flask based application which accepts JSON payload data

[admin@fedser flask]$ cat postjson.py 
from flask import Flask, request

app = Flask(__name__)

@app.route('/postjson', methods=['POST'])
def process_json():
    content_type = request.headers.get('Content-Type')
    if (content_type == 'application/json'):
        json = request.json
        return json
    else:
        return 'Content-Type not supported!'

Launch flask application

[admin@fedser flask]$ flask --app postjson run --host=0.0.0.0 --port=2121 &

Create a json payload

[admin@fedser flask]$ cat postdata.json 
{
"name": {
	"firstname": "Alice",
  	"middlename": "Wonder",
	"lastname": "land"
},
"age": 20,
"gender": "Male"
}

Verify flask application using the postdata.json payload

[admin@fedser flask]$ curl -X POST -H "Content-type: application/json" 'http://192.168.29.117:2121/postjson' -d @postdata.json
192.168.29.117 - - [04/Mar/2023 05:38:47] "POST /postjson HTTP/1.1" 200 -
{"age":20,"gender":"Male","name":{"firstname":"Alice","lastname":"land","middlename":"Wonder"}}

Step3: Configure log format using file-logger Plugin metadata

Log format can be declared as key value pairs in JSON format as shown below. Values only support strings. APISIX – https://apisix.apache.org/docs/apisix/apisix-variable/ or Nginx – http://nginx.org/en/docs/varindex.html variables can be used by prefixing the string with $. I have used the nginx variables as shown below.

[admin@fedser apisix]$ curl http://192.168.29.117:9180/apisix/admin/plugin_metadata/file-logger -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
{
  "log_format": {
        "remote_addr": "$remote_addr",
        "remote_user": "$remote_user",
        "@timestamp": "$time_iso8601",
        "request": "$request",
        "status": "$status",
        "body_bytes_sent": "$body_bytes_sent",
        "http_referer": "$http_referer",
        "http_user_agent": "$http_user_agent",
        "request_time": "$request_time",
        "upstream_connect_time": "$upstream_connect_time",
        "upstream_header_time": "$upstream_header_time",
        "upstream_response_time": "$upstream_response_time"
  }
}'
{"key":"\/apisix\/plugin_metadata\/file-logger","value":{"log_format":{"http_user_agent":"$http_user_agent","remote_user":"$remote_user","remote_addr":"$remote_addr","body_bytes_sent":"$body_bytes_sent","upstream_connect_time":"$upstream_connect_time","request":"$request","request_time":"$request_time","http_referer":"$http_referer","upstream_response_time":"$upstream_response_time","@timestamp":"$time_iso8601","status":"$status","upstream_header_time":"$upstream_header_time"}}}

Step4: Create upstream for backend flask application

Upstream is the service to forward your requests to. They can be configured to a Route or abstracted out to an Upstream object.

[admin@fedser apisix]$ curl "http://192.168.29.117:9180/apisix/admin/upstreams/1" -H "X-API-KEY: edd1c9f034335f136f87ad84b625c8f1" -X PUT -d '
{
  "type": "roundrobin",
  "nodes": {
    "192.168.29.117:2121": 1
  }
}'
{"key":"\/apisix\/upstreams\/1","value":{"id":"1","create_time":1678444782,"scheme":"http","hash_on":"vars","pass_host":"pass","update_time":1678444782,"nodes":{"192.168.29.117:2121":1},"type":"roundrobin"}}

Step5: Create route for backend flask application

Routes specify how requests to APISIX are forwarded to the Upstream. They match a client’s request based on defined rules and loads and executes the configured Plugins.

[admin@fedser apisix]$ curl "http://192.168.29.117:9180/apisix/admin/routes/1" \
-H "X-API-KEY: edd1c9f034335f136f87ad84b625c8f1" -X PUT -d '
{
  "methods": ["POST"],
  "host": "example.com",
  "uri": "/postjson",
  "plugins": {
    "file-logger": {
      "path": "logs/file.log"
    }
  },
  "upstream_id": "1"
}'
{"key":"\/apisix\/routes\/1","value":{"create_time":1678444915,"uri":"\/postjson","methods":["POST"],"priority":0,"status":1,"upstream_id":"1","plugins":{"file-logger":{"include_resp_body":false,"path":"logs\/file.log"}},"update_time":1678444915,"id":"1","host":"example.com"}}

Step6: Test the Services

We can validate that we are able to reach the backend application throug the API gateway as shown below.

[admin@fedser flask]$ curl -X POST -H "Content-type: application/json" -H "Host: example.com" 'http://192.168.29.117:9080/postjson' -d @postdata.json
172.20.0.3 - - [04/Mar/2023 06:07:24] "POST /postjson HTTP/1.1" 200 -
{"age":20,"gender":"Male","name":{"firstname":"Alice","lastname":"land","middlename":"Wonder"}}: 

Step7: Validate the logging file

We need to capture the container name or container id for the APISIX service and get an interactive session termial into that container.

[admin@fedser apisix]$ docker ps
CONTAINER ID   IMAGE                                  COMMAND                  CREATED          STATUS          PORTS                                                                                                                                                                                            NAMES
8de48af5f1c3   apache/apisix:3.1.0-debian             "/docker-entrypoint.…"   20 minutes ago   Up 20 minutes   0.0.0.0:9080->9080/tcp, :::9080->9080/tcp, 0.0.0.0:9091-9092->9091-9092/tcp, :::9091-9092->9091-9092/tcp, 0.0.0.0:9180->9180/tcp, :::9180->9180/tcp, 0.0.0.0:9443->9443/tcp, :::9443->9443/tcp   apisix_apisix_1
93bea6fe35f1   bitnami/etcd:3.4.15                    "/opt/bitnami/script…"   20 minutes ago   Up 20 minutes   0.0.0.0:2379->2379/tcp, :::2379->2379/tcp, 2380/tcp                                                                                                                                              apisix_etcd_1
30b3315bd731   apache/apisix-dashboard:3.0.0-alpine   "/usr/local/apisix-d…"   20 minutes ago   Up 20 minutes   0.0.0.0:9000->9000/tcp, :::9000->9000/tcp   

Once you have identified your container id, you can exec into it as shown below.

[admin@fedser apisix]$ docker exec -it 8de48af5f1c3 bash

You can now navigate into the logs folder and see that the file.log file generated with the JSON formatted log message with the required logging infomation.

apisix@8de48af5f1c3:/usr/local/apisix$ cd logs/

apisix@8de48af5f1c3:/usr/local/apisix/logs$ tail -f file.log 
{"body_bytes_sent":"167","remote_addr":"192.168.29.117","route_id":"1","request":"POST \/postjson HTTP\/1.1","status":400,"@timestamp":"2023-03-10T10:42:59+00:00","request_time":0.021,"upstream_connect_time":0.015,"upstream_response_time":0.021,"http_user_agent":"curl\/7.85.0","upstream_header_time":0.021}
{"upstream_connect_time":0.005,"http_user_agent":"curl\/7.85.0","remote_addr":"192.168.29.117","route_id":"1","request":"POST \/postjson HTTP\/1.1","@timestamp":"2023-03-10T10:43:25+00:00","request_time":0.008,"body_bytes_sent":"96","upstream_response_time":0.009,"status":200,"upstream_header_time":0.009}
{"upstream_connect_time":0.009,"http_user_agent":"curl\/7.85.0","remote_addr":"192.168.29.117","route_id":"1","body_bytes_sent":"96","@timestamp":"2023-03-10T10:44:24+00:00","request_time":0.012,"request":"POST \/postjson HTTP\/1.1","upstream_response_time":0.013,"status":200,"upstream_header_time":0.012}
{"upstream_connect_time":0.006,"http_user_agent":"curl\/7.85.0","remote_addr":"192.168.29.117","route_id":"1","body_bytes_sent":"96","@timestamp":"2023-03-10T10:45:50+00:00","request_time":0.007,"request":"POST \/postjson HTTP\/1.1","upstream_response_time":0.008,"status":200,"upstream_header_time":0.008}

Hope you enjoyed reading this article. Thank you..