cf push app errors in v0.15.0/v0.15.1

[vkazmin1]

Description

After upgrading from v0.14.0 to v0.15.0/v0.15.1, the CFApp controller is experiencing silent reconciliation failures. The application builds appear to complete successfully in kpack, but the CFApp controller encounters errors during reconciliation.

Environment

• Korifi Version: v0.15.0 (also reproduced in v0.15.1)
• Kubernetes Version: 1.31
• kpack Version: v0.16.1
• Platform: AWS EKS

Expected Behavior

• Application builds should complete and deploy successfully as they do in v0.14.0

Actual Behavior

The CFApp controller logs show repeated errors, but not related to cf push:

$v % cf push php14

Pushing app php14 to org test / space test as cf-admin...
Packaging files to upload...
Uploading files...
 11.90 KiB / 11.90 KiB [======================================================================================================================================] 100.00% 2s

Waiting for API to complete processing files...

Staging app and tracing logs...

cf push php14 -v :

RESPONSE: [2025-04-16T09:35:59+02:00]
HTTP/1.1 200 OK
Date: Wed, 16 Apr 2025 07:35:59 GMT
Content-Length: 27
Content-Type: application/json
X-Correlation-Id: ddf30124-fe3d-43d2-b9aa-04030b781af2


REQUEST: [2025-04-16T09:35:59+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: <domain>


REQUEST: [2025-04-16T09:36:00+02:00]
GET /v3/builds/4ebf9d5b-e4db-42c9-96b4-59736aa079da HTTP/1.1
Host: <domain>
Accept: application/json
Authorization: [PRIVATE DATA HIDDEN]
Content-Type: application/json
User-Agent: cf/8.9.0+c23186c.2024-12-02 (go1.23.1; arm64 darwin)
[application/json Content Hidden]

RESPONSE: [2025-04-16T09:36:00+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: d46211b6-771d-4342-a46e-32eeb15f3674
Date: Wed, 16 Apr 2025 07:36:00 GMT
Content-Length: 27


RESPONSE: [2025-04-16T09:36:00+02:00]
HTTP/1.1 200 OK
Content-Length: 960
Content-Type: application/json
Date: Wed, 16 Apr 2025 07:36:00 GMT
X-Correlation-Id: f205a225-9bd2-464f-a3c7-351b7eb7fa6a
{
  "created_at": "2025-04-16T07:35:56Z",
  "created_by": {},
  "droplet": null,
  "error": null,
  "guid": "4ebf9d5b-e4db-42c9-96b4-59736aa079da",
  "lifecycle": {
    "data": {
      "buildpacks": []
    },
    "type": "buildpack"
  },
  "links": {
    "app": {
      "href": "https://api.domain/v3/apps/aa432a51-d21c-465c-9baf-39883e06f6b5"
    },
    "self": {
      "href": "https://api.domain/v3/builds/4ebf9d5b-e4db-42c9-96b4-59736aa079da"
    }
  },
  "metadata": {
    "annotations": {
      "korifi.cloudfoundry.org/creation-version": "v0.15.0"
    },
    "labels": {
      "korifi.cloudfoundry.org/app-guid": "aa432a51-d21c-465c-9baf-39883e06f6b5",
      "korifi.cloudfoundry.org/package-guid": "42999b4c-1c17-4595-9589-78569e80d940",
      "korifi.cloudfoundry.org/space-guid": "cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf"
    }
  },
  "package": {
    "guid": "42999b4c-1c17-4595-9589-78569e80d940"
  },
  "relationships": {
    "app": {
      "data": {
        "guid": "aa432a51-d21c-465c-9baf-39883e06f6b5"
      }
    }
  },
  "staging_disk_in_mb": 0,
  "staging_memory_in_mb": 0,
  "state": "STAGING",
  "updated_at": "2025-04-16T07:35:57Z"
}


REQUEST: [2025-04-16T09:36:00+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:00+02:00]
HTTP/1.1 200 OK
Date: Wed, 16 Apr 2025 07:36:00 GMT
Content-Length: 27
Content-Type: application/json
X-Correlation-Id: 05d2c42a-ea67-48fa-8787-85498ece360b


REQUEST: [2025-04-16T09:36:00+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:00+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: 854609df-9173-40c9-b170-702dfb92b2a3
Date: Wed, 16 Apr 2025 07:36:00 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:00+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:01+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: a7af281c-2b47-4e5b-bd76-21cf6c44bf41
Date: Wed, 16 Apr 2025 07:36:01 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:01+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:01+02:00]
HTTP/1.1 200 OK
Content-Length: 27
Content-Type: application/json
X-Correlation-Id: 79b9d28a-e539-43e8-ad11-dfc106635f8e
Date: Wed, 16 Apr 2025 07:36:01 GMT


REQUEST: [2025-04-16T09:36:01+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:01+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: b3b6ba8a-67c6-4982-a0f5-978d2f71b824
Date: Wed, 16 Apr 2025 07:36:01 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:01+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:02+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: b7da78c0-359c-483d-8abc-566d753d8c27
Date: Wed, 16 Apr 2025 07:36:02 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:02+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:02+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: 2a2efd8f-1a8e-438e-919a-86b6dddab98c
Date: Wed, 16 Apr 2025 07:36:02 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:02+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain


RESPONSE: [2025-04-16T09:36:02+02:00]
HTTP/1.1 200 OK
Content-Type: application/json
X-Correlation-Id: ea049300-4217-4170-9cd0-21e5f01b7c25
Date: Wed, 16 Apr 2025 07:36:02 GMT
Content-Length: 27


REQUEST: [2025-04-16T09:36:02+02:00]
GET /api/v1/read/aa432a51-d21c-465c-9baf-39883e06f6b5?descending=true&limit=1&start_time=-6795364578871345152 HTTP/1.1
Host: domain

RESPONSE: [2025-04-16T09:36:02+02:00]
HTTP/1.1 200 OK
X-Correlation-Id: 47419605-cd86-4502-ae19-cd717531658d
Date: Wed, 16 Apr 2025 07:36:02 GMT
Content-Length: 27
Content-Type: application/json


REQUEST: [2025-04-16T09:36:03+02:00]
GET /v3/builds/4ebf9d5b-e4db-42c9-96b4-59736aa079da HTTP/1.1
Host: domain
Accept: application/json
Authorization: [PRIVATE DATA HIDDEN]
Content-Type: application/json
User-Agent: cf/8.9.0+c23186c.2024-12-02 (go1.23.1; arm64 darwin)
[application/json Content Hidden]

kubectl logs -n korifi deployment/korifi-controllers-controller-manager --all-containers --tail=10 |jq :

{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.277313486Z",
  "logger": "controllers.CFOrg.finalize",
  "caller": "k8sns/ns_finalizer.go:70",
  "message": "requeuing waiting for namespace deletion",
  "namespace": "cf",
  "name": "e05cd1c9-ada5-4d01-b7f5-841fbf1a9540",
  "logID": "9aa077cd-bd27-4767-b53c-4e064feb0089"
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.308650092Z",
  "logger": "controllers.CFBuild",
  "caller": "build/controller.go:74",
  "message": "set observed generation",
  "namespace": "cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf",
  "name": "97052fc3-a02f-4af0-9122-4d7eaed326e7",
  "logID": "b7a3cd6d-16f7-4dcb-8e09-ea56902194e9",
  "generation": 1
}
{
  "severity": "INFO",
  "timestamp": "2025-04-16T07:33:51.308791857Z",
  "logger": "controllers.CFBuild.BuildCleaner",
  "caller": "cleanup/build_cleaner.go:45",
  "message": "processing builds",
  "namespace": "cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf",
  "name": "97052fc3-a02f-4af0-9122-4d7eaed326e7",
  "logID": "b7a3cd6d-16f7-4dcb-8e09-ea56902194e9",
  "app": {
    "name": "6a24ebf8-d6c7-4784-87bf-6b8951ec1783",
    "namespace": "cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf"
  },
  "count": 2
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.343400785Z",
  "logger": "controllers.CFOrg",
  "caller": "k8sns/reconciler.go:77",
  "message": "set observed generation",
  "namespace": "cf",
  "name": "1364e609-8ed7-4451-a761-915a1b16a362",
  "logID": "7b18590a-67b5-47ba-90b0-6220c5786d35",
  "generation": 2
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.347475208Z",
  "logger": "controllers.CFOrg.finalize",
  "caller": "k8sns/ns_finalizer.go:70",
  "message": "requeuing waiting for namespace deletion",
  "namespace": "cf",
  "name": "1364e609-8ed7-4451-a761-915a1b16a362",
  "logID": "7b18590a-67b5-47ba-90b0-6220c5786d35"
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.353753161Z",
  "logger": "controllers.CFSpace",
  "caller": "k8sns/reconciler.go:77",
  "message": "set observed generation",
  "namespace": "cf-org-2e64e882-8c1b-4b15-b9c9-f33934776b8b",
  "name": "cf-space-cb62b86f-f6a1-41c1-8dc4-f6ad3fd05888",
  "logID": "8cd45079-9e94-4794-9ccd-4e82e85451d9",
  "generation": 2
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.353814714Z",
  "logger": "controllers.CFSpace.finalize-contained-apps",
  "caller": "k8sns/space_apps_finalizer.go:37",
  "message": "finalizing contained apps",
  "namespace": "cf-org-2e64e882-8c1b-4b15-b9c9-f33934776b8b",
  "name": "cf-space-cb62b86f-f6a1-41c1-8dc4-f6ad3fd05888",
  "logID": "8cd45079-9e94-4794-9ccd-4e82e85451d9",
  "duration": 1723616.353813304
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.353859616Z",
  "logger": "controllers.CFSpace.finalize-contained-apps",
  "caller": "k8sns/space_apps_finalizer.go:52",
  "message": "namespace found",
  "namespace": "cf-org-2e64e882-8c1b-4b15-b9c9-f33934776b8b",
  "name": "cf-space-cb62b86f-f6a1-41c1-8dc4-f6ad3fd05888",
  "logID": "8cd45079-9e94-4794-9ccd-4e82e85451d9"
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.353874456Z",
  "logger": "controllers.CFSpace.finalize-contained-apps",
  "caller": "k8sns/space_apps_finalizer.go:55",
  "message": "namespace already being deleted",
  "namespace": "cf-org-2e64e882-8c1b-4b15-b9c9-f33934776b8b",
  "name": "cf-space-cb62b86f-f6a1-41c1-8dc4-f6ad3fd05888",
  "logID": "8cd45079-9e94-4794-9ccd-4e82e85451d9"
}
{
  "severity": "DEBUG",
  "timestamp": "2025-04-16T07:33:51.359098151Z",
  "logger": "controllers.CFSpace.finalize",
  "caller": "k8sns/ns_finalizer.go:70",
  "message": "requeuing waiting for namespace deletion",
  "namespace": "cf-org-2e64e882-8c1b-4b15-b9c9-f33934776b8b",
  "name": "cf-space-cb62b86f-f6a1-41c1-8dc4-f6ad3fd05888",
  "logID": "8cd45079-9e94-4794-9ccd-4e82e85451d9"
}

Resources:

apiVersion: kpack.io/v1alpha2
kind: ClusterStore
metadata:
  name: primary-cluster-store
spec:
  sources:
  - image: paketobuildpacks/dotnet-core:1.6.1
  - image: paketobuildpacks/go:4.15.2
  - image: paketobuildpacks/java-native-image:11.9.0
  - image: paketobuildpacks/java:18.5.0
  - image: paketobuildpacks/nodejs:7.6.1
  - image: paketobuildpacks/php:2.19.9
  - image: paketobuildpacks/procfile:5.11.0
  - image: paketobuildpacks/python:2.25.2
  - image: paketobuildpacks/ruby:0.47.6
  - image: paketobuildpacks/web-servers:1.4.1
---
apiVersion: kpack.io/v1alpha2
kind: ClusterStack
metadata:
  name: primary-jammy-stack
spec:
  id: "io.buildpacks.stacks.jammy"
  buildImage:
    image: "paketobuildpacks/build-jammy-full"
  runImage:
    image: "paketobuildpacks/run-jammy-full"
---
apiVersion: kpack.io/v1alpha2
kind: ClusterBuilder
metadata:
  name: primary-cluster-builder
spec:
  order:
  - group:
    - id: paketo-buildpacks/nodejs
  - group:
    - id: paketo-buildpacks/dotnet-core
  - group:
    - id: paketo-buildpacks/go
  - group:
    - id: paketo-buildpacks/python
  - group:
    - id: paketo-buildpacks/php
  - group:
    - id: paketo-buildpacks/web-servers
  - group:
    - id: paketo-buildpacks/java-native-image
  - group:
    - id: paketo-buildpacks/java
  - group:
    - id: paketo-buildpacks/ruby
  - group:
    - id: paketo-buildpacks/procfile
  serviceAccountRef:
    name: controller
    namespace: kpack
  stack:
    kind: ClusterStack
    name: primary-jammy-stack
  store:
    kind: ClusterStore
    name: primary-cluster-store
  tag: <address>

Steps to Reproduce

1. Deploy Korifi v0.14.0 - applications build and deploy successfully
2. Upgrade to v0.15.0
3. Push a new application using cf push <app-name>

Additional Context

• The issue affects multiple applications/builds
• The kpack builds themselves appear to complete successfully
• No error message is being propagated (empty error field)
• Rolling back to v0.14.0 resolves the issue

Workaround

Currently using v0.14.0 as a workaround until this is resolved.

Questions

1. Is there a known issue with cf push?
2. Are there any additional logs or debugging steps that would be helpful?

[danail-branekov]

Hi @vkazmin1

With Korifi 0.15 we have introduced the option of using a custom logcache implementation. If such a custom implementation is not specified via the experimental.externalLogCache.enabled helm vallue, then korifi would loopback to localhost. I wonder whether that loopback does not work in your setup.

Do korifi-api logs (kubectl logs -n korifi deployments/korifi-api-deployment) get some errors while you push the app?

[vkazmin1]

kubectl logs -n korifi deployments/korifi-api-deployment

Hi @vkazmin1

With Korifi 0.15 we have introduced the option of using a custom logcache implementation. If such a custom implementation is not specified via the experimental.externalLogCache.enabled helm vallue, then korifi would loopback to localhost. I wonder whether that loopback does not work in your setup.

Do korifi-api logs (kubectl logs -n korifi deployments/korifi-api-deployment) get some errors while you push the app?

Hi @danail-branekov

Logs exactly after cf push appname:

"severity":"INFO","timestamp":"2025-04-17T06:53:11.154543371Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"e85168dd-f470-4bfb-9b2c-3d476f9176ae","url":"/whoami","method":"GET","remoteAddr":"10.13.74.186:46354","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.176097013Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"e85168dd-f470-4bfb-9b2c-3d476f9176ae","url":"/whoami","method":"GET","status":200,"size":52,"durationMillis":21}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.190884508Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"acc90369-fb14-49cf-aec7-f72ae2719db1","url":"/v3/spaces/cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf/actions/apply_manifest","method":"POST","remoteAddr":"10.13.74.186:46354","contentLength":50}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.297924852Z","logger":"KubeAPIWarningLogger","caller":"log/warning_handler.go:65","message":"metadata.finalizers: \"cfApp.korifi.cloudfoundry.org\": prefer a domain-qualified finalizer name to avoid accidental conflicts with other finalizer writers"}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.469657511Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"acc90369-fb14-49cf-aec7-f72ae2719db1","url":"/v3/spaces/cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf/actions/apply_manifest","method":"POST","status":202,"size":0,"durationMillis":278}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.498163292Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"c7b4536d-1ae6-4c9e-992f-d588030d2312","url":"/v3/jobs/space.apply_manifest~cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","remoteAddr":"10.13.74.186:46354","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.498338014Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"c7b4536d-1ae6-4c9e-992f-d588030d2312","url":"/v3/jobs/space.apply_manifest~cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","status":200,"size":388,"durationMillis":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.51922357Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"f1bc1bfc-5416-495a-a98c-60c5aa429f70","url":"/v3/apps?names=php15&space_guids=cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","remoteAddr":"10.13.74.186:46354","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.567966711Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"f1bc1bfc-5416-495a-a98c-60c5aa429f70","url":"/v3/apps?names=php15&space_guids=cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","status":200,"size":2499,"durationMillis":48}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.594010361Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"97258a1e-979d-4aa2-b9c3-9bd44504c57f","url":"/v3/resource_matches","method":"POST","remoteAddr":"10.13.74.186:46354","contentLength":1924}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.594136842Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"97258a1e-979d-4aa2-b9c3-9bd44504c57f","url":"/v3/resource_matches","method":"POST","status":201,"size":17,"durationMillis":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.609332161Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"94614e52-2cd6-435a-8daa-e32d62aee597","url":"/v3/packages","method":"POST","remoteAddr":"10.13.74.186:46354","contentLength":96}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.847982086Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"94614e52-2cd6-435a-8daa-e32d62aee597","url":"/v3/packages","method":"POST","status":201,"size":1082,"durationMillis":238}
{"severity":"INFO","timestamp":"2025-04-17T06:53:11.880698932Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"f88e43cb-9b57-4576-92e0-7e069a3c79e5","url":"/v3/packages/667f904d-e4db-4f42-b6d8-d77bb35dcf22/upload","method":"POST","remoteAddr":"10.13.74.186:46354","contentLength":12550}
time="2025-04-17T06:53:12Z" level=info msg="Could not save cache" error="open /.ecr/.config.json.tmp3652810338: no such file or directory"
time="2025-04-17T06:53:12Z" level=info msg="Could not save cache" error="open /.ecr/.config.json.tmp1865889171: no such file or directory"
{"severity":"INFO","timestamp":"2025-04-17T06:53:13.118875866Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"f88e43cb-9b57-4576-92e0-7e069a3c79e5","url":"/v3/packages/667f904d-e4db-4f42-b6d8-d77bb35dcf22/upload","method":"POST","status":200,"size":1072,"durationMillis":1238}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.137129204Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"d23438b7-70ea-42b7-8418-e0e21d27b274","url":"/v3/builds","method":"POST","remoteAddr":"10.13.74.186:46354","contentLength":59}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.173761063Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"72cb63b9-1b43-41c5-bf65-a56ec25c1d4f","url":"/v3/apps?names=php15&space_guids=cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","remoteAddr":"10.13.74.186:48112","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.186522891Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"d23438b7-70ea-42b7-8418-e0e21d27b274","url":"/v3/builds","method":"POST","status":201,"size":960,"durationMillis":49}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.266071732Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"72cb63b9-1b43-41c5-bf65-a56ec25c1d4f","url":"/v3/apps?names=php15&space_guids=cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf","method":"GET","status":200,"size":2499,"durationMillis":92}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.284031104Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"ca25b4be-35d8-43e5-9e8c-2dbcb85cacd3","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","remoteAddr":"10.13.74.186:48112","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.29419878Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"ca25b4be-35d8-43e5-9e8c-2dbcb85cacd3","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","status":200,"size":960,"durationMillis":10}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.31434108Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"f751ee46-7779-4b02-aa99-c1903db22750","url":"/api/v1/info","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.31444047Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"f751ee46-7779-4b02-aa99-c1903db22750","url":"/api/v1/info","method":"GET","status":200,"size":44,"durationMillis":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.329222296Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"f078e519-fa23-44e7-8e88-3ac32562d670","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.383614635Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"f078e519-fa23-44e7-8e88-3ac32562d670","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":54}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.649968764Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"efe86964-4bd5-41d9-89c5-f8e334547e4c","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.678991929Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"efe86964-4bd5-41d9-89c5-f8e334547e4c","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":29}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.943898315Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"b47323ff-0e2f-4367-9027-1963e28274c6","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:14.974927217Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"b47323ff-0e2f-4367-9027-1963e28274c6","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":31}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.244664904Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"1f298708-f5ca-4084-bb7e-9475d195c167","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.279297256Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"1f298708-f5ca-4084-bb7e-9475d195c167","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":34}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.545856168Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"1146760f-3597-4d28-b620-934bb7500373","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.575972232Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"1146760f-3597-4d28-b620-934bb7500373","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":30}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.840883328Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"19f6b6f5-7bc0-4f84-9e26-20223697b9af","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:15.874003878Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"19f6b6f5-7bc0-4f84-9e26-20223697b9af","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":33}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.143626754Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"d703b37a-261c-4b45-9365-db02c5be73a3","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.182478752Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"d703b37a-261c-4b45-9365-db02c5be73a3","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":38}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.452199401Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"cbfe95ff-99aa-4502-80e1-c3237c2ce292","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.48176659Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"cbfe95ff-99aa-4502-80e1-c3237c2ce292","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":29}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.747239641Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"a27a7c32-70ea-49d8-b3ad-79df916f6f36","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:16.785752656Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"a27a7c32-70ea-49d8-b3ad-79df916f6f36","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":38}
{"severity":"INFO","timestamp":"2025-04-17T06:53:17.051807493Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"4983c8ae-95bd-403b-a817-a99c5996d2ee","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:53:17.082116298Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"4983c8ae-95bd-403b-a817-a99c5996d2ee","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":30}

