Output when starting:

opal_client_1        | 2023-04-18T13:36:50.285126+0000 | 16 | opal_client.opa.runner                  | INFO  | Running OPA inline: opa run --server --addr=:8181 --authentication=off --authorization=off --config-file=/opal/config/config.yaml --log-level=debug
opal_client_1        | 2023-04-18T13:36:50.312097+0000 | 16 | opal_client.opa.logger                  | INFO  | Initializing server. {"addrs": [":8181"], "diagnostic-addrs": [], "time": "2023-04-18T13:36:50Z"}
opal_client_1        | 2023-04-18T13:36:50.313281+0000 | 16 | opal_client.opa.logger                  | INFO  | Starting decision logger. {"plugin": "decision_logs", "time": "2023-04-18T13:36:50Z"}

Not only do I not see decision logs, but I also don't ee the request/response pair when i make a query. However, I see logs like this

opal_client_1        | 2023-04-18T13:46:06.269338+0000 | 16 | opal_client.opa.logger                  | INFO  | Received request.    {"client_addr": "127.0.0.1:54582", "req_body": "", "req_id": 2, "req_method": "GET", "req_params": {}, "req_path": "/v1/policies", "time": "2023-04-18T13:46:06Z"}
opal_client_1        | 2023-04-18T13:46:06.270038+0000 | 16 | opal_client.opa.logger                  | INFO  | Sent response.       {"client_addr": "127.0.0.1:54582", "req_id": 2, "req_method": "GET", "req_path": "/v1/policies", "resp_body": "{\"result\":[]}\n", "resp_bytes": 14, "resp_duration": 0.7213, "resp_status": 200, "time": "2023-04-18T13:46:06Z"}

I got it when I run

docker compose -f docker-compose-example.yml up

without any config change

When I change it to be similar the values you posted before it is even better, and I see the full response in the logs as well, eg:

docker-opal_client-1               | 2023-04-18T14:04:25.406845+0000 | 56 | opal_client.opa.logger                  | INFO  | Sent response.       {"client_addr": "172.18.0.1:59754", "req_id": 13, "req_method": "GET", "req_path": "/v1/data/app/rbac", "resp_body": "{\"result\":{\"allow\":false,\"user_is_granted\":[]}}", "resp_bytes": 47, "resp_duration": 19.641375, "resp_status": 200, "time": "2023-04-18T14:04:25Z"}

This is my docker compose with few changes:

version: "3.8"
services:
  # When scaling the opal-server to multiple nodes and/or multiple workers, we use
  # a *broadcast* channel to sync between all the instances of opal-server.
  # Under the hood, this channel is implemented by encode/broadcaster (see link below).
  # At the moment, the broadcast channel can be either: postgresdb, redis or kafka.
  # The format of the broadcaster URI string (the one we pass to opal server as `OPAL_BROADCAST_URI`) is specified here:
  # <https://github.com/encode/broadcaster#available-backends>
  broadcast_channel:
    image: postgres:alpine
    environment:
      - POSTGRES_DB=postgres
      - POSTGRES_USER=postgres
      - POSTGRES_PASSWORD=postgres
  opal_server:
    # by default we run opal-server from latest official image
    image: permitio/opal-server:latest
    environment:
      # the broadcast backbone uri used by opal server workers (see comments above for: broadcast_channel)
      - OPAL_BROADCAST_URI=<postgres://postgres:postgres@broadcast_channel:5432/postgres>
      # number of uvicorn workers to run inside the opal-server container
      - UVICORN_NUM_WORKERS=4
      # the git repo hosting our policy
      # - if this repo is not public, you can pass an ssh key via `OPAL_POLICY_REPO_SSH_KEY`)
      # - the repo we pass in this example is *public* and acts as an example repo with dummy rego policy
      # - for more info, see: <https://docs.opal.ac/tutorials/track_a_git_repo>
      - OPAL_POLICY_REPO_URL=<https://github.com/permitio/opal-example-policy-repo>
      # in this example we will use a polling interval of 30 seconds to check for new policy updates (git commits affecting the rego policy).
      # however, it is better to utilize a git *webhook* to trigger the server to check for changes only when the repo has new commits.
      # for more info see: <https://docs.opal.ac/tutorials/track_a_git_repo>
      - OPAL_POLICY_REPO_POLLING_INTERVAL=30
      # configures from where the opal client should initially fetch data (when it first goes up, after disconnection, etc).
      # the data sources represents from where the opal clients should get a "complete picture" of the data they need.
      # after the initial sources are fetched, the client will subscribe only to update notifications sent by the server.
      - OPAL_DATA_CONFIG_SOURCES={"config":{"entries":[{"url":"<http://opal_server:7002/policy-data>","topics":["policy_data"],"dst_path":"/static"}]}}
      - OPAL_LOG_FORMAT_INCLUDE_PID=true
    ports:
      # exposes opal server on the host machine, you can access the server at: <http://localhost:7002>
      - "7002:7002"
    depends_on:
      - broadcast_channel
  opal_client:
    # by default we run opal-client from latest official image
    image: permitio/opal-client:latest
    environment:
      - OPAL_SERVER_URL=<http://opal_server:7002>
      - OPAL_LOG_FORMAT_INCLUDE_PID=true
      - OPAL_INLINE_OPA_LOG_FORMAT=http
      - OPAL_INLINE_OPA_LOG_FORMAT=full
      - OPAL_INLINE_OPA_CONFIG={"log_level":"debug"}
    ports:
      # exposes opal client on the host machine, you can access the client at: <http://localhost:7000>
      - "7004:7000"
      # exposes the OPA agent (being run by OPAL) on the host machine
      # you can access the OPA api that you know and love at: <http://localhost:8181>
      # OPA api docs are at: <https://www.openpolicyagent.org/docs/latest/rest-api/>
      - "8181:8181"
    depends_on:
      - opal_server
    # this command is not necessary when deploying OPAL for real, it is simply a trick for dev environments
    # to make sure that opal-server is already up before starting the client.
    command: sh -c "./wait-for.sh opal_server:7002 --timeout=20 -- ./start.sh"

