Skip to content

feat: query and answer logging#200

Merged
gadomski merged 3 commits into
mainfrom
issues/108-logging
Dec 18, 2025
Merged

feat: query and answer logging#200
gadomski merged 3 commits into
mainfrom
issues/108-logging

Conversation

@gadomski

Copy link
Copy Markdown
Collaborator

Closes #108. Includes a custom logging config for uvicorn (thanks Claude!) and hooks it into docker-compose.yaml and Terraform.

Testing locally, we got log messages like this:

api-1       | 2025-12-16 13:08:45 - atlas_assistant.api - INFO - Query: How is maize production projected to change under future climate scenarios in Kenya?
--- >8 ---
api-1       | 2025-12-16 13:09:04 - atlas_assistant.api - INFO - Answer: Maize production in Kenya is projected to change under different climate scenarios. Here's a summary of the projected changes:
api-1       |
api-1       | - **SSP126 Scenario**:
api-1       |   - 2021-2040: USD 6.39 billion
api-1       |   - 2041-2060: USD 6.94 billion
api-1       |   - 2061-2080: USD 7.31 billion
api-1       |   - 2081-2100: USD 7.39 billion
api-1       |
api-1       | - **SSP245 Scenario**:
api-1       |   - 2021-2040: USD 5.26 billion
api-1       |   - 2041-2060: USD 5.11 billion
api-1       |   - 2061-2080: USD 8.16 billion
api-1       |   - 2081-2100: USD 8.19 billion
api-1       |
api-1       | - **SSP370 Scenario**:
api-1       |   - 2021-2040: USD 9.64 billion
api-1       |   - 2041-2060: USD 10.09 billion
api-1       |   - 2061-2080: USD 10.07 billion
api-1       |   - 2081-2100: USD 9.43 billion
api-1       |
api-1       | - **SSP585 Scenario**:
api-1       |   - 2021-2040: USD 5.31 billion
api-1       |   - 2041-2060: USD 5.62 billion
api-1       |   - 2061-2080: USD 5.49 billion
api-1       |   - 2081-2100: USD 6.35 billion
api-1       |
api-1       | The data shows varying impacts on maize production depending on the climate scenario and timeframe. The SSP370 scenario shows the highest exposure values, particularly in the mid-century periods, while the SSP245 scenario shows a significant increase in exposure in the later periods.

This should show up in CloudWatch no problem, and you can do a filter on atlas_assistant.api to get log messages from the API.

My editor did some auto-formatting of the Dockerfile, apologies.

Checklist

  • Pre-commit hooks pass (uv run prek run --all-files)
  • Tests pass (uv run pytest --integration)
  • The PR's title is formatted per Conventional Commits

@github-actions

github-actions Bot commented Dec 16, 2025

Copy link
Copy Markdown

Terraform Format and Style 🖌success

Terraform Initialization ⚙️success

Terraform Validation 🤖success

Terraform Plan 📖success

Terraform Plan