and

INFO","timestamp":"2025-04-17T06:57:47.174191374Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"7d35b85a-968a-4bce-99ee-4bdf142115bc","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":32}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.443201805Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"0902c546-ad69-44e0-9c33-95804db40ae8","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.478812055Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"0902c546-ad69-44e0-9c33-95804db40ae8","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":35}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.552263686Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"a09d1aa5-4772-423b-8b51-f2c09c1250d7","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","remoteAddr":"10.13.74.186:48112","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.578920301Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"a09d1aa5-4772-423b-8b51-f2c09c1250d7","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","status":200,"size":960,"durationMillis":26}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.744142276Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"347203cd-dab4-4ec3-8223-5f840e9e76df","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.903741213Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"347203cd-dab4-4ec3-8223-5f840e9e76df","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":159}
{"severity":"INFO","timestamp":"2025-04-17T06:57:48.175602698Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"cca750e2-f58e-426b-a364-f67162d4acf7","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:48.22551606Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"cca750e2-f58e-426b-a364-f67162d4acf7","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":49}
{"severity":"INFO","timestamp":"2025-04-17T06:57:48.49204777Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"449b7dd4-5132-4e18-a8a9-17175aee53bd","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:48.600850878Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"449b7dd4-5132-4e18-a8a9-17175aee53bd","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":108}
{"severity":"INFO","timestamp":"2025-04-17T06:57:48.865675595Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"b996eec6-4c06-467b-a7b4-3a9ca4fd0711","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.002173997Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"b996eec6-4c06-467b-a7b4-3a9ca4fd0711","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":136}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.267920551Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"ea6b7ec5-a55b-4452-ac5f-ca87ed808e00","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.298626609Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"ea6b7ec5-a55b-4452-ac5f-ca87ed808e00","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":30}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.563305185Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"28460b9a-96fc-4aab-8583-6c4e9f368e1e","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.598495702Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"28460b9a-96fc-4aab-8583-6c4e9f368e1e","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":35}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.863179057Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"7b0bd11f-f545-43f3-9c57-99bea3d8c0e1","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:49.993708769Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"7b0bd11f-f545-43f3-9c57-99bea3d8c0e1","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":130}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.258682465Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"0ee9cecd-2b43-4d98-880e-a373ee480988","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.388623763Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"0ee9cecd-2b43-4d98-880e-a373ee480988","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":129}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.594214088Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"a2e058b3-4063-47bd-bf2d-c999dcb3b462","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","remoteAddr":"10.13.74.186:48112","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.609316276Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"a2e058b3-4063-47bd-bf2d-c999dcb3b462","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","status":200,"size":960,"durationMillis":15}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.654331106Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"49242ab1-0f0f-4d5f-a71a-1285e65d5694","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.71884937Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"49242ab1-0f0f-4d5f-a71a-1285e65d5694","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":64}
{"severity":"INFO","timestamp":"2025-04-17T06:57:50.984392462Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"27c6471d-a79d-4f27-b996-7c0189ed1f2b","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.015807067Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"27c6471d-a79d-4f27-b996-7c0189ed1f2b","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":31}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.279880886Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"e941d59f-345f-484b-84ed-c9fa448d2b71","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.404250576Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"e941d59f-345f-484b-84ed-c9fa448d2b71","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":124}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.67481886Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"e33773b6-7b61-43bd-80b3-d9e261aa20f2","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.703592323Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"e33773b6-7b61-43bd-80b3-d9e261aa20f2","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":28}
{"severity":"INFO","timestamp":"2025-04-17T06:57:51.985505513Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"cd1941e4-865a-44a7-9848-3f814e736b65","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.027190896Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"cd1941e4-865a-44a7-9848-3f814e736b65","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":41}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.303948522Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"784d155d-4d0b-4c74-8747-4ca9d93e43e3","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.352824175Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"784d155d-4d0b-4c74-8747-4ca9d93e43e3","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":48}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.663427267Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"e51292e5-1259-4d9b-8ffb-ac6fa51f283a","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.694831342Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"e51292e5-1259-4d9b-8ffb-ac6fa51f283a","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":31}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.961190332Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"ecab7805-001e-47a2-b62a-853edd609398","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:52.995084057Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"ecab7805-001e-47a2-b62a-853edd609398","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":33}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.259797503Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"467cdb6d-2220-4c47-bbad-f0fbef42952b","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.298457069Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"467cdb6d-2220-4c47-bbad-f0fbef42952b","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":38}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.563600158Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"0b61b4b0-6c65-4716-8f18-ec78efd8e5ea","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.595557317Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"0b61b4b0-6c65-4716-8f18-ec78efd8e5ea","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":31}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.627287555Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"b64ddcfa-f718-45e8-83b4-37cb50caa042","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","remoteAddr":"10.13.74.186:48112","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.694516023Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"b64ddcfa-f718-45e8-83b4-37cb50caa042","url":"/v3/builds/f307a62b-8efb-4874-94b4-672d25ba2b00","method":"GET","status":200,"size":960,"durationMillis":67}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.861520163Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"d26878d8-cb4a-4701-bcea-f4eb99cbfc55","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:53.898366434Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"d26878d8-cb4a-4701-bcea-f4eb99cbfc55","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":36}
{"severity":"INFO","timestamp":"2025-04-17T06:57:54.166885173Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"ebf3e0c5-c79a-4580-82bb-711e39657268","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:54.200829349Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"ebf3e0c5-c79a-4580-82bb-711e39657268","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":33}
{"severity":"INFO","timestamp":"2025-04-17T06:57:54.47218959Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"59bf6550-a276-4f9e-89ed-f53188c9933f","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:54.569482331Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"59bf6550-a276-4f9e-89ed-f53188c9933f","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":97}

