Skip to content
This repository has been archived by the owner on Feb 14, 2023. It is now read-only.

CF-StatsUnavailable; Stats unavailable: Stats server temporarily unavailable; "code": 200002 #639

Closed
krismarc opened this issue Mar 11, 2021 · 2 comments
Closed

CF-StatsUnavailable; Stats unavailable: Stats server temporarily unavailable; "code": 200002 #639

krismarc opened this issue Mar 11, 2021 · 2 comments

Comments

@krismarc
Copy link

Hi CF Community,

Describe the bug

I've decided to go further with my tests of cf-for-k8s on Minikube using Docker for windows. This time, I've attempted to deploy simple test python app. https://github.com/IBM-Cloud/get-started-python

Push went fine except an error at the end (at this point it should return the app status). However, the app is accessible.

To Reproduce*

Steps to reproduce the behavior:

  1. App deployment using following manifest file:
s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cat manifest.yml
applications:
- name: GetStartedPython
  memory: 128M
  buildpacks:
  - paketo-community/python
  routes:
  - route: test.apps.127.0.0.1.nip.io
  1. Check if app exists:
s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cf curl /v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575
{
   "metadata": {
      "guid": "0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575",
      "url": "/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575",
      "created_at": "2021-03-11T20:12:23Z",
      "updated_at": "2021-03-11T20:43:13Z"
   },
   "entity": {
      "name": "GetStartedPython",
      "production": false,
      "space_guid": "2970cd06-6e52-4594-8576-ef3d33e5669f",
      "stack_guid": "e0d593c7-f8d7-4210-8d90-76cb784f0292",
      "buildpack": null,
      "detected_buildpack": null,
      "detected_buildpack_guid": null,
      "environment_json": null,
      "memory": 128,
      "instances": 1,
      "disk_quota": 1024,
      "state": "STARTED",
      "version": "f968312e-010d-4437-bdc2-e9beef515bd1",
      "command": null,
      "console": false,
      "debug": null,
      "staging_task_id": "384c2ffc-9e14-4cec-80d3-d7f397aa6180",
      "package_state": "STAGED",
      "health_check_type": "port",
      "health_check_timeout": null,
      "health_check_http_endpoint": null,
      "staging_failed_reason": null,
      "staging_failed_description": null,
      "diego": true,
      "docker_image": null,
      "docker_credentials": {
         "username": null,
         "password": null
      },
      "package_updated_at": "2021-03-11T20:41:34Z",
      "detected_start_command": "python hello.py\n",
      "enable_ssh": false,
      "ports": [
         8080
      ],
      "space_url": "/v2/spaces/2970cd06-6e52-4594-8576-ef3d33e5669f",
      "stack_url": "/v2/stacks/e0d593c7-f8d7-4210-8d90-76cb784f0292",
      "routes_url": "/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/routes",
      "events_url": "/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/events",
      "service_bindings_url": "/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/service_bindings",
      "route_mappings_url": "/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/route_mappings"
   }
}
  1. Check if app works:
s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ curl -IkL test.apps.127.0.0.1.nip.io
HTTP/1.1 301 Moved Permanently
location: https://test.apps.127.0.0.1.nip.io/
date: Thu, 11 Mar 2021 20:59:47 GMT
server: istio-envoy
transfer-encoding: chunked

HTTP/1.1 200 OK
content-length: 4769
content-type: text/html; charset=utf-8
last-modified: Tue, 01 Jan 1980 00:00:01 GMT
cache-control: public, max-age=43200
expires: Fri, 12 Mar 2021 08:59:47 GMT
etag: "315532801.0-4769-2641038048"
date: Thu, 11 Mar 2021 20:59:47 GMT
server: istio-envoy
x-envoy-upstream-service-time: 3
  1. Few attempts to check stats:
s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cf curl /v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/stats
{
   "description": "Stats unavailable: Stats server temporarily unavailable.",
   "error_code": "CF-StatsUnavailable",
   "code": 200002
}

s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cf apps
Getting apps in org test-org / space test-space as admin...

Stats unavailable: Stats server temporarily unavailable.
FAILED

s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cf curl /v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/stats -v

REQUEST: [2021-03-11T21:57:32+01:00]
POST /oauth/token HTTP/1.1
Host: login.127.0.0.1.nip.io
Accept: application/json
Authorization: [PRIVATE DATA HIDDEN]
Content-Type: application/x-www-form-urlencoded
User-Agent: go-cli 7.2.0+be4a5ce2b.2020-12-10 / linux

grant_type=refresh_token&refresh_token=[PRIVATE DATA HIDDEN]&scope=