This is an example request that I've sent

curl --location --request GET '<http://localhost:8181/v1/data/app/rbac>' \
--data-raw ''

So either it is my policies (which seem to work fine, but perhaps break the logging?) or it is the MAIN_BRANCH or SUBSCRIPTION_DIRS properties. I'll play a bit to test it out

Ok, I have confirmed it has something to do with my policies/data. Because I get the decision logging still working with the properties above. I've set up a copy of the sample here on my development branch. https://github.com/david-hamilton-bah/opal-example-policy-repo/tree/development There are multiple directories and using the property

OPAL_POLICY_SUBSCRIPTION_DIRS=common:tenant_petshop

and having a util function within the

common

directory. I've included a docker-compose and postman collection. To be clear, this sample DOES work as expected. It is only when I apply my real policies and data that it breaks, so I'll just have to keep digging.

I see now that after doing several requests with my real policies, requests begin to hang with no response from OPA. Part of the problem is probably that i didn't realize the data would be prefixed with the directory name, whereas the policies won't be prefixed unless it is set in the package name in the rego file

so just copying someone's existing policies into a directory and "subscribing" to that will require all references to `data.*`to be changed to

data.tenant_petshop.*

for example

Coming back to this after doing some other work, I have simplified my scenario a bit. If I run the embedded OPA I will always see the server hanging when decision logs are turned on, but if I run OPA separately it runs fine. Starting OPA with

opa run --server --log-format json-pretty -c config.yaml ./server -l debug

Then in my docker-compose opal_client env

- OPAL_INLINE_OPA_ENABLED=false
      - OPAL_POLICY_STORE_URL=<http://host.docker.internal:8181>

./server

is an empty directory, so I am starting up OPA with no policies

OPAL client sends all the policy and static data and my policies work propertly, however, just doing the same with the embedded OPA, all my requests just load forever with no logging from OPA or OPAL client

repository is 2.3MB

Got policy bundle with 49 rego files, 1 data files

Docker stats prior to running any requests

CONTAINER ID   NAME                                      CPU %     MEM USAGE / LIMIT     MEM %     NET I/O           BLOCK I/O         PIDS
9350f5de83e1   bip-baaz-opal-opal_client-1               0.33%     101.4MiB / 1.938GiB   5.11%     390kB / 19.2kB    35.9MB / 0B      15

then after

CONTAINER ID   NAME                                      CPU %     MEM USAGE / LIMIT     MEM %     NET I/O           BLOCK I/O         PIDS
9350f5de83e1   bip-baaz-opal-opal_client-1               0.28%     103.5MiB / 1.938GiB   5.21%     401kB / 550kB     38.2MB / 0B       15

No significant changes to resources

Let me know if there is anything else I can do to debug the embedded OPA instance or any other metrics I could give you.

In the command line you’ve shared (

opa run --server --log-format json-pretty -c config.yaml ./server -l debug

), does the

./server

directory contain all policies? (that are also stored in your git repo)

And the received/sent messages stop. There is no received message for the request that freezes

but I get all the messages showing that OPAL sent the policies and OPA received them, and i still get the keepalive logs from opal client