experimental.externalLogCache.enabled is not enabled.

[vkazmin1]

Build Cleanup Race Condition in Korifi 0.15.0

Issue Description

After upgrading to Korifi 0.15.0, we're observing a race condition where builds get stuck in a polling loop. The API continuously polls for build status even when the underlying kpack builds may not exist or be in an inconsistent state.

Observed Behavior

1. When pushing an app or during build operations, Korifi creates CFBuild resources
2. The API continuously polls these builds via endpoints like:

   /v3/builds/<build-id>
   /api/v1/read/<resource-id>
   

3. Even after deleting builds, the polling continues, indicating a potential state management issue
4. Common errors observed:

   "error":"Operation cannot be fulfilled on builders.kpack.io \"23417467-e801-5779-a0f8-2182d79d9a42\": the object has been modified; please apply your changes to the latest version and try again"
   "error":"build.kpack.io \"b0d4ea2b-f2cd-4d7d-a157-a084dd2b7abc-build-1\" not found"
   

Root Cause

In 0.15.0, Korifi changed how it handles API server interactions to reduce empty patches. Probably, this is causing a race condition between the BuildCleaner and the kpack controller where the BuildCleaner sees builds as "running" but they don't exist in kpack anymore.

Impact

• Continuous polling of non-existent or completed builds
• Failed app deployments with 404 errors when retrieving logs
• Degraded user experience during cf push operations

