0

I am using Python 2.7.5. and try to use co-routine Greenthreads (Python eventlet) and Python requests module to speed up my REST API request.

I know The Python requests module uses poolmanager object (from urllib3 module) to maintain connections, I set the poolmanager DEFAULT_POOLSIZE = 1000.

Then monkeypatched my python module at __init__.py, and spawn 1000 greenthread to send PATCH requests (REST API) to my device. My device(F5 bigip device) can deal with 50req/s.

this is the log, which I find the problem is.

2022-07-13 09:54:31.893 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 1
2022-07-13 09:54:31.893 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.894 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 2
2022-07-13 09:54:31.895 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.895 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 3
2022-07-13 09:54:31.896 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.896 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 4
2022-07-13 09:54:31.897 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.897 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 5
2022-07-13 09:54:31.898 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.898 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 6
2022-07-13 09:54:31.899 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.900 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 7
2022-07-13 09:54:31.900 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.901 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 8
2022-07-13 09:54:31.901 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.902 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 9
2022-07-13 09:54:31.902 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.903 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 10
2022-07-13 09:54:31.903 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.904 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 11
2022-07-13 09:54:31.904 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.905 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 12
2022-07-13 09:54:31.906 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.906 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 13
2022-07-13 09:54:31.907 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.907 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 14
2022-07-13 09:54:31.908 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.909 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 15
2022-07-13 09:54:31.909 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.910 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 16
2022-07-13 09:54:31.910 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.911 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 17
2022-07-13 09:54:31.911 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.912 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 18
2022-07-13 09:54:31.912 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.913 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 19
2022-07-13 09:54:31.913 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.914 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 20
2022-07-13 09:54:31.914 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.915 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 21
2022-07-13 09:54:31.915 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.916 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 22
2022-07-13 09:54:31.916 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.917 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 23
2022-07-13 09:54:31.917 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.918 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 24
2022-07-13 09:54:31.918 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.919 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 25
2022-07-13 09:54:31.919 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.920 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 26
2022-07-13 09:54:31.920 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.921 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 27
2022-07-13 09:54:31.921 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.922 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 28
2022-07-13 09:54:31.922 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.923 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 29
2022-07-13 09:54:31.923 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.924 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 30
2022-07-13 09:54:31.925 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.925 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 31
2022-07-13 09:54:31.926 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.927 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 32
2022-07-13 09:54:31.927 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.928 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 33
2022-07-13 09:54:31.928 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.929 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 34
2022-07-13 09:54:31.929 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.930 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 35
2022-07-13 09:54:31.930 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:31.931 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse running green thread is 36
2022-07-13 09:54:31.931 31706 INFO f5_openstack_agent.lbaasv2.drivers.bigip.vs_connection [req-f7db08a8-432a-413f-b4c9-f9eb90de9613 bcd6de7aaddc49e386a664d0a20efcff 8a2d7296ae9b4bd4a412eb3cb9aa680e - - -] time elapse waiting  green thread is 0
2022-07-13 09:54:32.207 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.273908 sec
2022-07-13 09:54:32.209 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.276766 sec
2022-07-13 09:54:32.302 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.337186 sec
2022-07-13 09:54:32.303 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.340059 sec
2022-07-13 09:54:32.329 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.381034 sec
2022-07-13 09:54:32.331 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.384191 sec
2022-07-13 09:54:32.365 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.390816 sec
2022-07-13 09:54:32.367 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.394396 sec
2022-07-13 09:54:32.393 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.458491 sec
2022-07-13 09:54:32.396 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.461856 sec
2022-07-13 09:54:32.419 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.457652 sec
2022-07-13 09:54:32.421 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.460368 sec
2022-07-13 09:54:32.480 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.507334 sec
2022-07-13 09:54:32.481 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.510402 sec
2022-07-13 09:54:32.519 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.569053 sec
2022-07-13 09:54:32.521 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.571782 sec
2022-07-13 09:54:32.555 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.587162 sec
2022-07-13 09:54:32.558 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.590332 sec
2022-07-13 09:54:32.592 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:00.637019 sec
2022-07-13 09:54:32.595 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 0.640877 sec





2022-07-13 09:54:38.395 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.436821 sec
2022-07-13 09:54:38.396 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.439384 sec
2022-07-13 09:54:38.466 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.512065 sec
2022-07-13 09:54:38.468 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.515319 sec
2022-07-13 09:54:38.531 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.553081 sec
2022-07-13 09:54:38.533 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.556024 sec
2022-07-13 09:54:38.583 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.631171 sec
2022-07-13 09:54:38.585 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.634816 sec
2022-07-13 09:54:38.612 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.632594 sec
2022-07-13 09:54:38.614 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.635825 sec
2022-07-13 09:54:38.659 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.700147 sec
2022-07-13 09:54:38.661 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.703008 sec
2022-07-13 09:54:38.686 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.749487 sec
2022-07-13 09:54:38.688 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.753057 sec
2022-07-13 09:54:38.749 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.799416 sec
2022-07-13 09:54:38.750 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.801891 sec
2022-07-13 09:54:38.775 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.814294 sec
2022-07-13 09:54:38.776 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.817045 sec
2022-07-13 09:54:38.809 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:06.824674 sec
2022-07-13 09:54:38.811 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 6.827580 sec




2022-07-13 09:54:43.222 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:11.283620 sec
2022-07-13 09:54:43.224 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 11.287391 sec
2022-07-13 09:54:43.259 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:11.296450 sec
2022-07-13 09:54:43.261 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 11.299664 sec
2022-07-13 09:54:44.608 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.668820 sec
2022-07-13 09:54:44.610 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.672017 sec
2022-07-13 09:54:44.656 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.711311 sec
2022-07-13 09:54:44.658 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.714831 sec
2022-07-13 09:54:44.724 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.777329 sec
2022-07-13 09:54:44.725 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.780314 sec
2022-07-13 09:54:44.779 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.803660 sec
2022-07-13 09:54:44.781 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.806557 sec
2022-07-13 09:54:44.834 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.862764 sec
2022-07-13 09:54:44.836 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.865921 sec
2022-07-13 09:54:44.861 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.895232 sec
2022-07-13 09:54:44.864 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.899029 sec
2022-07-13 09:54:44.904 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:12.921001 sec
2022-07-13 09:54:44.906 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 12.924201 sec
2022-07-13 09:54:44.947 31706 INFO requests.sessions [-] send request {"connectionLimit": 1388} time elapse is 0:00:13.005864 sec
2022-07-13 09:54:44.949 31706 INFO f5.bigip.tm.ltm.virtual [-] method modify time elapse is 13.008865 sec
...

and the code is like this

                pool = eventlet.greenpool.GreenPool()
                for vs in vss:
                    try:
                        # vs.modify(connectionLimit=limit)
                        pool.spawn(vs.modify, connectionLimit=limit)
                        nums = pool.running()
                        waits = pool.waiting()
                        LOG.info("time elapse running green thread is %d" % nums)
                        LOG.info("time elapse waiting  green thread is %d" % waits)
                    except Exception as ex:
                        LOG.error(
                            "Fail to refresh virtual server %s"
                            " connection limit %s." % (vs.name, limit)
                        )

As the log above shows, there are 36 requests needed to be processed. all the 36 requests seem send out at once.

I also time the requests.sessions send method. it seems like every 10 requests responded as a batch, and each batch is about 6 seconds more latency than the previous batch.

At first, I think I am not monkeypatched my module, but I check the init.py file, and the eventlet monkeypatch is there.

I am a bit confused, it seems like non-blocking, but every 10 requests are responded to and blocked. Also, the poolmanager connection is 1000, it is much large than 10.

why the request is responded to in this way, anyone could give me a hint? is that possible my device problem?

------- update some information -------

