Self-hosted gateway start to log different after switch to json

[R8iKKo]

Report

Hi,

I am currently facing a problem with sh gw on Ubuntu 20.

I am using podman v3.2.4 and deploying via Ansible AWX.

What I am facing is that gw starts to log weird things after I switched std from text to json.

I also implemented log-driver: json-file, but the issue remains with logging into localsyslog and even when switching back to text.

I somehow "switched" logs and I am not able to even revert it back.

What I want are normal transaction logs that are default by gw. Such as:

apimuser[3]: Timestamp=2024-06-26T20:11:49.7829750Z, isRequestSuccess=true, totalTime=72, category=""GatewayLogs"", callerIpAddress=""xxx.xxx.xxx.xxx"", timeGenerated=2024-06-26T20:11:49.7829750Z, region=""Czech\ Republic"", correlationId=""xxx"", method=""GET"", url=""https://xxx.xxx"", responseCode=200, responseSize=143, cache=""none"", backendTime=71, apiId=""health"", operationId=""health"", apimSubscriptionId="xxx", clientProtocol=""HTTP/1.1"", apiRevision=""1""

What I am getting now is:

{"level":"Informational","timestamp":"2024-06-26T20:16:04.5669435Z","message":
2024-06-26T20:16:04.567045513+00:00 stdout F "www.gstatic.com","source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.583582303+00:00 stdout P {"level":"Informational","timestamp":"2024-06-26T20:16:04.5835271Z","message":"www.gstatic.com: [142.251.36.99]"
2024-06-26T20:16:04.583628904+00:00 stdout F ,"source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.583628904+00:00 stdout F {"level":"Informational","timestamp":"2024-06-26T20:16:04.5835785Z","message":"www.gstatic.com","source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.643500552+00:00 stdout P {"level":"Informational","timestamp":"2024-06-26T20:16:04.6397997Z","apiId":"xxx","operationId":"xxx","
2024-06-26T20:16:04.643557853+00:00 stdout P subscriptionId":"xxx,"tags":2593,"httpMethod":"GET","source":"TelemetryEntry","serviceName":"axxx","message":"27125","transportError":0
2024-06-26T20:16:04.643576754+00:00 stdout F ,"httpError":0}

My current ansible .yml is:

• name: Create APIMGW container
  containers.podman.podman_container:
  pod: apimgw-pod
  name: apimgw
  image: mcr.microsoft.com/azure-api-management/gateway:2.6.0
  state: present
  recreate: yes
  volume:
  - /etc/ssl/certs:/etc/ssl/certs
  - /opt/apimgw:/home/apimuser
  - /dev/log:/dev/log
  env:
  config.service.endpoint: "{{ config_service_endpoint }}"
  runtime.deployment.artifact.source: "Azure Portal"
  runtime.deployment.mechanism: "YAML"
  events.snapshot.backup.filesystem.location: "/home/apimuser"
  certificates.local.ca.enabled: true
  telemetry.logs.std: "json"
  telemetry.logs.std.level: "info"
  telemetry.logs.std.color: false
  env_file: /opt/apimgw/gatewaykey.env
  log_driver: json-file
  log_options: path=/var/log/apimgw-logs/{{ gateway_name }}.json

Previous playbook that worked fine was:

• name: Create APIMGW container
  containers.podman.podman_container:
  pod: apimgw-pod
  name: apimgw
  image: mcr.microsoft.com/azure-api-management/gateway:2.6.0
  state: present
  recreate: yes
  volume:
  - /etc/ssl/certs:/etc/ssl/certs
  - /opt/apimgw:/home/apimuser
  - /dev/log:/dev/log
  env:
  config.service.endpoint: "{{ config_service_endpoint }}"
  runtime.deployment.artifact.source: "Azure Portal"
  runtime.deployment.mechanism: "YAML"
  events.snapshot.backup.filesystem.location: "/home/apimuser"
  certificates.local.ca.enabled: true
  telemetry.logs.std: "text"
  telemetry.logs.std.level: "info"
  telemetry.logs.local: "localsyslog"
  telemetry.logs.local.localsyslog.endpoint: "/dev/log"
  telemetry.logs.local.localsyslog.facility: "7"
  env_file: /opt/apimgw/gatewaykey.env

But even when I reverted to former config, is still shows same "nonsense" but logs to syslog in text as it should.
What I've noticed is that in syslog, I cannot see logs under apimuser anymore, the are under name of the container [apimgw]

Is it possible that I somehow changed the level of logging for the gateway? And any ideas how to restore basic transaction logs and be able to log them in json to file? Thank you.

Expected Behavior

Standard gateway transaction logs

Actual Behavior

Weird network? logs in json instead

Steps to Reproduce the Problem

1. Deploy gateway with std set to json
2. Set log-driver to json-file
3. Revert settings to see if the logs are being changed even after rollback

Logs from self-hosted gateway

{"level":"Informational","timestamp":"2024-06-26T20:16:04.5669435Z","message":
2024-06-26T20:16:04.567045513+00:00 stdout F "www.gstatic.com","source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.583582303+00:00 stdout P {"level":"Informational","timestamp":"2024-06-26T20:16:04.5835271Z","message":"www.gstatic.com: [142.251.36.99]"
2024-06-26T20:16:04.583628904+00:00 stdout F ,"source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.583628904+00:00 stdout F {"level":"Informational","timestamp":"2024-06-26T20:16:04.5835785Z","message":"www.gstatic.com","source":"RoundRobinNameResolver"}
2024-06-26T20:16:04.643500552+00:00 stdout P {"level":"Informational","timestamp":"2024-06-26T20:16:04.6397997Z","apiId":"xxx","operationId":"xxx","
2024-06-26T20:16:04.643557853+00:00 stdout P subscriptionId":"xxx,"tags":2593,"httpMethod":"GET","source":"TelemetryEntry","serviceName":"axxx","message":"27125","transportError":0
2024-06-26T20:16:04.643576754+00:00 stdout F ,"httpError":0}

Self-hosted Gateway Version

2.6.0

Deployment

Self-Managed (YAML/Helm)

Platform

None

Kubernetes Version

None

Anything else?

No response

[tomkerkhove]

You have telemetry.logs.std: "json" configured which means logs will be in JSON. If you don't want that, change it back to text.

[R8iKKo]

Yes, but the problem is not with the format. I know I changed format from text to json, the problem I tried to show is that after this change, all transaction logs disappeared. That is the issue I'm having. That's why I send both log examples - before and after, I think you can clearly see the output changed, but not just from text to json, but whole output is different, showing things I'm not even interested in.

I also tried to recreate this issue with docker-compose and seems like docker is not having this problem. Even after switch to json and setting up loging to localsyslog and then filtering data with rsyslog, I am getting proper transaction logs into separate file.

My issue here is why is it seems to be impossible to achieve via podman, or why gateway switched to log just network related things, but not transactions. Thank you

[tomkerkhove]

With transactional logs you mean request logs? If so, this is a known issue that we are fixing and will be shipped over summer.

[R8iKKo]

Oh sorry, yes I meant request logs. So is it a bug connected to podman? Like I said, I tried to reproduce this with docker-compose and I don't see this issue happening there.

Anyways thank you for your answer.

[tomkerkhove]

The bug seems to be in general, based on the configuration of the service.
Most likely it works if you enable local diagnostics on a single API