Steps to Reproduce

1. Deploy an application using cf push
2. Observe build polling in API logs
3. Delete the build resources
4. Notice continued polling despite resource deletion

CFBuild:

k describe cfbuilds.korifi.cloudfoundry.org 837de3c1-01e4-4753-8393-6d111fd597a7  -n cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf
Name:         837de3c1-01e4-4753-8393-6d111fd597a7
Namespace:    cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf
Labels:       korifi.cloudfoundry.org/app-guid=6c023ebf-2883-471c-b608-6730a912cc93
              korifi.cloudfoundry.org/package-guid=ff7e88e1-dd28-448e-9f1a-342d50925812
              korifi.cloudfoundry.org/space-guid=cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf
Annotations:  korifi.cloudfoundry.org/creation-version: v0.15.0
API Version:  korifi.cloudfoundry.org/v1alpha1
Kind:         CFBuild
Metadata:
  Creation Timestamp:  2025-04-22T10:21:34Z
  Generation:          1
  Owner References:
    API Version:           korifi.cloudfoundry.org/v1alpha1
    Block Owner Deletion:  true
    Controller:            true
    Kind:                  CFApp
    Name:                  6c023ebf-2883-471c-b608-6730a912cc93
    UID:                   3f0caacc-3c9b-4c9d-b862-44719447b0d5
  Resource Version:        189583581
  UID:                     89848dbb-3f42-4c92-9a6e-db9750ce135b
