emissary-ingress / emissary

open source Kubernetes-native API gateway for microservices built on the Envoy Proxy
https://www.getambassador.io
Apache License 2.0
4.36k stars 683 forks source link

Upstream request timeout #372

Closed austrum closed 6 years ago

austrum commented 6 years ago

I've tried the 5 minute quick start on 2 machines and I'm getting the same result for both when I follow the instructions. Navigating to http://localhost:8080/ambassador/v0/diag yields an error "upstream request timeout". Here are the logs from docker:

docker run -it -p 8080:80 --name=ambassador --rm quay.io/datawire/ambassador:0.30.2 --demo
2018-04-11 00:16:47 kubewatch 0.30.2 INFO: No K8s
2018-04-11 00:16:47 kubewatch 0.30.2 INFO: generating config with gencount 1 (0 changes)
2018-04-11 00:16:48 kubewatch 0.30.2 INFO: Scout reports {"latest_version": "0.30.2", "application": "ambassador", "notices": [], "cached": false, "timestamp": 1523405807.740703}
[2018-04-11 00:16:48.239][10][info][upstream] source/common/upstream/cluster_manager_impl.cc:132] cm init: all clusters initialized
[2018-04-11 00:16:48.239][10][info][config] source/server/configuration_impl.cc:55] loading 1 listener(s)
[2018-04-11 00:16:48.251][10][info][config] source/server/configuration_impl.cc:95] loading tracing configuration
[2018-04-11 00:16:48.251][10][info][config] source/server/configuration_impl.cc:122] loading stats sink configuration
AMBASSADOR: starting diagd
AMBASSADOR: starting Envoy
AMBASSADOR: waiting
PIDS: 11:diagd 12:envoy 13:kubewatch
starting hot-restarter with target: /application/start-envoy.sh
forking and execing new child process at epoch 0
forked new child process with PID=14
[2018-04-11 00:16:48.389][14][info][main] source/server/server.cc:184] initializing epoch 0 (hot restart version=9.200.16384.127.options=capacity=16384, num_slots=8209 hash=228984379728933363)
[2018-04-11 00:16:48.525][14][info][config] source/server/configuration_impl.cc:55] loading 1 listener(s)
[2018-04-11 00:16:48.556][14][info][config] source/server/configuration_impl.cc:95] loading tracing configuration
[2018-04-11 00:16:48.556][14][info][config] source/server/configuration_impl.cc:122] loading stats sink configuration
[2018-04-11 00:16:48.557][14][info][main] source/server/server.cc:359] starting main dispatch loop
[2018-04-11 00:16:48.559][14][info][upstream] source/common/upstream/cluster_manager_impl.cc:132] cm init: all clusters initialized
[2018-04-11 00:16:48.559][14][info][main] source/server/server.cc:343] all clusters initialized. initializing init manager
[2018-04-11 00:16:48.559][14][info][config] source/server/listener_manager_impl.cc:543] all dependencies initialized. starting workers
2018-04-11 00:16:49 kubewatch 0.30.2 INFO: No K8s
2018-04-11 00:16:49 kubewatch 0.30.2 INFO: No K8s, idling
2018-04-11 00:16:49 diagd 0.30.2 INFO: Scout reports {"latest_version": "0.30.2", "application": "ambassador", "notices": [], "cached": false, "timestamp": 1523405809.38882}
[2018-04-11 00:16:58.560][14][info][main] source/server/drain_manager_impl.cc:65] shutting down parent after drain
ACCESS [2018-04-11T00:17:57.870Z] "GET /ambassador/v0/diag HTTP/1.1" 504 - 0 24 5012 - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/65.0.3325.181 Safari/537.36" "230f3426-a83d-45f4-89a6-a4d11250d0bd" "localhost:8080" "-"
ACCESS [2018-04-11T00:18:02.972Z] "GET /favicon.ico HTTP/1.1" 504 - 0 24 5012 - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/65.0.3325.181 Safari/537.36" "a88a141e-eebe-4cc4-8dd2-edf6d62e50f9" "localhost:8080" "-"

Hoping there's a quick fix? Would love to check out Ambassador! Thank you.

richarddli commented 6 years ago

Hi, apologies for the delay, and thank you for the bug report. We haven't been able to reproduce this. What version of Docker are you running?

ptagr commented 6 years ago

any update on this? just got a 504

slankas commented 6 years ago

The docker run instructions appear to be incorrect. Service appears to be listening on port 8877 from my logs.

docker run -it -p 8080:8877 --name=ambassador --rm quay.io/datawire/ambassador:0.34.2 --demo


