Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Expression policy not logging #12764

Open
KaiHicks opened this issue Jan 22, 2025 · 1 comment
Open

Expression policy not logging #12764

KaiHicks opened this issue Jan 22, 2025 · 1 comment
Labels
bug Something isn't working

Comments

@KaiHicks
Copy link

Describe the bug
When I create an expression policy bound to a step or application that contains log statements, they are not showing in the server logs. This is with any logging level.

To Reproduce
Steps to reproduce the behavior:

  1. Set logging level to trace
  2. Create the following expression policy:
ak_logger.info(f"--Logged-- from ak_logger {request=}")
print(f"--Logged-- from print {request=}")
return True
  1. Enable execution logging on the expression
  2. Bind the policy to an application
  3. Trigger authorization on the application. In my case, the application has a proxy provider so I tried to ping the service through the reverse proxy. In this step, I used the user "test2"
  4. Go to your application and click the Test button under Check access and test the application. In this step, I used the user "test"

Expected behavior
I should find two logs like --Logged-- from ak_logger request=<PolicyRequest user=... in the server logs.

The first such log should show the user test2, corresponding to step 5. The second such log should show the user test, corresponding to step 6.

As for the print statement, I would expect them to show in the logs in the same way, but I would also understand if they did not.

Logs

$ sudo docker logs -t -f --since 10m authentik_sso-server-1 2>&1 | grep "\\--L
ogged--"
2025-01-22T04:55:44.419081214Z --Logged-- from print request=<PolicyRequest user=test ...>

When I invoke the provider by pinging the service through my reverse proxy, I do find logs indicating that the provider is being used

    {
        "event": "/outpost.goauthentik.io/auth/nginx",
        "host": "nextcloud.home.arakawa.app",
        "level": "info",
        "logger": "authentik.outpost.proxyv2.application",
        "method": "GET",
        "name": "[Proxy] Provider for NextCloud",
        "remote": "...",
        "runtime": "0.649",
        "scheme": "http",
        "size": 21,
        "status": 401,
        "timestamp": "2025-01-22T04:55:36.12Z",
        "user_agent": "Nextcloud/6.2.3 (it.twsweb.Nextcloud; build:1; iOS 18.2.1) Alamofire/5.10.2"
    }

Note that we only see a single log from the print statement for the user test. The logs from the test2 user are not present at all. Additionally, any logs from ak_logger are not present either.

I have also tried info and debug logging levels.

Version and Deployment (please complete the following information):

  • authentik version: 2024.12.1
  • Deployment: docker-compose
@KaiHicks KaiHicks added the bug Something isn't working label Jan 22, 2025
@BeryJu
Copy link
Member

BeryJu commented Jan 22, 2025

When using the "Check access" function, logs of policies are captured and shown in the UI, hence they don't show up in the server stdout.

Specifically with the proxy provider, application policies are checked during initial authorization, not for every request to the outpost, so you'd have to login to the application in an incognito window

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants