Confused with timings / Slow HTTP requests

[balonchiks]

hi, I have setup doods on a raspberry pi 4 (4Gb ram version) in a docker container, and i have configured home assistant (which is on a different machine but on the same network) to point image_processing to doods. Everything works so far but i am kind of confused on some points.

Please see my start and detection log below:

2020-10-30T14:19:48.764Z    INFO    detector/detector.go:79 Configured Detector {"package": "detector", "name": "default_edgetpu", "type": "tflite-edgetpu", "model": "models/mobilenet_ssd_v2_coco_quant_postprocess_edgetpu.tflite", "labels": 80, "width": 300, "height": 300}

2020-10-30T14:19:52.113Z    INFO    detector/detector.go:79 Configured Detector {"package": "detector", "name": "tensorflow", "type": "tensorflow", "model": "models/faster_rcnn_inception_v2_coco_2018_01_28.pb", "labels": 80, "width": -1, "height": -1}

2020-10-30T14:19:52.117Z    INFO    server/server.go:284    API Listening   {"package": "server", "address": ":8080", "tls": false, "version": "v0.2.5-0-gbf6d7a1-dirty"}

2020-10-30T14:20:04.510Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.060275315, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T14:20:04.515Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 11.233914828, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/0EhmoF4qWh-000001", "remote": "10.0.10.20:53816"}

2020-10-30T14:20:25.348Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.033383344, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

If I am correct, in the last line it says that the time it took to detect objects is "duration": 0.033383344, correct? but in the line before it says HTTP Request {"status": 200, "took": 11.233914828 - that is the time it took for the image to do a roundtrip between homeassistant to doods and back? am i correct? it doesn't look legit to me as almost 11 seconds is way to much, is there something that i am missing?

Thank you :)

[snowzach]

@balonchiks I think this is a nuance of the way tensorflow works on the first detection after it starts up. I think it doesn't load up everything right away. The first detection you do, from my experience, takes a while. Actually, if you have multiple threads configured (which is not a thing I believe when you use the edgeTPU) the first detection the thread does takes significantly longer than subsequent ones. You should have another log line after that last line you pasted in with the next request and I am betting the duration of that request is much slower. So the actual detection is quick but to get everything ready for the first detection takes a bit.

[balonchiks]

thanks for your reply but i forgot to mention that all the following lines (about 300 hundreds) are in the range of 10-11 seconds.. so not sure on what to do here. the raspberry pi is running on the 5ghz wifi and located about a meter away from the router, if that makes sense.

edit: it's been about 3 hours of running now and it's now down to about 8-9 seconds:

2020-10-30T16:57:55.761Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.031548702, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T16:57:55.765Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 8.876036118, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/ttNsYIJ4VX-000025", "remote": "10.0.10.20:35878"}

2020-10-30T16:58:07.906Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.028370483, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T16:58:07.909Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 8.967013485, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/ttNsYIJ4VX-000026", "remote": "10.0.10.20:50724"}

2020-10-30T16:58:19.657Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.033114488, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T16:58:19.660Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 8.745512089, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/ttNsYIJ4VX-000027", "remote": "10.0.10.20:60350"}

2020-10-30T16:58:31.766Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.03144563, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T16:58:31.769Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 8.854795901, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/ttNsYIJ4VX-000028", "remote": "10.0.10.20:44444"}

2020-10-30T16:58:43.866Z    INFO    tflite/detector.go:393  Detection Complete  {"package": "detector.tflite", "name": "default_edgetpu", "id": "", "duration": 0.029782086, "detections": 20, "device": {"Type":1,"Path":"/sys/bus/usb/devices/2-1"}}

2020-10-30T16:58:43.868Z    INFO    server/server.go:139    HTTP Request    {"status": 200, "took": 8.917077811, "request": "/detect", "method": "POST", "package": "server.request", "request-id": "aa09eeaee375/ttNsYIJ4VX-000029", "remote": "10.0.10.20:54902"}

[balonchiks]

switched to ethernet connection instead of wifi - no changes. also noticed that pi cpu usage peaks at >80% when the doods is running. s might be not enough cpu power?

[balonchiks]

ok, so the issue was with pi being undervolted, changed power supply - all good now