[+] Running 3/3 - Container azuredevops-broadcast_channel-1 Created 0.0s - Container azuredevops-opal_server-1 Recreated 0.1s - Container azuredevops-opal_clientA-1 Recreated 0.1s Attaching to azuredevops-broadcast_channel-1, azuredevops-opal_clientA-1, azuredevops-opal_server-1 azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | PostgreSQL Database directory appears to contain a database; Skipping initialization azuredevops-broadcast_channel-1 | azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.677 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 13:00:21.677 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432 azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.677 UTC [1] LOG: listening on IPv6 address "::", port 5432 azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.683 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.691 UTC [24] LOG: database system was interrupted; last known up at 2023-02-07 13:00:11 UTC azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.893 UTC [24] LOG: database system was not properly shut down; automatic recovery in progress azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.896 UTC [24] LOG: redo starts at 0/15406C8 azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.896 UTC [24] LOG: invalid record length at 0/15407B0: wanted 24, got 0 azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.896 UTC [24] LOG: redo done at 0/1540778 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.902 UTC [22] LOG: checkpoint starting: end-of-recovery immediate wait azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.913 UTC [22] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.002 s, total=0.013 s; sync files=2, longest=0.001 s, average=0.001 s; distance=0 kB, estimate=0 kB azuredevops-broadcast_channel-1 | 2023-02-07 13:00:21.916 UTC [1] LOG: database system is ready to accept connections azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [1] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [1] [INFO] Listening at: http://0.0.0.0:7002 (1) azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [1] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [7] [INFO] Booting worker with pid: 7 azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [8] [INFO] Booting worker with pid: 8 azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [9] [INFO] Booting worker with pid: 9 azuredevops-opal_server-1 | [2023-02-07 13:00:22 +0000] [12] [INFO] Booting worker with pid: 12 azuredevops-opal_server-1 | 2023-02-07T13:00:22.819853+0000 | 7 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T13:00:22.820273+0000 | 7 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T13:00:22.907767+0000 | 7 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T13:00:22.908115+0000 | 7 | opal_server.server | INFO | leadership lock acquired, leader pid: 7 azuredevops-opal_server-1 | 2023-02-07T13:00:22.908242+0000 | 7 | opal_server.server | INFO | listening on webhook topic: 'webhook' azuredevops-opal_server-1 | 2023-02-07T13:00:22.908737+0000 | 7 | opal_server.server | INFO | Policy repo will be cloned to: /opal/regoclone/opal_repo_clone azuredevops-opal_server-1 | 2023-02-07T13:00:22.909279+0000 | 7 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '4db30ade06104688b18cc2b093c0e6d2', 'subscriber_id': '9a3802b897b24651b557bc40e139bb3e', 'topic': 'webhook', 'callback': functools.partial(, ), 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:00:22.909458+0000 | 7 | opal_server.policy.watcher.task | INFO | Launching policy watcher azuredevops-opal_server-1 | 2023-02-07T13:00:22.909618+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-07T13:00:22.910224+0000 | 7 | opal_server.data.data_update_publisher | INFO | [7] Starting Polling Updates azuredevops-opal_server-1 | 2023-02-07T13:00:22.912464+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-07T13:00:22.916394+0000 | 8 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T13:00:22.916815+0000 | 8 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_clientA-1 | [2023-02-07 13:00:22 +0000] [7] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_clientA-1 | [2023-02-07 13:00:22 +0000] [7] [INFO] Listening at: http://0.0.0.0:7000 (7) azuredevops-opal_clientA-1 | [2023-02-07 13:00:22 +0000] [7] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_clientA-1 | [2023-02-07 13:00:22 +0000] [16] [INFO] Booting worker with pid: 16 azuredevops-opal_server-1 | 2023-02-07T13:00:22.978765+0000 | 8 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T13:00:23.021946+0000 | 12 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T13:00:23.022247+0000 | 12 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T13:00:23.023183+0000 | 9 | opal_server.server | INFO | OPAL was not provided with JWT encryption keys, cannot verify api requests! azuredevops-opal_server-1 | 2023-02-07T13:00:23.023495+0000 | 9 | opal_server.pubsub | INFO | Initializing broadcaster for server<->server communication azuredevops-opal_server-1 | 2023-02-07T13:00:23.067673+0000 | 12 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_server-1 | 2023-02-07T13:00:23.070024+0000 | 9 | opal_server.server | INFO | *** OPAL Server Startup *** azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.172470+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'FastApiRpcFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.172694+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'HttpFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.172765+0000 | 16 | opal_common.fetcher.fetcher_register | INFO | Fetcher Register loaded azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.172960+0000 | 16 | opal_client.callbacks.register | INFO | Callbacks register loaded azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.173174+0000 | 16 | opal_client.client | INFO | API authentication disabled (public encryption key was not provided) azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.200826+0000 | 16 | opal_client.opa.runner | INFO | Launching opa runner azuredevops-opal_clientA-1 | 2023-02-07T13:00:23.201405+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-07T13:00:23.215804+0000 | 16 | opal_client.opa.logger | INFO | Initializing server. {"addrs": [":8181"], "diagnostic-addrs": [], "time": "2023-02-07T13:00:23Z"} azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.204646+0000 | 16 | opal_client.opa.runner | INFO | Running OPA initial start callbacks azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.205029+0000 | 16 | opal_client.data.updater | INFO | Launching data updater azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.205155+0000 | 16 | opal_client.policy.updater | INFO | Launching policy updater azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.205221+0000 | 16 | opal_client.data.updater | INFO | Subscribing to topics: ['policy_data'] azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.205364+0000 | 16 | opal_client.policy.updater | INFO | Subscribing to topics: ['policy:default', 'policy:services/billing'] azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.205535+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-07T13:00:24.205770+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.208025+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-07T13:00:24.208214+0000 | 16 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T13:00:24.216051+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_server-1 | 2023-02-07T13:00:24.216079+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_server-1 | 2023-02-07T13:00:24.227741+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '93a7ab41ed994ef39d0d37af5c81df66', 'subscriber_id': '076590c0f4b64443ae9df6aaf00fea49', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:00:24.227750+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'e48536dedd9a4aacb3accd6e5553e2b2', 'subscriber_id': 'e3e6209c5638473ea2da216142795841', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:00:24.228177+0000 | 8 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T13:00:24.228177+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T13:00:24.228417+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T13:00:24.228418+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T13:00:24.230973+0000 | 9 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T13:00:24.231092+0000 | 8 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T13:00:24.261211+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'dbe9159840484e16838c11a82d222ced', 'subscriber_id': 'b18b9091d93a47839f879c32a378ab13', 'topic': 'policy:services/billing', 'callback': .callback at 0x7f15fb13f400>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:00:24.261467+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '560c18a4d5ca42cdab7337a68b88c510', 'subscriber_id': 'b18b9091d93a47839f879c32a378ab13', 'topic': 'policy:default', 'callback': .callback at 0x7f15fb13f400>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:00:24.262299+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '2b72b34f6a314e7e9345516e6131603f', 'subscriber_id': '7a76e85ca2364810a95230e558dd2fa4', 'topic': 'policy_data', 'callback': .callback at 0x7f15fb13b400>, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.264519+0000 | 16 | opal_client.policy.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.264904+0000 | 16 | opal_client.policy.updater | INFO | Refetching policy code (full bundle) azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.265409+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.267131+0000 | 16 | opal_client.data.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.267268+0000 | 16 | opal_client.data.updater | INFO | Performing data configuration, reason: Initial load azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.267312+0000 | 16 | opal_client.data.updater | INFO | Getting data-sources configuration from 'http://opal_server:7002/data/config' azuredevops-opal_server-1 | 2023-02-07T13:00:24.270655+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45050 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.271372+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_server-1 | 2023-02-07T13:00:24.273226+0000 | 12 | opal_server.data.api | INFO | Serving source configuration azuredevops-opal_server-1 | 2023-02-07T13:00:24.273677+0000 | 12 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45052 - "GET /data/config HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.274369+0000 | 16 | opal_client.data.updater | INFO | Triggering data update with id: 532ef80bcbd94052ad691d7389b608ab azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.274501+0000 | 16 | opal_client.data.updater | INFO | Fetching policy data azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.274582+0000 | 16 | opal_client.data.fetcher | INFO | Fetching data from url: http://opal_server:7002/policy-data azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.275302+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T13:00:24.276639+0000 | 9 | opal_server.data.api |WARNING | Serving default all-data route, meaning DATA_CONFIG_SOURCES was not configured! azuredevops-opal_server-1 | 2023-02-07T13:00:24.276973+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45054 - "GET /policy-data HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.277745+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-07T13:00:24.279365+0000 | 16 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/static azuredevops-opal_clientA-1 | 2023-02-07T13:00:24.280027+0000 | 16 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/static -> 204 azuredevops-opal_clientA-1 | 2023-02-07T13:00:25.235106+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T13:00:25.239108+0000 | 12 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45064 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T13:00:25.239750+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T13:00:25.736380+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T13:00:25.742695+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45066 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T13:00:25.743810+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T13:00:26.260286+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T13:00:26.263722+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45074 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T13:00:26.264315+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T13:00:33.685804+0000 | 16 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_server-1 | 2023-02-07T13:00:33.690077+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45134 - "GET /policy?path=default&path=services/billing HTTP/1.1" 503 azuredevops-opal_clientA-1 | 2023-02-07T13:00:33.690582+0000 | 16 | opal_common.utils |WARNING | Unexpected response code 503: {'detail': 'policy repo is not ready'} azuredevops-opal_clientA-1 | 2023-02-07T13:00:33.690829+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-07T13:00:33.690999+0000 | 16 | opal_client...base_policy_store_client |ERROR | OPA transaction failed, transaction id=c05b84727ffc4db283df6ae100dd933b, actions=[], error=ValueError('unexpected response code while fetching bundle: 503') azuredevops-opal_clientA-1 | 2023-02-07T13:00:33.691234+0000 | 16 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T13:00:41.580773+0000 | 7 | opal_common.git.repo_cloner | INFO | Clone succeeded azuredevops-opal_server-1 | 2023-02-07T13:00:41.584873+0000 | 7 | opal_common.sources.base_policy_source | INFO | Polling task is off azuredevops-opal_server-1 | 2023-02-07T13:01:23.795046+0000 | 8 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client disconnected - 45044 :: b18b9091d93a47839f879c32a378ab13 azuredevops-opal_server-1 | 2023-02-07T13:01:23.796108+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy:services/billing' for subscriber=b18b9091d93a47839f879c32a378ab13 azuredevops-opal_server-1 | 2023-02-07T13:01:23.795953+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client disconnected - 45042 :: 7a76e85ca2364810a95230e558dd2fa4 azuredevops-opal_server-1 | 2023-02-07T13:01:23.796681+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy:default' for subscriber=b18b9091d93a47839f879c32a378ab13 azuredevops-opal_server-1 | 2023-02-07T13:01:23.797267+0000 | 8 | fastapi_websocket_pubsub.event_broadc...| INFO | Cancelling broadcast listen task azuredevops-opal_server-1 | 2023-02-07T13:01:23.797839+0000 | 8 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='__EventNotifier_ALL_TOPICS__' for subscriber=e3e6209c5638473ea2da216142795841 azuredevops-opal_server-1 | 2023-02-07T13:01:23.797603+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='policy_data' for subscriber=7a76e85ca2364810a95230e558dd2fa4 azuredevops-opal_server-1 | 2023-02-07T13:01:23.798696+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Cancelling broadcast listen task azuredevops-opal_server-1 | 2023-02-07T13:01:23.799172+0000 | 8 | websockets.legacy.server | INFO | connection closed azuredevops-opal_server-1 | 2023-02-07T13:01:23.799850+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | Removing Subscription of topic='__EventNotifier_ALL_TOPICS__' for subscriber=076590c0f4b64443ae9df6aaf00fea49 azuredevops-opal_server-1 | 2023-02-07T13:01:23.802346+0000 | 9 | 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 13:01:25 +0000] [8] [INFO] Starting gunicorn 20.1.0 azuredevops-opal_clientA-1 | [2023-02-07 13:01:25 +0000] [8] [INFO] Listening at: http://0.0.0.0:7000 (8) azuredevops-opal_clientA-1 | [2023-02-07 13:01:25 +0000] [8] [INFO] Using worker: uvicorn.workers.UvicornWorker azuredevops-opal_clientA-1 | [2023-02-07 13:01:25 +0000] [17] [INFO] Booting worker with pid: 17 azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.431110+0000 | 17 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'FastApiRpcFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.431384+0000 | 17 | opal_common.fetcher.fetcher_register | INFO | Loading FetcherProvider 'HttpFetchProvider' found at: azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.431469+0000 | 17 | opal_common.fetcher.fetcher_register | INFO | Fetcher Register loaded azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.431665+0000 | 17 | opal_client.callbacks.register | INFO | Callbacks register loaded azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.431918+0000 | 17 | opal_client.client | INFO | API authentication disabled (public encryption key was not provided) azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.459253+0000 | 17 | opal_client.opa.runner | INFO | Launching opa runner azuredevops-opal_clientA-1 | 2023-02-07T13:01:25.460005+0000 | 17 | 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-07T13:01:25.474023+0000 | 17 | opal_client.opa.logger | INFO | Initializing server. {"addrs": [":8181"], "diagnostic-addrs": [], "time": "2023-02-07T13:01:25Z"} azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.463748+0000 | 17 | opal_client.opa.runner | INFO | Running OPA initial start callbacks azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.464452+0000 | 17 | opal_client.data.updater | INFO | Launching data updater azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.464643+0000 | 17 | opal_client.policy.updater | INFO | Launching policy updater azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.464712+0000 | 17 | opal_client.data.updater | INFO | Subscribing to topics: ['policy_data'] azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.464854+0000 | 17 | opal_client.policy.updater | INFO | Subscribing to topics: ['policy:default', 'policy:services/billing'] azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.465071+0000 | 17 | 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-07T13:01:26.465334+0000 | 17 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.467040+0000 | 17 | 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-07T13:01:26.467360+0000 | 17 | fastapi_websocket_rpc.websocket_rpc_c...| INFO | Trying server - ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T13:01:26.473830+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Listening for incoming events from broadcast channel (first listener started) azuredevops-opal_server-1 | 2023-02-07T13:01:26.474303+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': '1a3e7447b8aa43e6ac8086c36d991e33', 'subscriber_id': '076590c0f4b64443ae9df6aaf00fea49', 'topic': '__EventNotifier_ALL_TOPICS__', 'callback': >, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:01:26.474728+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T13:01:26.475021+0000 | 9 | fastapi_websocket_pubsub.event_broadc...| INFO | Starting broadcaster listener azuredevops-opal_server-1 | 2023-02-07T13:01:26.475932+0000 | 9 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T13:01:26.476467+0000 | 9 | fastapi_websocket_rpc.websocket_rpc_e...| INFO | Client connected azuredevops-opal_server-1 | 2023-02-07T13:01:26.477010+0000 | 9 | websockets.legacy.server | INFO | connection open azuredevops-opal_server-1 | 2023-02-07T13:01:26.510327+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'cbda7cfcb08f49bd93cca48f8fc5c744', 'subscriber_id': 'a5e548b305fd47728832730438af818d', 'topic': 'policy:default', 'callback': .callback at 0x7f15fb13b490>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:01:26.510659+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'b3d9a9db16bf4eef969d7d9448710341', 'subscriber_id': 'a5e548b305fd47728832730438af818d', 'topic': 'policy:services/billing', 'callback': .callback at 0x7f15fb13b490>, 'notifier_id': None} azuredevops-opal_server-1 | 2023-02-07T13:01:26.511617+0000 | 9 | fastapi_websocket_pubsub.event_notifier | INFO | New subscription {'id': 'a45873c7c8054d89957376fa037504fc', 'subscriber_id': '1de9d8b0198246d88538898807175a91', 'topic': 'policy_data', 'callback': .callback at 0x7f15fb13ba30>, 'notifier_id': None} azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.511917+0000 | 17 | opal_client.policy.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.512427+0000 | 17 | opal_client.policy.updater | INFO | Refetching policy code (full bundle) azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.512866+0000 | 17 | opal_client.policy.fetcher | INFO | Fetching policy bundle from http://opal_server:7002/policy azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.514377+0000 | 17 | opal_client.data.updater | INFO | Connected to server azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.514473+0000 | 17 | opal_client.data.updater | INFO | Performing data configuration, reason: Initial load azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.514512+0000 | 17 | opal_client.data.updater | INFO | Getting data-sources configuration from 'http://opal_server:7002/data/config' azuredevops-opal_server-1 | 2023-02-07T13:01:26.516450+0000 | 12 | opal_server.data.api | INFO | Serving source configuration azuredevops-opal_server-1 | 2023-02-07T13:01:26.517052+0000 | 12 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45550 - "GET /data/config HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.518381+0000 | 17 | opal_client.data.updater | INFO | Triggering data update with id: 0df1346b2771414bbc7639d88c731f7e azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.518543+0000 | 17 | opal_client.data.updater | INFO | Fetching policy data azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.518656+0000 | 17 | opal_client.data.fetcher | INFO | Fetching data from url: http://opal_server:7002/policy-data azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.519520+0000 | 17 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_server-1 | 2023-02-07T13:01:26.520818+0000 | 12 | opal_server.data.api |WARNING | Serving default all-data route, meaning DATA_CONFIG_SOURCES was not configured! azuredevops-opal_server-1 | 2023-02-07T13:01:26.521124+0000 | 12 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45552 - "GET /policy-data HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.522204+0000 | 17 | 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-07T13:01:26.523105+0000 | 9 | opal_common.git.bundle_maker | INFO | Using root manifest dir path (new-fashioned): '.' azuredevops-opal_server-1 | 2023-02-07T13:01:26.523232+0000 | 9 | opal_common.git.bundle_maker | INFO | Compiling manifest file .manifest azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.523928+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/static azuredevops-opal_server-1 | 2023-02-07T13:01:26.524436+0000 | 9 | opal_common.git.bundle_maker | INFO | Manifest file .manifest not found, assuming empty azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.525080+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/static -> 204 azuredevops-opal_server-1 | 2023-02-07T13:01:26.527958+0000 | 9 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.4:45548 - "GET /policy?path=default&path=services/billing HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.529524+0000 | 17 | opal_client.policy.fetcher | INFO | Fetched valid bundle, id: 91d8d637464385411ad7744dd1811a50e8ed95c0 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.530065+0000 | 17 | opal_client.policy.updater | INFO | Got policy bundle with 3 rego files, 2 data files, commit hash: '91d8d637464385411ad7744dd1811a50e8ed95c0' azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.531784+0000 | 17 | opal_client.opa.logger | INFO | Received request. GET /v1/policies azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.532525+0000 | 17 | opal_client.opa.logger | INFO | Sent response. GET /v1/policies -> 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.534309+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/default azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.534939+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/default -> 204 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.536728+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/data/services/billing azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.537371+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/data/services/billing -> 204 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.538952+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/default/rbac.rego azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.542608+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/default/rbac.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.546709+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/services/billing/rbac.rego azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.553539+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/services/billing/rbac.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.556079+0000 | 17 | opal_client.opa.logger | INFO | Received request. PUT /v1/policies/services/billing/utils.rego azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.568573+0000 | 17 | opal_client.opa.logger | INFO | Sent response. PUT /v1/policies/services/billing/utils.rego -> 200 azuredevops-opal_clientA-1 | 2023-02-07T13:01:26.569468+0000 | 17 | fastapi_websocket_pubsub.pub_sub_client | INFO | Connected to PubSub server ws://opal_server:7002/ws azuredevops-opal_clientA-1 | 2023-02-07T13:01:27.826340+0000 | 17 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T13:01:27.827248+0000 | 17 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200 azuredevops-opal_server-1 | 2023-02-07T13:01:49.013870+0000 | 12 | opal_server.policy.webhook.api |WARNING | Got an unexpected webhook not matching the tracked repo (git@ssh.dev.azure.com:v3/Alegeus-Technologies/ArchitectureCouncil/OPAL-Policy-Repo) - with these URLS: ['https://dev.azure.com/Alegeus-Technologies/ArchitectureCouncil/_git/OPAL-Policy-Repo'] and those names: []. azuredevops-opal_server-1 | 2023-02-07T13:01:49.014398+0000 | 12 | uvicorn.protocols.http.httptools_impl | INFO | 192.168.48.1:35268 - "POST /webhook HTTP/1.1" 200 azuredevops-opal_clientA-1 | 2023-02-07T13:02:02.667603+0000 | 17 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T13:02:02.668263+0000 | 17 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200 azuredevops-opal_clientA-1 | 2023-02-07T13:02:03.378398+0000 | 17 | opal_client.opa.logger | INFO | Received request. GET /v1/data azuredevops-opal_clientA-1 | 2023-02-07T13:02:03.378782+0000 | 17 | opal_client.opa.logger | INFO | Sent response. GET /v1/data -> 200