RESPONSE: [2021-03-11T21:57:32+01:00]
HTTP/1.1 200 OK
Connection: close
Transfer-Encoding: chunked
Cache-Control: no-store
Content-Type: application/json;charset=UTF-8
Date: Thu, 11 Mar 2021 20:57:32 GMT
Pragma: no-cache
Server: istio-envoy
Strict-Transport-Security: max-age=31536000 ; includeSubDomains
X-Content-Type-Options: nosniff
X-Envoy-Upstream-Service-Time: 134
X-Frame-Options: DENY
X-Xss-Protection: 1; mode=block

12e3
{"access_token":"[PRIVATE DATA HIDDEN]","token_type":"[PRIVATE DATA HIDDEN]","id_token":"[PRIVATE DATA HIDDEN]","refresh_token":"[PRIVATE DATA HIDDEN]","expires_in":599,"scope":"routing.router_groups.read cloud_controller.read password.write cloud_controller.write openid routing.router_groups.write doppler.firehose scim.write scim.read cloud_controller.admin uaa.user","jti":"62009fdad0c741e38922732cdf07f41e"}
0



REQUEST: [2021-03-11T21:57:32+01:00]
GET /v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/stats HTTP/1.1
Host: api.127.0.0.1.nip.io
Accept: application/json
Authorization: [PRIVATE DATA HIDDEN]
Content-Type: application/json
User-Agent: go-cli 7.2.0+be4a5ce2b.2020-12-10 / linux


RESPONSE: [2021-03-11T21:57:33+01:00]
HTTP/1.1 503 Service Unavailable
Connection: close
Content-Length: 137
Content-Type: application/json;charset=utf-8
Date: Thu, 11 Mar 2021 20:57:33 GMT
Server: istio-envoy
X-Content-Type-Options: nosniff
X-Envoy-Upstream-Service-Time: 674
X-Vcap-Request-Id: 02f2ab73-180f-4c97-83bb-6b1ff7b288ca::e95b4bfb-960e-47da-bbae-bcaa64610562

{
  "description": "Stats unavailable: Stats server temporarily unavailable.",
  "error_code": "CF-StatsUnavailable",
  "code": 200002
}
  1. That's what I found in cf-api-server pod logs:
{
  "timestamp": "2021-03-11T20:47:45.363291100Z",
  "message": "Started GET \"/v2/apps/0dfaddbf-b97f-4e37-a4e7-fdbadb6a4575/stats\" for user: adedd6f1-b54f-4432-9bd5-b4e48d0fcf02, ip: 172.17.0.1 with vcap-request-id: 22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340 at 2021-03-11 20:47:45 UTC",
  "log_level": "info",
  "source": "cc.api",
  "data": {
    "request_guid": "22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340"
  },
  "thread_id": 68920,
  "fiber_id": 68940,
  "process_id": 1,
  "file": "/workspace/middleware/request_logs.rb",
  "lineno": 28,
  "method": "call"
}
{
  "timestamp": "2021-03-11T20:47:45.572132700Z",
  "message": "stats_for_app.error",
  "log_level": "error",
  "source": "cc.diego.instances_reporter",
  "data": {
    "request_guid": "22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340",
    "error": "2:the server could not find the requested resource (get pods.metrics.k8s.io). debug_error_string:{\"created\":\"@1615495665.571772000\",\"description\":\"Error received from peer ipv4:10.96.236.26:8080\",\"file\":\"src/core/lib/surface/call.cc\",\"file_line\":1063,\"grpc_message\":\"the server could not find the requested resource (get pods.metrics.k8s.io)\",\"grpc_status\":2}"
  },
  "thread_id": 68920,
  "fiber_id": 68940,
  "process_id": 1,
  "file": "/workspace/lib/cloud_controller/diego/reporters/instances_stats_reporter.rb",
  "lineno": 74,
  "method": "rescue in stats_for_app"
}
{
  "timestamp": "2021-03-11T20:47:45.572641500Z",
  "message": "Request failed: 503: {\"description\"=>\"Stats unavailable: Stats server temporarily unavailable.\", \"error_code\"=>\"CF-StatsUnavailable\", \"code\"=>200002, \"test_mode_info\"=>{\"description\"=>\"Stats unavailable: Stats server temporarily unavailable.\", \"error_code\"=>\"CF-StatsUnavailable\", \"backtrace\"=>[\"/workspace/lib/cloud_controller/backends/instances_reporters.rb:27:in `rescue in stats_for_app'\", \"/workspace/lib/cloud_controller/backends/instances_reporters.rb:24:in `stats_for_app'\", \"/workspace/app/controllers/runtime/stats_controller.rb:25:in `stats'\", \"/workspace/app/controllers/base/base_controller.rb:85:in `dispatch'\", \"/workspace/lib/cloud_controller/rest_controller/routes.rb:18:in `block in define_route'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1635:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1635:in `block in compile!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:987:in `block (3 levels) in route!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1006:in `route_eval'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:987:in `block (2 levels) in route!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1035:in `block in process_route'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1033:in `catch'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1033:in `process_route'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:985:in `block in route!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:984:in `each'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:984:in `route!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1098:in `block in dispatch!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `block in invoke'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `catch'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `invoke'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1095:in `dispatch!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:919:in `block in call!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `block in invoke'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `catch'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1072:in `invoke'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:919:in `call!'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:908:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/xss_header.rb:18:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/path_traversal.rb:16:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/json_csrf.rb:26:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/base.rb:50:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/base.rb:50:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-protection-2.0.8.1/lib/rack/protection/frame_options.rb:31:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/null_logger.rb:11:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:194:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/sinatra-2.0.8.1/lib/sinatra/base.rb:1951:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/urlmap.rb:74:in `block in call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'\", \"/workspace/middleware/request_logs.rb:38:in `call'\", \"/workspace/middleware/security_context_setter.rb:19:in `call'\", \"/workspace/middleware/vcap_request_id.rb:15:in `call'\", \"/workspace/middleware/cors.rb:49:in `call_app'\", \"/workspace/middleware/cors.rb:14:in `call'\", \"/workspace/middleware/request_metrics.rb:12:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/rack-2.2.3/lib/rack/builder.rb:244:in `call'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/thin-1.7.2/lib/thin/connection.rb:86:in `block in pre_process'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `catch'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/thin-1.7.2/lib/thin/connection.rb:84:in `pre_process'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/thin-1.7.2/lib/thin/connection.rb:50:in `block in process'\", \"/layers/paketo-buildpacks_bundle-install/gems/ruby/2.7.0/gems/eventmachine-1.0.9.1/lib/eventmachine.rb:1067:in `block in spawn_threadpool'\"]}}",
  "log_level": "error",
  "source": "cc.api",
  "data": {
    "request_guid": "22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340"
  },
  "thread_id": 68920,
  "fiber_id": 68940,
  "process_id": 1,
  "file": "/workspace/lib/sinatra/vcap.rb",
  "lineno": 45,
  "method": "block in registered"
}
{
  "timestamp": "2021-03-11T20:47:45.573017700Z",
  "message": "Completed 503 vcap-request-id: 22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340",
  "log_level": "info",
  "source": "cc.api",
  "data": {
    "request_guid": "22363b1c-c8f3-4bc0-b8cb-37f1b4543866::06fe60bf-556c-4242-8cfa-077ec32e6340"
  },
  "thread_id": 68920,
  "fiber_id": 68940,
  "process_id": 1,
  "file": "/workspace/middleware/request_logs.rb",
  "lineno": 40,
  "method": "call"
}