2018-06-13 20:39:33 kubewatch 0.34.2 INFO: No K8s 2018-06-13 20:39:33 kubewatch 0.34.2 INFO: generating config with gencount 1 (0 changes) 2018-06-13 20:39:33 kubewatch 0.34.2 INFO: Scout reports {"latest_version": "0.32.2", "application": "ambassador", "notices": [], "cached": false, "timestamp": 1528922373.247525} [2018-06-13 20:39:33.479][10][info][upstream] source/common/upstream/cluster_manager_impl.cc:132] cm init: all clusters initialized [2018-06-13 20:39:33.479][10][info][config] source/server/configuration_impl.cc:53] loading 1 listener(s) [2018-06-13 20:39:33.501][10][info][config] source/server/configuration_impl.cc:87] loading tracing configuration [2018-06-13 20:39:33.501][10][info][config] source/server/configuration_impl.cc:109] loading stats sink configuration AMBASSADOR: starting diagd AMBASSADOR: starting Envoy AMBASSADOR: waiting PIDS: 14:diagd 15:envoy 16:kubewatch starting hot-restarter with target: /application/start-envoy.sh forking and execing new child process at epoch 0 forked new child process with PID=17 [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:181] initializing epoch 0 (hot restart version=10.200.16384.127.options=capacity=16384, num_slots=8209 hash=228984379728933363 size=2654312) [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:183] statically linked extensions: [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:185] access_loggers: envoy.file_access_log,envoy.http_grpc_access_log [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:188] filters.http: envoy.buffer,envoy.cors,envoy.ext_authz,envoy.fault,envoy.filters.http.rbac,envoy.grpc_http1_bridge,envoy.grpc_json_transcoder,envoy.grpc_web,envoy.gzip,envoy.health_check,envoy.http_dynamo_filter,envoy.ip_tagging,envoy.lua,envoy.rate_limit,envoy.router,envoy.squash,extauth [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:191] filters.listener: envoy.listener.original_dst,envoy.listener.proxy_protocol,envoy.listener.tls_inspector [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:194] filters.network: envoy.client_ssl_auth,envoy.echo,envoy.ext_authz,envoy.http_connection_manager,envoy.mongo_proxy,envoy.ratelimit,envoy.redis_proxy,envoy.tcp_proxy [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:196] stat_sinks: envoy.dog_statsd,envoy.metrics_service,envoy.statsd [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:198] tracers: envoy.dynamic.ot,envoy.lightstep,envoy.zipkin [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:201] transport_sockets.downstream: envoy.transport_sockets.capture,raw_buffer,tls [2018-06-13 20:39:33.679][17][info][main] source/server/server.cc:204] transport_sockets.upstream: envoy.transport_sockets.capture,raw_buffer,tls [2018-06-13 20:39:33.721][17][info][config] source/server/configuration_impl.cc:53] loading 1 listener(s) [2018-06-13 20:39:33.746][17][info][config] source/server/configuration_impl.cc:87] loading tracing configuration [2018-06-13 20:39:33.746][17][info][config] source/server/configuration_impl.cc:109] loading stats sink configuration [2018-06-13 20:39:33.747][17][info][main] source/server/server.cc:396] starting main dispatch loop [2018-06-13 20:39:33.749][17][info][upstream] source/common/upstream/cluster_manager_impl.cc:132] cm init: all clusters initialized [2018-06-13 20:39:33.749][17][info][main] source/server/server.cc:376] all clusters initialized. initializing init manager [2018-06-13 20:39:33.749][17][info][config] source/server/listener_manager_impl.cc:781] all dependencies initialized. starting workers 2018-06-13 20:39:34 kubewatch 0.34.2 INFO: No K8s 2018-06-13 20:39:34 kubewatch 0.34.2 INFO: No K8s, idling 2018-06-13 20:39:34 diagd 0.34.2 [P14TMainThread] INFO: thread count 17, listening on 0.0.0.0:8877 [2018-06-13 20:39:34 +0000] [14] [INFO] Starting gunicorn 19.8.1 [2018-06-13 20:39:34 +0000] [14] [INFO] Listening at: http://0.0.0.0:8877 (14) [2018-06-13 20:39:34 +0000] [14] [INFO] Using worker: threads [2018-06-13 20:39:34 +0000] [46] [INFO] Booting worker with pid: 46 2018-06-13 20:39:34 diagd 0.34.2 [P46TMainThread] INFO: Starting periodic updates 2018-06-13 20:39:40 diagd 0.34.2 [P46TThreadPoolExecutor-0_0] INFO: Scout reports {"latest_version": "0.32.2", "application": "ambassador", "notices": [], "cached": false, "timestamp": 1528922380.60811} [2018-06-13 20:39:43.748][17][info][main] source/server/drain_manager_impl.cc:63] shutting down parent after drain

richarddli commented 6 years ago

I've just tested again the Docker instructions, and they work fine. Please hop on our Slack (https://d6e.co/slack) if you need help!