Spec:
  App Ref:
    Name:  6c023ebf-2883-471c-b608-6730a912cc93
  Lifecycle:
    Data:
      Stack:  
    Type:     buildpack
  Package Ref:
    Name:             ff7e88e1-dd28-448e-9f1a-342d50925812
  Staging Disk MB:    0
  Staging Memory MB:  0
Status:
  Conditions:
    Last Transition Time:  2025-04-22T10:21:34Z
    Message:               
    Observed Generation:   1
    Reason:                BuildRunning
    Status:                True
    Type:                  Staging
    Last Transition Time:  2025-04-22T10:21:34Z
    Message:               Ready
    Observed Generation:   1
    Reason:                Ready
    Status:                True
    Type:                  Ready
  Observed Generation:     1
Events:                    <none>

[danail-branekov]

@vkazmin1 thanks for all the details.

From the api logs I can see that reading from logcache returns an non-empty result (size is not zero) and the response code is 200:

{"severity":"INFO","timestamp":"2025-04-17T06:57:47.744142276Z","logger":"http-logger","caller":"middleware/http_logging.go:36","message":"request","correlation-id":"347203cd-dab4-4ec3-8223-5f840e9e76df","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","remoteAddr":"10.13.74.186:48126","contentLength":0}
{"severity":"INFO","timestamp":"2025-04-17T06:57:47.903741213Z","logger":"http-logger","caller":"middleware/http_logging.go:40","message":"response","correlation-id":"347203cd-dab4-4ec3-8223-5f840e9e76df","url":"/api/v1/read/b46779fa-d88f-45d3-a9b5-a7618f8483b6?descending=true&limit=1&start_time=-6795364578871345152","method":"GET","status":200,"size":27,"durationMillis":159}