Cluster information

local minikube using WSL2

s8me5s@DESKTOP-Q8TBEVJ:~/liberty-test-app$ kubectl cluster-info
Kubernetes master is running at https://127.0.0.1:49179
KubeDNS is running at https://127.0.0.1:49179/api/v1/namespaces/kube-system/services/kube-dns:dns/proxy

s8me5s@DESKTOP-Q8TBEVJ:~/liberty-test-app$ cf t
API endpoint:   https://api.127.0.0.1.nip.io
API version:    3.98.0
user:           admin
org:            test-org
space:          test-space

CLI versions

paste output of the following commands

  1. ytt --version: ytt version 0.31.0
  2. kapp --version: kapp version 0.35.0
  3. kubectl version: v1.19.3
  4. cf version: cf version 7.2.0+be4a5ce2b.2020-12-10
@krismarc krismarc mentioned this issue Mar 11, 2021
Closed
@krismarc
Copy link
Author

Ok solved. 😆
"error": "2:the server could not find the requested resource (get pods.metrics.k8s.io). debug_error_string:{\"created\":\"@1615495665.571772000\",\"description\":\"Error received from peer ipv4:10.96.236.26:8080\",\"file\":\"src/core/lib/surface/call.cc\",\"file_line\":1063,\"grpc_message\":\"the server could not find the requested resource (get pods.metrics.k8s.io)\",\"grpc_status\":2}"

somehow I missed this..

Solution:

$ minikube addons enable metrics-server
    ▪ Using image k8s.gcr.io/metrics-server-amd64:v0.2.1
🌟  The 'metrics-server' addon is enabled

s8me5s@DESKTOP-Q8TBEVJ:~/get-started-python$ cf apps
Getting apps in org test-org / space test-space as admin...

name               requested state   processes   routes
GetStartedPython   started           web:1/1     GetStartedPython.apps.127.0.0.1.nip.io, test.apps.127.0.0.1.nip.io

@acosta11
Copy link
Member

Hi KrzMar,

Thanks for the detailed issue and follow up solution report! From my experience running cf-for-k8s, that error message tends to show up when metrics-server is absent from the cluster, so the solution you described in your follow up comment seems consistent with my understanding of the symptoms you described. I'm going to go ahead and resolve the issue as a result, but feel free to reopen if there was something we missed.

Thanks,
Andrew

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@krismarc @acosta11