docker-compose up [+] Running 4/3 - Network azuredevops_default Created 0.1s - Container azuredevops-broadcast_channel-1 Created 0.1s - Container azuredevops-opal_server-1 Created 0.1s - Container azuredevops-opal_clientA-1 Created 0.1s Attaching to azuredevops-broadcast_channel-1, azuredevops-opal_clientA-1, azuredevops-opal_server-1 azuredevops-broadcast_channel-1 | The files belonging to this database system will be owned by user "postgres". azuredevops-broadcast_channel-1 | This user must also own the server process. azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | The database cluster will be initialized with locale "en_US.utf8". azuredevops-broadcast_channel-1 | The default database encoding has accordingly been set to "UTF8". azuredevops-broadcast_channel-1 | The default text search configuration will be set to "english". azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | Data page checksums are disabled. azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | fixing permissions on existing directory /var/lib/postgresql/data ... ok azuredevops-broadcast_channel-1 | creating subdirectories ... ok azuredevops-broadcast_channel-1 | selecting dynamic shared memory implementation ... posix azuredevops-broadcast_channel-1 | selecting default max_connections ... 100 azuredevops-broadcast_channel-1 | selecting default shared_buffers ... 128MB azuredevops-broadcast_channel-1 | selecting default time zone ... UTC azuredevops-broadcast_channel-1 | creating configuration files ... ok azuredevops-broadcast_channel-1 | running bootstrap script ... ok azuredevops-broadcast_channel-1 | performing post-bootstrap initialization ... sh: locale: not found azuredevops-broadcast_channel-1 | 2023-02-07 03:58:38.920 UTC [30] WARNING: no usable system locales were found azuredevops-broadcast_channel-1 | ok azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [1] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [1] [INFO] Listening at: http://0.0.0.0:7002 (1) azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [1] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [7] [INFO] Booting worker with pid: 7 azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [8] [INFO] Booting worker with pid: 8 azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [9] [INFO] Booting worker with pid: 9 azuredevops-opal_server-1 | [2023-02-07 03:58:39 +0000] [10] [INFO] Booting worker with pid: 10 azuredevops-broadcast_channel-1 | syncing data to disk ... initdb: warning: enabling "trust" authentication for local connections azuredevops-broadcast_channel-1 | initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb. azuredevops-broadcast_channel-1 | ok azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | Success. You can now start the database server using: azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | pg_ctl -D /var/lib/postgresql/data -l logfile start azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | waiting for server to start....2023-02-07 03:58:40.308 UTC [36] LOG: starting PostgreSQL 15.1 on x86_64-pc-linux-musl, compiled by gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, 64-bit azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.388 UTC [36] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.557 UTC [39] LOG: database system was shut down at 2023-02-07 03:58:39 UTC azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.590 UTC [36] LOG: database system is ready to accept connections azuredevops-broadcast_channel-1 | done azuredevops-broadcast_channel-1 | server started azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | /usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/* azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | waiting for server to shut down...2023-02-07 03:58:40.695 UTC [36] LOG: received fast shutdown request azuredevops-broadcast_channel-1 | .2023-02-07 03:58:40.708 UTC [36] LOG: aborting any active transactions azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.712 UTC [36] LOG: background worker "logical replication launcher" (PID 42) exited with exit code 1 azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.712 UTC [37] LOG: shutting down azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.720 UTC [37] LOG: checkpoint starting: shutdown immediate azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.769 UTC [37] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.020 s, sync=0.006 s, total=0.057 s; sync files=2, longest=0.003 s, average=0.003 s; distance=0 kB, estimate=0 kB azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.779 UTC [36] LOG: database system is shut down azuredevops-broadcast_channel-1 | done azuredevops-broadcast_channel-1 | server stopped azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | PostgreSQL init process complete; ready for start up. azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.877 UTC [1] LOG: starting PostgreSQL 15.1 on x86_64-pc-linux-musl, compiled by gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, 64-bit azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.878 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432 azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.878 UTC [1] LOG: listening on IPv6 address "::", port 5432 azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.892 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.910 UTC [50] LOG: database system was shut down at 2023-02-07 03:58:40 UTC azuredevops-broadcast_channel-1 | 2023-02-07 03:58:40.925 UTC [1] LOG: database system is ready to accept connections azuredevops-opal_clientA-1 | [2023-02-07 03:58:41 +0000] [7] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_clientA-1 | [2023-02-07 03:58:41 +0000] [7] [INFO] Listening at: http://0.0.0.0:7000 (7) azuredevops-opal_clientA-1 | [2023-02-07 03:58:41 +0000] [7] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_clientA-1 | [2023-02-07 03:58:41 +0000] [16] [INFO] Booting worker with pid: 16 azuredevops-opal_server-1 | 2023-02-07T03:58:41.628006+0000 | 7 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T03:58:41.628996+0000 | 7 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T03:58:41.757004+0000 | 8 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T03:58:41.758115+0000 | 8 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T03:58:41.791282+0000 | 10 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T03:58:41.791843+0000 | 10 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T03:58:41.818496+0000 | 7 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T03:58:41.819648+0000 | 7 | opal_server.server | INFO | leadership lock acquired, leader pid: 7 azuredevops-opal_server-1 | 2023-02-07T03:58:41.820003+0000 | 7 | opal_server.server | INFO | listening on webhook topic: 'webhook' azuredevops-opal_server-1 | 2023-02-07T03:58:41.821225+0000 | 7 | opal_server.server | INFO | Policy repo will be cloned to: /opal/regoclone/opal_repo_clone azuredevops-opal_server-1 | 2023-02-07T03:58:41.822803+0000 | 7 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '136c0fc7cca746f3bd06f422d2c885bb', 'subscriber_id': '1c30f5b278184ee19f3a880675431354', 'topic': 'webhook', 'callback': functools.partial(, ), 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:58:41.823512+0000 | 7 | opal_server.policy.watcher.task | INFO | Launching policy watcher azuredevops-opal_server-1 | 2023-02-07T03:58:41.824037+0000 | 7 | opal_common.topics.publisher | INFO | started broadcaster keepalive task: topic is '__broadcast_session_keepalive__', interval is 3600 seconds azuredevops-opal_server-1 | 2023-02-07T03:58:41.826051+0000 | 7 | opal_server.data.data_update_publisher | INFO | [7] Starting Polling Updates azuredevops-opal_server-1 | 2023-02-07T03:58:41.830566+0000 | 7 | opal_common.git.repo_cloner | INFO | Cloning repo from 'git@ssh.dev.azure.com:v3/Alegeus-Technologies/ArchitectureCouncil/OPAL-Policy-Repo' to '/opal/regoclone/opal_repo_clone' (branch: 'master') azuredevops-opal_server-1 | 2023-02-07T03:58:41.895633+0000 | 8 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T03:58:41.914997+0000 | 9 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T03:58:41.915565+0000 | 9 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T03:58:41.922453+0000 | 10 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T03:58:42.003873+0000 | 9 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.231296+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'FastApiRpcFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.231707+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'HttpFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.231858+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Fetcher Register loaded azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.232195+0000 | 16 | opal_client.callbacks.register | INFO | Callbacks register loaded azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.232620+0000 | 16 | opal_client.client | INFO | API authentication disabled (public encryption key was not provided) azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.288124+0000 | 16 | opal_client.opa.runner | INFO | Launching opa runner azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.289057+0000 | 16 | opal_client.opa.runner | INFO | Running OPA inline: opa run --server --addr=:8181 --authentication=off --authorization=off --log-level=info azuredevops-opal_clientA-1 | 2023-02-07T03:58:42.336259+0000 | 16 | opal_client.opa.logger | INFO | Initializing server. {"addrs": [":8181"], "diagnostic-addrs": [], "time": "2023-02-07T03:58:42Z"} azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.295003+0000 | 16 | opal_client.opa.runner | INFO | Running OPA initial start callbacks azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.296187+0000 | 16 | opal_client.data.updater | INFO | Launching data updater azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.296731+0000 | 16 | opal_client.policy.updater | INFO | Launching policy updater azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.297270+0000 | 16 | opal_client.data.updater | INFO | Subscribing to topics: ['policy_data'] azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.298117+0000 | 16 | opal_client.policy.updater | INFO | Subscribing to topics: ['policy:default', 'policy:services/billing'] azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.299390+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Trying to connect to Pub/Sub server - ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.300514+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.308726+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Trying to connect to Pub/Sub server - ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.310526+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:58:43.333187+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_server-1 | 2023-02-07T03:58:43.336657+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_server-1 | 2023-02-07T03:58:43.353829+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'b23eb50b86b54e6caa1dab288b8cc7d8', 'subscriber_id': '861baef3364c46ef92d40569c4aea582', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:58:43.354191+0000 | 8 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T03:58:43.354379+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T03:58:43.354518+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'd0b071d7b92c4e4aad67c2836610d412', 'subscriber_id': '92982df677d5483c9051dc1115999797', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:58:43.354866+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T03:58:43.355187+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T03:58:43.356890+0000 | 8 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T03:58:43.357298+0000 | 9 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T03:58:43.390962+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '09a1be0825104606a13af47276037d2b', 'subscriber_id': '1dd458d0f0f34cd5a7152164eb231374', 'topic': 'policy:services/billing', 'callback': .callback at 0x7f9eeae57400>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:58:43.391240+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '791a0c83f4b14cdcad6c2aa7e413838c', 'subscriber_id': '1dd458d0f0f34cd5a7152164eb231374', 'topic': 'policy:default', 'callback': .callback at 0x7f9eeae57400>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:58:43.393904+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'a60b5af63f4f4194b133a28dc04606bf', 'subscriber_id': '7504b78ac87f43c982156d9b30a00a4f', 'topic': 'policy_data', 'callback': .callback at 0x7f9eeae5b400>, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.394744+0000 | 16 | opal_client.policy.updater | INFO | Connected to server azuredevops-opal_server-1 | 2023-02-07T03:58:43.400838+0000 | 9 | opal_server.data.api | INFO | Serving source configuration azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.395038+0000 | 16 | opal_client.policy.updater | INFO | Refetching policy code (full bundle) azuredevops-opal_server-1 | 2023-02-07T03:58:43.401885+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47220 - "GET /data/config HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.395409+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:58:43.406351+0000 | 10 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47218 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.397781+0000 | 16 | opal_client.data.updater | INFO | Connected to server azuredevops-opal_server-1 | 2023-02-07T03:58:43.407026+0000 | 9 | opal_server.data.api |WARNING | Serving default all-data route, meaning DATA_CONFIG_SOURCES was not configured! azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.397937+0000 | 16 | opal_client.data.updater | INFO | Performing data configuration, reason: Initial load azuredevops-opal_server-1 | 2023-02-07T03:58:43.407411+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47222 - "GET /policy-data HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.397991+0000 | 16 | opal_client.data.updater | INFO | Getting data-sources configuration from 'http://opal_server:7002/data/config' azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.403678+0000 | 16 | opal_client.data.updater | INFO | Triggering data update with id: 382abb12c02d461983a9af2d611cf14d azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.403971+0000 | 16 | opal_client.data.updater | INFO | Fetching policy data azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.404121+0000 | 16 | opal_client.data.fetcher | INFO | Fetching data from url: http://opal_server:7002/policy-data azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.405317+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.406959+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.408465+0000 | 16 | opal_client.data.updater | INFO | Saving fetched data to policy-store: source url='http://opal_server:7002/policy-data', destination path='/static' azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.410350+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/static azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.411107+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/static -> 204 azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.588472+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:58:43.594390+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47226 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T03:58:43.595170+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T03:58:44.258307+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:58:44.266949+0000 | 7 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47234 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T03:58:44.267708+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T03:58:46.513534+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:58:46.524043+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47248 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T03:58:46.525826+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T03:58:47.580403+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:58:47.588823+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47260 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T03:58:47.590079+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T03:58:47.591064+0000 | 16 | opal_client.policy.fetcher |WARNING | Failed all attempts to fetch bundle, got error: ValueError('unexpected response code while fetching bundle: 503') azuredevops-opal_clientA-1 | 2023-02-07T03:58:47.592321+0000 | 16 | opal_client...base_policy_store_client |ERROR | OPA transaction failed, transaction id=3437f4cc80e74cb3a4f64cf53d010a68, actions=[], error=ValueError('unexpected response code while fetching bundle: 503') azuredevops-opal_clientA-1 | 2023-02-07T03:58:47.594178+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:58:49.865223+0000 | 7 | opal_common.git.repo_cloner | INFO | Clone succeeded azuredevops-opal_server-1 | 2023-02-07T03:58:49.869886+0000 | 7 | opal_common.sources.base_policy_source | INFO | Polling task is off azuredevops-opal_clientA-1 | 2023-02-07T03:59:09.439452+0000 | 16 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T03:59:09.439748+0000 | 16 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:10.587853+0000 | 16 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T03:59:10.588109+0000 | 16 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200 azuredevops-opal_server-1 | 2023-02-07T03:59:25.432838+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client disconnected - 47210 :: 7504b78ac87f43c982156d9b30a00a4f azuredevops-opal_server-1 | 2023-02-07T03:59:25.432862+0000 | 8 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client disconnected - 47212 :: 1dd458d0f0f34cd5a7152164eb231374 azuredevops-opal_server-1 | 2023-02-07T03:59:25.433215+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy:services/billing' for subscriber=1dd458d0f0f34cd5a7152164eb231374 azuredevops-opal_server-1 | 2023-02-07T03:59:25.433215+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy_data' for subscriber=7504b78ac87f43c982156d9b30a00a4f azuredevops-opal_server-1 | 2023-02-07T03:59:25.433410+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Cancelling broadcast listen task azuredevops-opal_server-1 | 2023-02-07T03:59:25.433353+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy:default' for subscriber=1dd458d0f0f34cd5a7152164eb231374 azuredevops-opal_server-1 | 2023-02-07T03:59:25.433606+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='__EventNotifier_ALL_TOPICS__' for subscriber=92982df677d5483c9051dc1115999797 azuredevops-opal_server-1 | 2023-02-07T03:59:25.434172+0000 | 9 | websockets.legacy.server | INFO | connection closed azuredevops-opal_server-1 | 2023-02-07T03:59:25.434149+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Cancelling broadcast listen task azuredevops-opal_server-1 | 2023-02-07T03:59:25.435163+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='__EventNotifier_ALL_TOPICS__' for subscriber=861baef3364c46ef92d40569c4aea582 azuredevops-opal_server-1 | 2023-02-07T03:59:25.436180+0000 | 8 | websockets.legacy.server | INFO | connection closed azuredevops-opal_clientA-1 exited with code 137 azuredevops-opal_clientA-1 exited with code 0 azuredevops-opal_clientA-1 | [2023-02-07 03:59:26 +0000] [7] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_clientA-1 | [2023-02-07 03:59:26 +0000] [7] [INFO] Listening at: http://0.0.0.0:7000 (7) azuredevops-opal_clientA-1 | [2023-02-07 03:59:26 +0000] [7] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_clientA-1 | [2023-02-07 03:59:26 +0000] [16] [INFO] Booting worker with pid: 16 azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.813010+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'FastApiRpcFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.813585+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'HttpFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.813836+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Fetcher Register loaded azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.814120+0000 | 16 | opal_client.callbacks.register | INFO | Callbacks register loaded azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.814446+0000 | 16 | opal_client.client | INFO | API authentication disabled (public encryption key was not provided) azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.862771+0000 | 16 | opal_client.opa.runner | INFO | Launching opa runner azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.863552+0000 | 16 | opal_client.opa.runner | INFO | Running OPA inline: opa run --server --addr=:8181 --authentication=off --authorization=off --log-level=info azuredevops-opal_clientA-1 | 2023-02-07T03:59:26.885048+0000 | 16 | opal_client.opa.logger | INFO | Initializing server. {"addrs": [":8181"], "diagnostic-addrs": [], "time": "2023-02-07T03:59:26Z"} azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.868351+0000 | 16 | opal_client.opa.runner | INFO | Running OPA initial start callbacks azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.868681+0000 | 16 | opal_client.data.updater | INFO | Launching data updater azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.868802+0000 | 16 | opal_client.policy.updater | INFO | Launching policy updater azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.868853+0000 | 16 | opal_client.data.updater | INFO | Subscribing to topics: ['policy_data'] azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.869008+0000 | 16 | opal_client.policy.updater | INFO | Subscribing to topics: ['policy:default', 'policy:services/billing'] azuredevops-opal_server-1 | 2023-02-07T03:59:27.875191+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.869181+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Trying to connect to Pub/Sub server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:59:27.875913+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '1729d8f7948242ddbcc739e31f022c91', 'subscriber_id': '92982df677d5483c9051dc1115999797', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.869463+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:59:27.876489+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.871051+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Trying to connect to Pub/Sub server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:59:27.876565+0000 | 10 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.871234+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:59:27.876867+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T03:59:27.878494+0000 | 9 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T03:59:27.888329+0000 | 10 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '9caebbe8569e497cae10c72cca782dbe', 'subscriber_id': '5705046dd0da46468f8f6c5b76e11922', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:59:27.888620+0000 | 10 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T03:59:27.888928+0000 | 10 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T03:59:27.892741+0000 | 10 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T03:59:27.900030+0000 | 10 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '28aca90dacb545d0984d9599b13b5a26', 'subscriber_id': '07765c9f06f54dd98626e1437d5263bd', 'topic': 'policy:default', 'callback': .callback at 0x7f9eeae6f400>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T03:59:27.900332+0000 | 10 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'df93f6ea51cd48bab4b8bc4cd98b5c4d', 'subscriber_id': '07765c9f06f54dd98626e1437d5263bd', 'topic': 'policy:services/billing', 'callback': .callback at 0x7f9eeae6f400>, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.903835+0000 | 16 | opal_client.policy.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.904069+0000 | 16 | opal_client.policy.updater | INFO | Refetching policy code (full bundle) azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.904316+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T03:59:27.912715+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '563ede66e43949dba9a4558621abffc2', 'subscriber_id': '5bb4234a39e5433a88b0bf2610e42dc0', 'topic': 'policy_data', 'callback': .callback at 0x7f9eeae5ba30>, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.914148+0000 | 16 | opal_client.data.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.914322+0000 | 16 | opal_client.data.updater | INFO | Performing data configuration, reason: Initial load azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.914379+0000 | 16 | opal_client.data.updater | INFO | Getting data-sources configuration from 'http://opal_server:7002/data/config' azuredevops-opal_server-1 | 2023-02-07T03:59:27.916737+0000 | 7 | opal_server.data.api | INFO | Serving source configuration azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.918742+0000 | 16 | opal_client.data.updater | INFO | Triggering data update with id: a9b86176792340f7a3fe30fd45829eff azuredevops-opal_server-1 | 2023-02-07T03:59:27.917219+0000 | 7 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47590 - "GET /data/config HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.918965+0000 | 16 | opal_client.data.updater | INFO | Fetching policy data azuredevops-opal_server-1 | 2023-02-07T03:59:27.917537+0000 | 8 | opal_common.git.bundle_maker | INFO | Using root manifest dir path (new-fashioned): '.' azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.919098+0000 | 16 | opal_client.data.fetcher | INFO | Fetching data from url: http://opal_server:7002/policy-data azuredevops-opal_server-1 | 2023-02-07T03:59:27.917774+0000 | 8 | opal_common.git.bundle_maker | INFO | Compiling manifest file .manifest azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.920039+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T03:59:27.918808+0000 | 8 | opal_common.git.bundle_maker | INFO | Manifest file .manifest not found, assuming empty azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.922825+0000 | 16 | opal_client.data.updater | INFO | Saving fetched data to policy-store: source url='http://opal_server:7002/policy-data', destination path='/static' azuredevops-opal_server-1 | 2023-02-07T03:59:27.921582+0000 | 9 | opal_server.data.api |WARNING | Serving default all-data route, meaning DATA_CONFIG_SOURCES was not configured! azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.924310+0000 | 16 | opal_client.policy.fetcher | INFO | Fetched valid bundle, id: 4fa15196bf50a009711d2fe39a637a0aa2a8a078 azuredevops-opal_server-1 | 2023-02-07T03:59:27.921886+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47592 - "GET /policy-data HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.924702+0000 | 16 | opal_client.policy.updater | INFO | Got policy bundle with 3 rego files, 2 data files, commit hash: '4fa15196bf50a009711d2fe39a637a0aa2a8a078' azuredevops-opal_server-1 | 2023-02-07T03:59:27.922799+0000 | 8 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.4:47588 - "GET /policy?path=default&path=services/billing HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.928446+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/static azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.929230+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/static -> 204 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.929831+0000 | 16 | opal_client.opa.logger | INFO | Received request. GET /v1/policies azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.930005+0000 | 16 | opal_client.opa.logger | INFO | Sent response. GET /v1/policies -> 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.931875+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/default azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.932435+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/default -> 204 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.934081+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/services/billing azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.934760+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/services/billing -> 204 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.936470+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/default/rbac.rego azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.939611+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/default/rbac.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.941669+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/services/billing/rbac.rego azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.946837+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/services/billing/rbac.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.948765+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/services/billing/utils.rego azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.953911+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/services/billing/utils.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T03:59:27.955053+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T03:59:30.359094+0000 | 16 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T03:59:30.361847+0000 | 16 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200 azuredevops-opal_server-1 | 2023-02-07T04:00:04.382033+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.1:33670 - "POST /webhook HTTP/1.1" 401 azuredevops-broadcast_channel-1 | 2023-02-07 04:03:40.962 UTC [48] LOG: checkpoint starting: time azuredevops-broadcast_channel-1 | 2023-02-07 04:03:45.043 UTC [48] LOG: checkpoint complete: wrote 43 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=4.022 s, sync=0.040 s, total=4.082 s; sync files=11, longest=0.031 s, average=0.004 s; distance=252 kB, estimate=252 kB azuredevops-opal_server-1 | 2023-02-07T04:13:28.422940+0000 | 8 | uvicorn.protocols.http.httptools_impl | INFO | 172.28.0.1:39806 - "POST /webhook HTTP/1.1" 401