Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Adding new routes or changing existing is very slow #1318

Closed
sivarajp opened this issue Mar 15, 2019 · 8 comments
Closed

Adding new routes or changing existing is very slow #1318

sivarajp opened this issue Mar 15, 2019 · 8 comments

Comments

@sivarajp
Copy link

sivarajp commented Mar 15, 2019 •
edited
Loading

Describe the bug
Adding new routes or changing existing is very slow. Takes sometime to reflect changes.

To Reproduce
Create a new route or update an existing route.

getambassador.io/config: |
  ---
  apiVersion: ambassador/v1
  kind:  Mapping
  name: test-service-mapping
  prefix: /services/test-service/
  service: test-service.services:8080
  rewrite: /services/test-service/

(Rewrite is correct, my service is running under context)
Expected behavior
Expect the route to take effect immediately.

Versions (please complete the following information):

  • Ambassador: 0.51.2
  • Kubernetes environment: AWS(Kubespray)
  • Version. v1.11.5

Additional context
Also if i change the route from /services/test-service/ to /services/testservice/ it takes time to reflect.

I enabled debug logs and i get 404 for few requests. After sometime the url is available.

ACCESS [2019-03-15T20:37:14.589Z] "GET /services/test-service/ HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.68.66" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "bda56d69-8961-4916-a020-c448feff9004" "abc.com:8443" "-"
ACCESS [2019-03-15T20:37:15.451Z] "GET /services/test-service/ HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.68.66" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "92df5cc6-60fe-42d8-afca-c9b0407edd7a" "internal-kube-aws-preprod2-internal-405356190.us-east-1.elb.amazonaws.com:8443" "-"
@sivarajp
Copy link
Author

sivarajp commented Mar 18, 2019 •
edited
Loading

Additional info. After ingress is updated, the services is available after 15 secs. Is it a normal behavior? If you notice the validation itself takes 15secs

2019/03/18 18:23:06 SYNC: python3 /ambassador/post_update.py http://localhost:38716/api/snapshot/9
2019-03-18 18:23:06 diagd 0.51.2 [P64TThreadPoolExecutor-0_7] INFO: Update requested from http://localhost:38716/api/snapshot/9
2019-03-18 18:23:06 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: copying configuration from http://localhost:38716/api/snapshot/9 to /ambassador/snapshots/snapshot-tmp.yaml
2019-03-18 18:23:21 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: successfully validated the resulting envoy configuration, continuing...
2019-03-18 18:23:21 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: rotating snapshots for snapshot 9
2019-03-18 18:23:21 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: saving Envoy configuration for snapshot 9
2019-03-18 18:23:21 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: running 'sh /ambassador/kick_ads.sh 47'
KICK: kicking ambex
2019-03-18 18:23:21 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: configuration updated
time="2019-03-18T18:23:21Z" level=info msg="Loaded file /ambassador/envoy/envoy.json"
time="2019-03-18T18:23:21Z" level=info msg="Pushing snapshot v9"
[2019-03-18 18:23:21.842][000119][info][upstream] [source/server/lds_api.cc:80] lds: add/update listener 'ambassador-listener-80'
2019-03-18 18:23:22 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: Scout reports {"latest_version": "0.51.2", "application": "ambassador", "cached": true, "timestamp": 1552932390.702468}
2019-03-18 18:23:22 diagd 0.51.2 [P64TAmbassadorEventWatcher] INFO: Scout notices: [{"level": "DEBUG", "message": "Returning cached result"}]

@esmet
Copy link
Contributor

esmet commented Mar 18, 2019

How many service objects exist across all namespaces in your cluster? I wonder if this is related to #1292

@sivarajp
Copy link
Author

We have close to 800 and it will increase in future.

@kflynn
Copy link
Member

kflynn commented Mar 21, 2019

This will, I hope, be addressed by 0.52.0's switch to the C YAML parser.

@sivarajp
Copy link
Author

sivarajp commented Mar 21, 2019 •
edited
Loading

@kflynn

The validation is fast now, but the envoy loading is still slow. Below is the logs. i have changed the service annotation at 2019/03/21 20:33:30, my first success response is ACCESS [2019-03-21T20:34:13.335Z] ".

It took almost 45 seconds to see my update.