As I mentioned, I change the poolmanager DEFAULT_POOLSIZE = 1000 which affects the value of pool_maxsize. Then I do a test again, I change the pool_maxsize to 1.

Although the log shows 2022-07-18 08:19:52.423 15412 WARNING requests.packages.urllib3.connectionpool [-] Connection pool is full, discarding connection: 100.123.73.244: Full, the process become faster.

It seems more efficient to rebuild connections to the device rather than maintain a pool of connections and reuse them.

class HTTPAdapter(BaseAdapter):
    """The built-in HTTP Adapter for urllib3.

    Provides a general-case interface for Requests sessions to contact HTTP and
    HTTPS urls by implementing the Transport Adapter interface. This class will
    usually be created by the :class:`Session <Session>` class under the
    covers.

    :param pool_connections: The number of urllib3 connection pools to cache.
    :param pool_maxsize: The maximum number of connections to save in the pool.
    :param max_retries: The maximum number of retries each connection
        should attempt. Note, this applies only to failed DNS lookups, socket
        connections and connection timeouts, never to requests where data has
        made it to the server. By default, Requests does not retry failed
        connections. If you need granular control over the conditions under
        which we retry a request, import urllib3's ``Retry`` class and pass
        that instead.
    :param pool_block: Whether the connection pool should block for connections.

    Usage::

      >>> import requests
      >>> s = requests.Session()
      >>> a = requests.adapters.HTTPAdapter(max_retries=3)
      >>> s.mount('http://', a)
    """
    __attrs__ = ['max_retries', 'config', '_pool_connections', '_pool_maxsize',
                 '_pool_block']

    def __init__(self, pool_connections=DEFAULT_POOLSIZE,
                 pool_maxsize=DEFAULT_POOLSIZE, max_retries=DEFAULT_RETRIES,
                 pool_block=DEFAULT_POOLBLOCK):
        pool_connections = 1
        # I change this pool_maxsize value from 1000 to 1
        # pool_maxsize = 1000
        pool_maxsize = 1
        if max_retries == DEFAULT_RETRIES:
            self.max_retries = Retry(0, read=False)
        else:
            self.max_retries = Retry.from_int(max_retries)
        self.config = {}
        self.proxy_manager = {}

        super(HTTPAdapter, self).__init__()

        self._pool_connections = pool_connections
        self._pool_maxsize = pool_maxsize
        self._pool_block = pool_block

        self.init_poolmanager(pool_connections, pool_maxsize, block=pool_block)

I am so curious why it behaves like this. is it F5 REST server problem or my code problem...

Pzhang
  • 193
  • 2
  • 14
  • 1
    Well, your device only has a certain number of CPUs. Once those CPUs are all working, nothing more can get dispatched until some of them finish. – Tim Roberts Jul 18 '22 at 05:13
  • Thanks for your hint @TimRoberts. I am going to have look and I will do more tests. I just updated some observations. I change the pool size of my connections (from 1000 to 1). It means only one connection will be reused, a new request needs to build a new connection to F5 bigip device. But it makes the process faster. I am totally lost since I know little about the device API server itself. – Pzhang Jul 18 '22 at 08:41
  • Yeah, that's the problem. There's an awful lot of this that is out of your control. Most major service providers do connection and bandwidth throttling to maintain quality of service and prevent DOS attacks. – Tim Roberts Jul 18 '22 at 17:56
  • Hello, @TimRoberts I do more tests and measure the time of each function. I find the latency, is related to every first connection of an unverified SSL (HTTPS) connection. It seems it takes a lot of time for unverified SSL connections (HTTPS). But I am still trying to find out why the F5 iControl device does unverified SSL connections very slow. – Pzhang Jul 21 '22 at 07:22

1 Answers1

0

I think I finally a find an answer to this historical question. I find this configuration of BigIP these days. It does have connection throttling just like the picture below.

enter image description here

Pzhang
  • 193
  • 2
  • 14