Also, note that the start_time parameter is always negative, i.e. the cli is requesting the logs from the very beginning. On a happy path subsequent requests should have their start_time with a timestamp that is after the last invocation.

I wonder what the log cache read request returns. Could you try performing the request with cf curl and check what the result is? For example, what would

cf curl "/api/v1/read/<put the actual guid from api logs here>?descending=true&limit=1&start_time=-6795364578871345152"

As per build cleaner race - could you elaborate which build resources you delete in step 3 of your reproduction scenario?

[vkazmin1]

@danail-branekov
cf curl output:

$ korifi-15 % cf curl "/v3/builds/c59f0221-7aba-4a6a-aaae-8214b6e4725e"
{"guid":"c59f0221-7aba-4a6a-aaae-8214b6e4725e","created_at":"2025-04-23T07:42:59Z","updated_at":"2025-04-23T07:42:59Z","created_by":{},"state":"STAGING","staging_memory_in_mb":0,"staging_disk_in_mb":0,"error":null,"lifecycle":{"type":"buildpack","data":{"buildpacks":[]}},"package":{"guid":"2ae3f1d3-a8c1-41df-99b8-25245383d5fd"},"droplet":null,"relationships":{"app":{"data":{"guid":"7ee64aea-ae9e-4331-ad4b-e105e61bc5ae"}}},"metadata":{"labels":{"korifi.cloudfoundry.org/app-guid":"7ee64aea-ae9e-4331-ad4b-e105e61bc5ae","korifi.cloudfoundry.org/package-guid":"2ae3f1d3-a8c1-41df-99b8-25245383d5fd","korifi.cloudfoundry.org/space-guid":"cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf"},"annotations":{"korifi.cloudfoundry.org/creation-version":"v0.15.0"}},"links":{"app":{"href":"https://api.webiste.de/v3/apps/7ee64aea-ae9e-4331-ad4b-e105e61bc5ae"},"self":{"href":"https://api.website.de/v3/builds/c59f0221-7aba-4a6a-aaae-8214b6e4725e"}}}

