WebThingsIO / thing-url-adapter

Proxy adapter for Web Thing API endpoints
Mozilla Public License 2.0
22 stars 18 forks source link

thing-url-adapter hits clients VERY frequently #38

Closed dhylands closed 6 years ago

dhylands commented 6 years ago

I have the gateway running on my RPi connected via WiFi. It has the thing-url-adapter installed. If I run the webthing-python example, then I see that gateway is doing over 70 GET requests per second from / on the webthing-python client.

Here's what I see in the log:

725 >python3 multiple-things.py 
2018-05-03 10:09:57,640 selector_events.py:65 DEBUG Using selector: EpollSelector
2018-05-03 10:09:57,641 multiple-things.py:118 DEBUG starting the sensor update looping task
2018-05-03 10:09:57,644 multiple-things.py:158 INFO starting the server
2018-05-03 10:09:58,523 web.py:2106 INFO 101 GET /0 (192.168.1.84) 0.94ms
2018-05-03 10:09:58,525 web.py:2106 INFO 101 GET /1 (192.168.1.84) 0.45ms
2018-05-03 10:09:58,528 web.py:2106 INFO 200 GET / (192.168.1.84) 0.76ms
2018-05-03 10:09:58,529 web.py:2106 INFO 200 GET / (192.168.1.84) 0.73ms
2018-05-03 10:09:58,584 web.py:2106 INFO 200 GET / (192.168.1.84) 1.00ms
2018-05-03 10:09:58,587 web.py:2106 INFO 200 GET /0/properties/on (192.168.1.84) 2.29ms
2018-05-03 10:09:58,588 web.py:2106 INFO 200 GET /0/properties/level (192.168.1.84) 0.48ms
2018-05-03 10:09:58,589 web.py:2106 INFO 101 GET /0 (192.168.1.84) 0.46ms
2018-05-03 10:09:58,620 web.py:2106 INFO 200 GET / (192.168.1.84) 0.60ms
2018-05-03 10:09:58,633 web.py:2106 INFO 200 GET / (192.168.1.84) 0.86ms
2018-05-03 10:09:58,642 web.py:2106 INFO 200 GET / (192.168.1.84) 0.59ms
2018-05-03 10:09:58,643 web.py:2106 INFO 200 GET /1/properties/on (192.168.1.84) 0.49ms
2018-05-03 10:09:58,644 web.py:2106 INFO 200 GET /1/properties/level (192.168.1.84) 0.48ms
2018-05-03 10:09:58,645 web.py:2106 INFO 101 GET /1 (192.168.1.84) 0.46ms
2018-05-03 10:09:58,652 web.py:2106 INFO 200 GET / (192.168.1.84) 0.55ms
2018-05-03 10:09:58,659 web.py:2106 INFO 200 GET / (192.168.1.84) 0.49ms
2018-05-03 10:09:58,691 web.py:2106 INFO 200 GET / (192.168.1.84) 0.58ms
2018-05-03 10:09:58,698 web.py:2106 INFO 200 GET / (192.168.1.84) 0.52ms
2018-05-03 10:09:58,706 web.py:2106 INFO 200 GET / (192.168.1.84) 0.69ms
2018-05-03 10:09:58,712 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:58,718 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:58,732 web.py:2106 INFO 200 GET / (192.168.1.84) 0.51ms
2018-05-03 10:09:58,765 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:58,771 web.py:2106 INFO 200 GET / (192.168.1.84) 0.53ms
2018-05-03 10:09:58,779 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:58,792 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:58,800 web.py:2106 INFO 200 GET / (192.168.1.84) 0.55ms
2018-05-03 10:09:58,843 web.py:2106 INFO 200 GET / (192.168.1.84) 0.59ms
2018-05-03 10:09:58,849 web.py:2106 INFO 200 GET / (192.168.1.84) 0.49ms
2018-05-03 10:09:58,856 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:58,866 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:58,872 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:58,878 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:58,900 web.py:2106 INFO 200 GET / (192.168.1.84) 0.58ms
2018-05-03 10:09:58,908 web.py:2106 INFO 200 GET / (192.168.1.84) 0.53ms
2018-05-03 10:09:58,914 web.py:2106 INFO 200 GET / (192.168.1.84) 0.49ms
2018-05-03 10:09:58,920 web.py:2106 INFO 200 GET / (192.168.1.84) 0.52ms
2018-05-03 10:09:58,926 web.py:2106 INFO 200 GET / (192.168.1.84) 0.53ms
2018-05-03 10:09:58,932 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:58,938 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:58,972 web.py:2106 INFO 200 GET / (192.168.1.84) 0.61ms
2018-05-03 10:09:58,978 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:58,985 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:58,995 web.py:2106 INFO 200 GET / (192.168.1.84) 0.56ms
2018-05-03 10:09:59,007 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:59,102 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:59,113 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,119 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,125 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:59,131 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,137 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:59,167 web.py:2106 INFO 200 GET / (192.168.1.84) 0.94ms
2018-05-03 10:09:59,173 web.py:2106 INFO 200 GET / (192.168.1.84) 0.51ms
2018-05-03 10:09:59,179 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:59,186 web.py:2106 INFO 200 GET / (192.168.1.84) 0.70ms
2018-05-03 10:09:59,196 web.py:2106 INFO 200 GET / (192.168.1.84) 0.74ms
2018-05-03 10:09:59,202 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,240 web.py:2106 INFO 200 GET / (192.168.1.84) 0.56ms
2018-05-03 10:09:59,254 web.py:2106 INFO 200 GET / (192.168.1.84) 0.56ms
2018-05-03 10:09:59,261 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:59,267 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:59,275 web.py:2106 INFO 200 GET / (192.168.1.84) 0.67ms
2018-05-03 10:09:59,281 web.py:2106 INFO 200 GET / (192.168.1.84) 0.58ms
2018-05-03 10:09:59,312 web.py:2106 INFO 200 GET / (192.168.1.84) 0.56ms
2018-05-03 10:09:59,320 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,327 web.py:2106 INFO 200 GET / (192.168.1.84) 1.18ms
2018-05-03 10:09:59,334 web.py:2106 INFO 200 GET / (192.168.1.84) 1.00ms
2018-05-03 10:09:59,341 web.py:2106 INFO 200 GET / (192.168.1.84) 0.74ms
2018-05-03 10:09:59,348 web.py:2106 INFO 200 GET / (192.168.1.84) 1.17ms
2018-05-03 10:09:59,382 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:59,388 web.py:2106 INFO 200 GET / (192.168.1.84) 0.44ms
2018-05-03 10:09:59,394 web.py:2106 INFO 200 GET / (192.168.1.84) 0.46ms
2018-05-03 10:09:59,408 web.py:2106 INFO 200 GET / (192.168.1.84) 0.68ms
2018-05-03 10:09:59,426 web.py:2106 INFO 200 GET / (192.168.1.84) 0.62ms
2018-05-03 10:09:59,432 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:59,438 web.py:2106 INFO 200 GET / (192.168.1.84) 0.51ms
2018-05-03 10:09:59,444 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:59,457 web.py:2106 INFO 200 GET / (192.168.1.84) 0.49ms
2018-05-03 10:09:59,490 web.py:2106 INFO 200 GET / (192.168.1.84) 0.70ms
2018-05-03 10:09:59,498 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:59,508 web.py:2106 INFO 200 GET / (192.168.1.84) 0.60ms
2018-05-03 10:09:59,517 web.py:2106 INFO 200 GET / (192.168.1.84) 0.56ms
2018-05-03 10:09:59,521 web.py:2106 INFO 200 GET / (127.0.0.1) 0.57ms
2018-05-03 10:09:59,525 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:59,531 web.py:2106 INFO 200 GET / (192.168.1.84) 0.47ms
2018-05-03 10:09:59,534 web.py:2106 INFO 200 GET /0/properties/on (127.0.0.1) 0.45ms
2018-05-03 10:09:59,535 web.py:2106 INFO 200 GET /0/properties/level (127.0.0.1) 0.43ms
2018-05-03 10:09:59,537 web.py:2106 INFO 101 GET /0 (192.168.1.20) 0.46ms
2018-05-03 10:09:59,543 web.py:2106 INFO 200 GET /1/properties/on (127.0.0.1) 0.71ms
2018-05-03 10:09:59,545 web.py:2106 INFO 200 GET /1/properties/level (127.0.0.1) 0.66ms
2018-05-03 10:09:59,547 web.py:2106 INFO 101 GET /1 (192.168.1.20) 0.73ms
2018-05-03 10:09:59,563 web.py:2106 INFO 200 GET / (192.168.1.84) 0.53ms
2018-05-03 10:09:59,569 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:59,578 web.py:2106 INFO 200 GET / (192.168.1.84) 0.60ms
2018-05-03 10:09:59,585 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:59,591 web.py:2106 INFO 200 GET / (192.168.1.84) 0.44ms
2018-05-03 10:09:59,597 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:59,637 web.py:2106 INFO 200 GET / (192.168.1.84) 0.68ms
2018-05-03 10:09:59,645 web.py:2106 INFO 200 GET / (192.168.1.84) 1.60ms
2018-05-03 10:09:59,651 web.py:2106 INFO 200 GET / (192.168.1.84) 0.57ms
2018-05-03 10:09:59,657 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:59,664 web.py:2106 INFO 200 GET / (192.168.1.84) 0.72ms
2018-05-03 10:09:59,670 web.py:2106 INFO 200 GET / (192.168.1.84) 0.49ms
2018-05-03 10:09:59,676 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:59,721 web.py:2106 INFO 200 GET / (192.168.1.84) 0.92ms
2018-05-03 10:09:59,730 web.py:2106 INFO 200 GET / (192.168.1.84) 0.48ms
2018-05-03 10:09:59,736 web.py:2106 INFO 200 GET / (192.168.1.84) 0.83ms
2018-05-03 10:09:59,742 web.py:2106 INFO 200 GET / (192.168.1.84) 0.44ms
2018-05-03 10:09:59,749 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:59,767 web.py:2106 INFO 200 GET / (192.168.1.84) 0.58ms
2018-05-03 10:09:59,774 web.py:2106 INFO 200 GET / (192.168.1.84) 0.86ms
2018-05-03 10:09:59,781 web.py:2106 INFO 200 GET / (192.168.1.84) 0.77ms
2018-05-03 10:09:59,787 web.py:2106 INFO 200 GET / (192.168.1.84) 0.63ms
2018-05-03 10:09:59,794 web.py:2106 INFO 200 GET / (192.168.1.84) 0.50ms
2018-05-03 10:09:59,801 web.py:2106 INFO 200 GET / (192.168.1.84) 0.45ms
2018-05-03 10:09:59,842 web.py:2106 INFO 200 GET / (192.168.1.84) 0.87ms
2018-05-03 10:09:59,850 web.py:2106 INFO 200 GET / (192.168.1.84) 0.77ms
2018-05-03 10:09:59,856 web.py:2106 INFO 200 GET / (192.168.1.84) 0.64ms
2018-05-03 10:09:59,863 web.py:2106 INFO 200 GET / (192.168.1.84) 0.66ms
2018-05-03 10:09:59,874 web.py:2106 INFO 200 GET / (192.168.1.84) 0.59ms
2018-05-03 10:09:59,881 web.py:2106 INFO 200 GET / (192.168.1.84) 0.55ms
2018-05-03 10:09:59,917 web.py:2106 INFO 200 GET / (192.168.1.84) 0.86ms
2018-05-03 10:09:59,926 web.py:2106 INFO 200 GET / (192.168.1.84) 0.82ms
2018-05-03 10:09:59,934 web.py:2106 INFO 200 GET / (192.168.1.84) 0.71ms
2018-05-03 10:09:59,941 web.py:2106 INFO 200 GET / (192.168.1.84) 0.78ms
2018-05-03 10:09:59,954 web.py:2106 INFO 200 GET / (192.168.1.84) 0.59ms
Timmeey commented 6 years ago

You specifically mentioned the python-web-thing, does it not happen with other (js/java) web things? (just asking because you mentioning the pything web thing)

did you modify the source of the "thing-url-adapter"? because this is really weird, the timeouts are set to 5000ms between requests. Could you check the gateway logs/logfiles if there is anything unusual? (~/.mozilla-iot/log/run-app.log)

Are you using the git version? or are you using the bundled plugin version? Because i had weird issues with the git version and incompatibilities sometimes, which all got fixed after i removed all leftovers from the manual git version and switched to the bundled version coming with the gateway itself

dhylands commented 6 years ago

I happened to notice this while running the webthing-python example/multiple-things.py, so I have no idea if it happens with the other languages or not.

The gateway was just running in the background. I didn't configure it or add any things to it.