data.aws_route53_zone.ecs_domain: Reading...
data.aws_region.current: Reading...
module.ecr.data.aws_caller_identity.current: Reading...
data.aws_availability_zones.available: Reading...
module.ecr.data.aws_partition.current: Reading...
module.vpc.aws_vpc.this[0]: Refreshing state... [id=vpc-03289f94e18646154]
module.ecr.aws_ecr_repository.this[0]: Refreshing state... [id=atlas]
data.aws_caller_identity.current: Reading...
aws_secretsmanager_secret.backend_secrets: Refreshing state... [id=arn:aws:secretsmanager:us-east-1:757082729759:secret:atlas-backend-P7JPQE]
module.acm.aws_acm_certificate.this[0]: Refreshing state... [id=arn:aws:acm:us-east-1:757082729759:certificate/5f558056-e6e3-4f7a-9685-b06f0e30bc0a]
data.aws_region.current: Read complete after 0s [id=us-east-1]
module.ecr.data.aws_partition.current: Read complete after 0s [id=aws]
module.alb.data.aws_partition.current[0]: Reading...
module.ecs.module.cluster.aws_cloudwatch_log_group.this[0]: Refreshing state... [id=/aws/ecs/atlas-cluster]
module.alb.data.aws_partition.current[0]: Read complete after 0s [id=aws]
aws_cognito_user_pool.atlas_pool: Refreshing state... [id=us-east-1_tnnHCVrfv]
data.aws_caller_identity.current: Read complete after 0s [id=757082729759]
module.ecr.data.aws_caller_identity.current: Read complete after 0s [id=757082729759]
module.ecr.data.aws_iam_policy_document.repository[0]: Reading...
module.ecr.data.aws_iam_policy_document.repository[0]: Read complete after 0s [id=996006171]
data.aws_availability_zones.available: Read complete after 0s [id=us-east-1]
module.ecr.aws_ecr_repository_policy.this[0]: Refreshing state... [id=atlas]
module.ecr.aws_ecr_lifecycle_policy.this[0]: Refreshing state... [id=atlas]
module.ecs.module.cluster.aws_ecs_cluster.this[0]: Refreshing state... [id=arn:aws:ecs:us-east-1:757082729759:cluster/atlas-cluster]
aws_cognito_user_pool_domain.default: Refreshing state... [id=adaptation-atlas]
aws_cognito_user_pool_client.atlas_pool_client: Refreshing state... [id=7mg2hpfgj5qdpui6s6q601qn18]
data.aws_route53_zone.ecs_domain: Read complete after 0s [id=Z07137001EGM5VZYG83X8]
module.acm.aws_route53_record.validation[0]: Refreshing state... [id=Z07137001EGM5VZYG83X8__f5dcc02929533cc50697c7e364e7d847.atlas-assistant.ds.io._CNAME]
aws_secretsmanager_secret_version.backend_secrets: Refreshing state... [id=arn:aws:secretsmanager:us-east-1:757082729759:secret:atlas-backend-P7JPQE|terraform-20251217201710215500000001]
aws_cognito_managed_login_branding.client: Refreshing state...
module.ecs.module.cluster.aws_ecs_cluster_capacity_providers.this[0]: Refreshing state... [id=atlas-cluster]
module.acm.aws_acm_certificate_validation.this[0]: Refreshing state... [id=2025-11-12 01:52:16.236 +0000 UTC]
module.vpc.aws_default_security_group.this[0]: Refreshing state... [id=sg-08051020ab6126f0f]
module.vpc.aws_subnet.public[1]: Refreshing state... [id=subnet-04225e3ac37eb8717]
module.vpc.aws_subnet.public[2]: Refreshing state... [id=subnet-0f243362d7c8bbce0]
module.vpc.aws_default_route_table.default[0]: Refreshing state... [id=rtb-0dcfcded61b9fbc9e]
module.vpc.aws_subnet.public[0]: Refreshing state... [id=subnet-0816c99f59d729149]
module.alb.aws_lb_target_group.this["ecs_tg"]: Refreshing state... [id=arn:aws:elasticloadbalancing:us-east-1:757082729759:targetgroup/tf-20251119050939812400000001/0a68004d0926b7e1]
module.vpc.aws_default_network_acl.this[0]: Refreshing state... [id=acl-0a2558310700565e6]
module.vpc.aws_internet_gateway.this[0]: Refreshing state... [id=igw-02c1aab179c651a5e]
module.alb.aws_security_group.this[0]: Refreshing state... [id=sg-07795e64001b6db0f]
module.vpc.aws_route_table.public[0]: Refreshing state... [id=rtb-0e64bac2aee4ce75b]
module.vpc.aws_subnet.private[0]: Refreshing state... [id=subnet-0ab6e527cf89a9de4]
module.vpc.aws_subnet.private[1]: Refreshing state... [id=subnet-09c3b628017e267cf]
module.vpc.aws_subnet.private[2]: Refreshing state... [id=subnet-0ac9eb4080bd25c0e]
module.vpc.aws_route_table.private[0]: Refreshing state... [id=rtb-0ee28703cd3d25b43]
module.vpc.aws_eip.nat[0]: Refreshing state... [id=eipalloc-01c425311cd3f1196]
module.vpc.aws_route.public_internet_gateway[0]: Refreshing state... [id=r-rtb-0e64bac2aee4ce75b1080289494]
module.alb.aws_vpc_security_group_ingress_rule.this["all_https"]: Refreshing state... [id=sgr-003bc45a8af642617]
module.alb.aws_vpc_security_group_ingress_rule.this["all_http"]: Refreshing state... [id=sgr-0ff162ba4fcef51d5]
module.alb.aws_vpc_security_group_egress_rule.this["all"]: Refreshing state... [id=sgr-07d0fed2c4f085987]
module.vpc.aws_route_table_association.public[1]: Refreshing state... [id=rtbassoc-0ff904d7ad05b62b3]
module.vpc.aws_route_table_association.public[2]: Refreshing state... [id=rtbassoc-04a32bdc90c40388d]
module.vpc.aws_route_table_association.public[0]: Refreshing state... [id=rtbassoc-0a2465ff114318352]
module.alb.aws_lb.this[0]: Refreshing state... [id=arn:aws:elasticloadbalancing:us-east-1:757082729759:loadbalancer/app/atlas-lb/4483a88acd924120]
module.vpc.aws_route_table_association.private[2]: Refreshing state... [id=rtbassoc-050a0e163ca98e4f3]
module.vpc.aws_route_table_association.private[0]: Refreshing state... [id=rtbassoc-04ddbcc18760a8f53]
module.vpc.aws_route_table_association.private[1]: Refreshing state... [id=rtbassoc-0f13cc9d613a9452b]
module.ecs.module.service["atlas-backend"].data.aws_caller_identity.current[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_region.current[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_region.current[0]: Read complete after 0s [id=us-east-1]
module.ecs.module.service["atlas-backend"].data.aws_partition.current[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_partition.current[0]: Read complete after 0s [id=aws]
module.ecs.module.service["atlas-backend"].data.aws_subnet.this[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.task_exec_assume[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.task_exec_assume[0]: Read complete after 0s [id=2291109037]
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.tasks[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.tasks[0]: Read complete after 0s [id=757765849]
module.ecs.module.service["atlas-backend"].module.container_definition["api"].data.aws_region.current: Reading...
module.ecs.module.service["atlas-backend"].module.container_definition["api"].data.aws_region.current: Read complete after 0s [id=us-east-1]
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.task_exec[0]: Reading...
module.ecs.module.service["atlas-backend"].aws_iam_role.task_exec[0]: Refreshing state... [id=atlas-backend-taskexec-20251116234104652600000002]
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.task_exec[0]: Read complete after 0s [id=199952894]
module.ecs.module.service["atlas-backend"].aws_iam_policy.tasks[0]: Refreshing state... [id=arn:aws:iam::757082729759:policy/atlas-backend-tasks-20251116234105401000000004]
module.ecs.module.service["atlas-backend"].aws_iam_policy.task_exec[0]: Refreshing state... [id=arn:aws:iam::757082729759:policy/atlas-backend-taskexec-20251116234104652600000001]
module.ecs.module.service["atlas-backend"].data.aws_caller_identity.current[0]: Read complete after 0s [id=757082729759]
module.ecs.module.service["atlas-backend"].module.container_definition["api"].aws_cloudwatch_log_group.this[0]: Refreshing state... [id=/aws/ecs/atlas-backend/api]
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.tasks_assume[0]: Reading...
module.ecs.module.service["atlas-backend"].data.aws_iam_policy_document.tasks_assume[0]: Read complete after 0s [id=4216913783]
module.ecs.module.service["atlas-backend"].aws_iam_role.tasks[0]: Refreshing state... [id=atlas-backend-tasks-20251116234105073100000003]
module.vpc.aws_nat_gateway.this[0]: Refreshing state... [id=nat-0256afcefe6e79339]
module.ecs.module.service["atlas-backend"].data.aws_subnet.this[0]: Read complete after 0s [id=subnet-0ab6e527cf89a9de4]
module.ecs.module.service["atlas-backend"].aws_security_group.this[0]: Refreshing state... [id=sg-0724bfcc4ba152baf]
module.vpc.aws_route.private_nat_gateway[0]: Refreshing state... [id=r-rtb-0ee28703cd3d25b431080289494]
module.ecs.module.service["atlas-backend"].aws_vpc_security_group_egress_rule.this["all"]: Refreshing state... [id=sgr-07df038ccf9ef8105]
module.ecs.module.service["atlas-backend"].aws_vpc_security_group_ingress_rule.this["ecs_alb"]: Refreshing state... [id=sgr-02bceb7b9f7314e0e]
module.alb.aws_route53_record.this["A"]: Refreshing state... [id=Z07137001EGM5VZYG83X8_api_A]
module.alb.aws_lb_listener.this["ecs-http-https-redirect"]: Refreshing state... [id=arn:aws:elasticloadbalancing:us-east-1:757082729759:listener/app/atlas-lb/4483a88acd924120/826137068bbdafb6]
module.alb.aws_lb_listener.this["ecs-https"]: Refreshing state... [id=arn:aws:elasticloadbalancing:us-east-1:757082729759:listener/app/atlas-lb/4483a88acd924120/22ed82e682205229]
module.ecs.module.service["atlas-backend"].aws_iam_role_policy_attachment.task_exec[0]: Refreshing state... [id=atlas-backend-taskexec-20251116234104652600000002/arn:aws:iam::757082729759:policy/atlas-backend-taskexec-20251116234104652600000001]
module.ecs.module.service["atlas-backend"].aws_iam_role_policy_attachment.tasks_internal[0]: Refreshing state... [id=atlas-backend-tasks-20251116234105073100000003/arn:aws:iam::757082729759:policy/atlas-backend-tasks-20251116234105401000000004]
module.ecs.module.service["atlas-backend"].aws_ecs_task_definition.this[0]: Refreshing state... [id=atlas-backend]
module.ecs.module.service["atlas-backend"].aws_ecs_service.this[0]: Refreshing state... [id=arn:aws:ecs:us-east-1:757082729759:service/atlas-cluster/atlas-backend]
module.ecs.module.service["atlas-backend"].aws_appautoscaling_target.this[0]: Refreshing state... [id=service/atlas-cluster/atlas-backend]
module.ecs.module.service["atlas-backend"].aws_appautoscaling_policy.this["memory"]: Refreshing state... [id=memory]
module.ecs.module.service["atlas-backend"].aws_appautoscaling_policy.this["cpu"]: Refreshing state... [id=cpu]

Terraform used the selected providers to generate the following execution
plan. Resource actions are indicated with the following symbols:
  ~ update in-place
+/- create replacement and then destroy

Terraform will perform the following actions:

  # module.ecs.module.service["atlas-backend"].aws_ecs_service.this[0] will be updated in-place
  ~ resource "aws_ecs_service" "this" {
        id                                 = "arn:aws:ecs:us-east-1:757082729759:service/atlas-cluster/atlas-backend"
        name                               = "atlas-backend"
        tags                               = {
            "client"  = "cgiar"
            "owner"   = "orbaco"
            "project" = "atlas-assistant"
        }
      ~ task_definition                    = "arn:aws:ecs:us-east-1:757082729759:task-definition/atlas-backend:31" -> (known after apply)
        # (19 unchanged attributes hidden)

        # (5 unchanged blocks hidden)
    }

  # module.ecs.module.service["atlas-backend"].aws_ecs_task_definition.this[0] must be replaced
+/- resource "aws_ecs_task_definition" "this" {
      ~ arn                      = "arn:aws:ecs:us-east-1:757082729759:task-definition/atlas-backend:31" -> (known after apply)
      ~ arn_without_revision     = "arn:aws:ecs:us-east-1:757082729759:task-definition/atlas-backend" -> (known after apply)
      ~ container_definitions    = jsonencode(
          ~ [
              ~ {
                  ~ command                = [
                        # (5 unchanged elements hidden)
                        "8000",
                      + "--log-config",
                      + "logging.yaml",
                    ]
                  - environment            = []
                    name                   = "api"
                  ~ portMappings           = [
                      ~ {
                          - hostPort      = 8000
                          - protocol      = "tcp"
                            # (1 unchanged attribute hidden)
                        },
                    ]
                  - systemControls         = []
                  - volumesFrom            = []
                    # (17 unchanged attributes hidden)
                },
            ] # forces replacement
        )
      ~ enable_fault_injection   = false -> (known after apply)
      ~ id                       = "atlas-backend" -> (known after apply)
      ~ revision                 = 31 -> (known after apply)
        tags                     = {
            "client"  = "cgiar"
            "owner"   = "orbaco"
            "project" = "atlas-assistant"
        }
        # (13 unchanged attributes hidden)

        # (1 unchanged block hidden)
    }

Plan: 1 to add, 1 to change, 1 to destroy.

Pusher: @aliziel, Action: pull_request, Working Directory: /terraform/aws, Workflow: Terraform Workflow

@aliziel aliziel left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll double check the ECS logs after deploy to make sure the AWS drivers are compatible with the Uvicorn/Fast setup.

Not a blocker, but would it be easy and safe to also include the streamed response messages that are accessible to the client ? I realize size may be a concern, but those XResponseMessages that get printed in devtools could be valuable information to retain serverside with the current query/answer change

@gadomski

Copy link
Copy Markdown
Collaborator Author

Not a blocker, but would it be easy and safe to also include the streamed response messages that are accessible to the client ? I realize size may be a concern, but those XResponseMessages that get printed in devtools could be valuable information to retain serverside with the current query/answer change

Yeah, I chose to just to the query and the answer to avoid spamming the logs. We could add it, but I think i'd be worried about creating too much noise.

@gadomski
gadomski merged commit 46cacb1 into main Dec 18, 2025
4 checks passed
@gadomski
gadomski deleted the issues/108-logging branch December 18, 2025 21:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Log requests and responses

2 participants