$ korifi-15 % cf curl "/api/v1/read/7ee64aea-ae9e-4331-ad4b-e105e61bc5ae?descending=true&limit=1&start_time=-6795364578871345152"
{"envelopes":{"batch":[]}}

Regarding build cleaner race.
As I understand, the build cleaner race condition involves two types of resources that need to be cleaned up (if we would do it via kubectl):
The CFBuild resource (Korifi's build object):

kubectl delete cfbuilds.korifi.cloudfoundry.org -n cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf c59f0221-7aba-4a6a-aaae-8214b6e4725e

The corresponding kpack Build resource (if it exists)

kubectl get builds.kpack.io -n cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf

The race condition occurs when:

1. The BuildCleaner deletes the kpack Build
2. But the CFBuild remains in STAGING state
3. This causes the continuous polling with empty log results we're seeing

in our case, looking at the build status:

CFBuild exists in STAGING state
$korifi-15 % kubectl get cfbuilds.korifi.cloudfoundry.org -n cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf

NAME                                   APPGUID                                STAGED   AGE
0eb72bdb-a6b6-4394-bcab-0ecd531346c6   bff6e995-56ba-43dd-9a78-877682cecad0   True     7d18h
379b1210-3e47-4f3e-af7a-5a2a2a9e7936   cfe50311-b894-40fc-b725-3f8a5f727000   True     25h
4ebf9d5b-e4db-42c9-96b4-59736aa079da   aa432a51-d21c-465c-9baf-39883e06f6b5   True     7d
6c7ce538-1143-4fb5-8806-7afc37dd90ee   e2a0e75b-70d4-41f3-8ed7-f2b100d5d94d   True     7d18h
6dff5141-eb4f-4e04-904e-e40870b4a371   c37565bd-9a93-4b5f-9a52-238f8ec90b0b   True     7d18h
6ed63fec-1748-4c5e-8222-3c0720618fee   6a24ebf8-d6c7-4784-87bf-6b8951ec1783   True     7d1h
7b9795fc-6609-49e3-8172-8e11c4cff8a3   fa0e7fa8-c6df-42b9-9eaa-a0fa786b53f1   True     25h
8156c9b4-57bb-4f45-b350-8c1782b80843   a089daf6-e797-4075-a578-8422250f22c4   True     231d
8a1dcf79-dc4a-47db-add3-fb4ca66e3cba   933a5cc1-26c1-46fa-9d55-e2973193c97e   True     195d
8b5d681a-4f90-4f29-9b0e-24ad982157f0   b46779fa-d88f-45d3-a9b5-a7618f8483b6   True     5d18h
8f7a4be9-a1e1-4ae9-9700-ec2e89d795ea   7ee64aea-ae9e-4331-ad4b-e105e61bc5ae   False    5m22s
97052fc3-a02f-4af0-9122-4d7eaed326e7   6a24ebf8-d6c7-4784-87bf-6b8951ec1783   True     7d
9ec60d14-7b03-4a3d-af32-c4d18900b266   7cd70c02-a81a-452b-97d7-80cf4b68cd7c            5m1s
a1b85f74-b7ea-44a4-b18b-330f6ce89020   b46779fa-d88f-45d3-a9b5-a7618f8483b6   True     5d18h
bed710a1-f874-4202-b878-b57c6ec497a2   e2a0e75b-70d4-41f3-8ed7-f2b100d5d94d   True     7d2h
c37d8a47-b161-49f9-9f36-7beec30451c9   8381b387-ea95-4a21-a4c1-bcbcc1122c8b   True     7d18h
c59f0221-7aba-4a6a-aaae-8214b6e4725e   7ee64aea-ae9e-4331-ad4b-e105e61bc5ae            28m
dc563df3-a9a5-4800-8f31-6eadd56152a8   7b84f832-59e7-4b5b-817a-23eb8f923fa5   True     24h
e41a1955-4cbb-42df-a459-8a39eeedd108   8381b387-ea95-4a21-a4c1-bcbcc1122c8b   True     7d18h
e5390a19-6d12-4d3e-86dc-771e4c44595e   aa432a51-d21c-465c-9baf-39883e06f6b5   True     7d
e868fad0-ea91-427c-86ce-6b66f2e0d448   fa0e7fa8-c6df-42b9-9eaa-a0fa786b53f1   True     26h
eabc0211-11bb-4977-911a-4bc1d46608e2   241279d5-0a6f-4d27-ae48-6e71024d1e7c   True     7d18h
edc237f7-24b4-4fa0-9ade-d1b086f241ab   ec627d89-1e87-4ca6-a911-552e2a9ebdb9   True     7d18h
f0918abd-fc48-417e-966a-293bdbd6e9f6   933a5cc1-26c1-46fa-9d55-e2973193c97e   True     195d
f307a62b-8efb-4874-94b4-672d25ba2b00   b46779fa-d88f-45d3-a9b5-a7618f8483b6   True     6d1h

$korifi-15 % kubectl get builds.kpack.io -n cf-space-25ddf634-58df-4dff-a1fc-4a4ec6e90baf

NAME                                            IMAGE                                                                                                                                                                                     SUCCEEDED
241279d5-0a6f-4d27-ae48-6e71024d1e7c-build-1    151111117596.dkr.ecr.eu-central-1.amazonaws.com/tenant/241279d5-0a6f-4d27-ae48-6e71024d1e7c-droplets@sha256:74f1c3afc41a06696   True

but there is no here a respective builds.kpack.io for newly created cfbuilds.korifi.cloudfoundry.org

• it has invalid configuration (no memory/disk limits, no buildpacks)

This suggests the kpack Build was either never created or was cleaned up prematurely

Really smth strange. If I revert back to 0.14.0, cf push starts to work properly again.

[georgethebeatle]

@vkazmin1 We still cannot reproduce this issue. Does it happen consistently for all apps or is it sporadic? Is it affected by the concrete buidpack, i.e. does it happen for php apps only? Can you try to push your app by explicitly specifying the buildpack via the -b flag to force the creation of a dedicated builder? Also are you doing any manual modifications with kubectl?

I can see in the logs above that there is some org namespace being deleted: "requeuing waiting for namespace deletion". Can you check if the org where you push your app has its deletion timestamp set?