2019/03/21 20:33:30 SYNC: python3 /ambassador/post_update.py http://localhost:35512/api/snapshot/4
2019-03-21 20:33:30 diagd 0.52.0 [P51TThreadPoolExecutor-0_15] INFO: Update requested from http://localhost:35512/api/snapshot/4
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: copying configuration from http://localhost:35512/api/snapshot/4 to /ambassador/snapshots/snapshot-tmp.yaml
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://dev-key-value-service.services:8080 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://employee-rs-service.services:8080 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://httpbin.org:80 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://key-value-service.services:8080 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://kube-docs.od-system:8080 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://127.0.0.1:8877 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://127.0.0.1:8877 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Load balancer for tcp://127.0.0.1:8877 is None
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: listen_ports ['80']
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: -global-: NOTICE: Ambassador 0.60 will default to listening on port 8080 for HTTP. You will need to change your configuration to continue using port 80.
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: successfully validated the resulting envoy configuration, continuing...
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: rotating snapshots for snapshot 4
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: saving Envoy configuration for snapshot 4
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: running 'sh /ambassador/kick_ads.sh 38'
KICK: kicking ambex
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: configuration updated from snapshot 4
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Scout reports {"latest_version": "0.51.2", "application": "ambassador", "cached": true, "timestamp": 1553199882.542976}
2019-03-21 20:33:30 diagd 0.52.0 [P51TAmbassadorEventWatcher] INFO: Scout notices: [{"level": "DEBUG", "message": "Returning cached result"}]
time="2019-03-21T20:33:30Z" level=info msg="Loaded file /ambassador/envoy/envoy.json"
time="2019-03-21T20:33:30Z" level=info msg="Pushing snapshot v4"
[2019-03-21 20:33:30.903][000084][info][upstream] [source/server/lds_api.cc:80] lds: add/update listener 'ambassador-listener-80'
ACCESS [2019-03-21T20:33:34.798Z] "GET / HTTP/1.0" 426 - 0 0 0 - "-" "LogicMonitor" "-" "10.233.67.66:80" "-"
ACCESS [2019-03-21T20:33:45.705Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "d1b669de-6d95-46c1-896d-9747f9afc230" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:33:59.399Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "59cf7822-884b-4e52-adc8-381355eb9537" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:33:59.578Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "5f476f45-7c94-4c3a-bc5a-c8f6007a10b5" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:33:59.770Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "a0d44724-c161-4352-8907-3d9d952d9ae5" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:33:59.913Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "e637d70b-9053-4cd7-9fa5-5728ce83c2d8" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:00.092Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "67711b56-c81c-4b27-b9ba-13ccaba08aa9" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:00.294Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "cc56dad7-3222-4f19-a424-273e8faf784b" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:00.450Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "fde5298a-7b81-474f-a8d9-690bbf1f105d" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:00.615Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "0f30c3c1-e5c5-4907-8583-116b80f679ce" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:00.784Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "6c48df1e-4988-4d04-a68a-dfa80fb2b63e" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:01.850Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "7a7f5b53-1a5c-461e-bd38-0c1c0d1f5860" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:02.020Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "937cb38a-5bcd-434c-bdf5-476c6830567c" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:02.199Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "c568306c-ca29-4a43-a2eb-28e83165f29b" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:02.388Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "bbfe9f3c-3dcc-47ed-8154-0df61de0c84f" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:02.576Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "3cbe154f-43b9-4c8a-87fa-76daa7d11d57" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:02.739Z] "GET /services/siva-kube-docs HTTP/1.1" 404 NR 0 0 0 - "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "39e409c0-8949-45be-b7b3-720ea556eb3b" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "-"
ACCESS [2019-03-21T20:34:13.335Z] "GET /services/siva-kube-docs HTTP/1.1" 200 - 0 10376 1 0 "10.20.13.34,10.94.97.158" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36" "89616299-de61-4b6f-b895-40c795107da4" "internal-kube-aws-dev2-internal-191080426.us-east-1.elb.amazonaws.com:8443" "10.233.2.13:8080"

@songole
Copy link

songole commented Apr 3, 2019

Could you add some comments in the original issue as well. It shows that multiple people are seeing it.

@sivarajp
Copy link
Author

@songole I'm not sure whats the original issue #. I can link.

@kflynn kflynn closed this as completed May 9, 2019
@kflynn
Copy link
Member

kflynn commented May 9, 2019

Lots of work around this in 0.60.3. I'm going to close this (again) -- please reopen (again) if there are issues on 0.61!

@weinong weinong mentioned this issue Jul 5, 2019
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@kflynn @esmet @sivarajp @songole