Forum Discussion

MP9922's avatar
MP9922
New Contributor
2 years ago

ReadyAPI is slow and busy closing expired connections

I am currently expieriencing my ReadyAPI (3.43.1) to be slow when navigating the GUI. After setting the loglevel to trace, i found that it is constantly trying to close some connections (all 5 seconds) and requesting something from optimizely. Is this the normal behaviour or does this cause my performance issues?

 

 

Also when running my tests in parallel with the testrunner I sometimes experience the process not finishing (my test pipeline times out). The only logs that still come in are the same:

 

13:36:02,874 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Closing connections idle longer than 30 SECONDS
13:36:07,878 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Closing expired connections
 
2023-02-17T11:49:27.4234035Z 12:49:27,419 DEBUG [HttpProjectConfigManager] Fetching datafile from: https://cdn.optimizely.com/datafiles/RTy3UXWtsK7jBQs1NxwdT.json
2023-02-17T11:49:27.4250735Z 12:49:27,422 DEBUG [RequestAuthCache] Auth cache not set in the context
2023-02-17T11:49:27.4271164Z 12:49:27,422 DEBUG [RequestAuthCache] Auth cache not set in the context
2023-02-17T11:49:27.4295211Z 12:49:27,426 DEBUG [PoolingHttpClientConnectionManager] Connection request: [route: {s}->https://cdn.optimizely.com:443][total kept alive: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2023-02-17T11:49:27.4331841Z 12:49:27,430 DEBUG [wire] http-outgoing-0 << "[read] I/O error: Read timed out"
2023-02-17T11:49:27.4356149Z 12:49:27,432 DEBUG [PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {s}->https://cdn.optimizely.com:443][total kept alive: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2023-02-17T11:49:27.4374260Z 12:49:27,434 DEBUG [DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 10000
2023-02-17T11:49:27.4386151Z 12:49:27,436 DEBUG [MainClientExec] Executing request GET /datafiles/RTy3UXWtsK7jBQs1NxwdT.json HTTP/1.1
2023-02-17T11:49:27.4402091Z 12:49:27,437 DEBUG [MainClientExec] Target auth state: UNCHALLENGED
2023-02-17T11:49:27.4413226Z 12:49:27,439 DEBUG [MainClientExec] Proxy auth state: UNCHALLENGED
2023-02-17T11:49:27.4430166Z 12:49:27,440 DEBUG [headers] http-outgoing-0 >> GET /datafiles/RTy3UXWtsK7jBQs1NxwdT.json HTTP/1.1
2023-02-17T11:49:27.4440746Z 12:49:27,442 DEBUG [headers] http-outgoing-0 >> If-Modified-Since: Wed, 06 Jul 2022 22:48:48 GMT
2023-02-17T11:49:27.4456843Z 12:49:27,443 DEBUG [headers] http-outgoing-0 >> Host: cdn.optimizely.com
2023-02-17T11:49:27.4468304Z 12:49:27,444 DEBUG [headers] http-outgoing-0 >> Connection: Keep-Alive
2023-02-17T11:49:27.4476801Z 12:49:27,445 DEBUG [headers] http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.2 (Java/17.0.5)
2023-02-17T11:49:27.4484522Z 12:49:27,446 DEBUG [headers] http-outgoing-0 >> Accept-Encoding: gzip,deflate
2023-02-17T11:49:27.4493936Z 12:49:27,447 DEBUG [wire] http-outgoing-0 >> "GET /datafiles/RTy3UXWtsK7jBQs1NxwdT.json HTTP/1.1[\r][\n]"
2023-02-17T11:49:27.4504162Z 12:49:27,448 DEBUG [wire] http-outgoing-0 >> "If-Modified-Since: Wed, 06 Jul 2022 22:48:48 GMT[\r][\n]"
2023-02-17T11:49:27.4511785Z 12:49:27,449 DEBUG [wire] http-outgoing-0 >> "Host: cdn.optimizely.com[\r][\n]"
2023-02-17T11:49:27.4521179Z 12:49:27,450 DEBUG [wire] http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
2023-02-17T11:49:27.4530261Z 12:49:27,451 DEBUG [wire] http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/17.0.5)[\r][\n]"
2023-02-17T11:49:27.4538564Z 12:49:27,452 DEBUG [wire] http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
2023-02-17T11:49:27.4549865Z 12:49:27,453 DEBUG [wire] http-outgoing-0 >> "[\r][\n]"
2023-02-17T11:49:27.4827457Z 12:49:27,480 DEBUG [wire] http-outgoing-0 << "HTTP/1.1 304 Not Modified[\r][\n]"
2023-02-17T11:49:27.4845634Z 12:49:27,481 DEBUG [wire] http-outgoing-0 << "Content-Type: application/json; charset=utf-8[\r][\n]"
2023-02-17T11:49:27.4855325Z 12:49:27,483 DEBUG [wire] http-outgoing-0 << "Last-Modified: Wed, 06 Jul 2022 22:48:48 GMT[\r][\n]"
2023-02-17T11:49:27.4868367Z 12:49:27,484 DEBUG [wire] http-outgoing-0 << "ETag: "e79f271fa7b677ce97677ee20d9e3d01"[\r][\n]"
2023-02-17T11:49:27.4876682Z 12:49:27,486 DEBUG [wire] http-outgoing-0 << "Cache-Control: max-age=118[\r][\n]"
2023-02-17T11:49:27.4885157Z 12:49:27,487 DEBUG [wire] http-outgoing-0 << "Date: Fri, 17 Feb 2023 11:49:27 GMT[\r][\n]"
2023-02-17T11:49:27.4893240Z 12:49:27,487 DEBUG [wire] http-outgoing-0 << "Connection: keep-alive[\r][\n]"
2023-02-17T11:49:27.4902575Z 12:49:27,488 DEBUG [wire] http-outgoing-0 << "Server-Timing: cdn-cache; desc=HIT[\r][\n]"
2023-02-17T11:49:27.4913571Z 12:49:27,489 DEBUG [wire] http-outgoing-0 << "Server-Timing: edge; dur=4[\r][\n]"
2023-02-17T11:49:27.4922560Z 12:49:27,490 DEBUG [wire] http-outgoing-0 << "Server-Timing: cdn;desc="AkamaiION";dur=0,rtt;desc="579";dur=0,cdnip;desc="23.206.208.144";dur=0,cdnmap;desc="a5048.dsca.akamaiedge.net";dur=0,proto;desc="";dur=0[\r][\n]"
2023-02-17T11:49:27.4930634Z 12:49:27,491 DEBUG [wire] http-outgoing-0 << "Access-Control-Max-Age: 604800[\r][\n]"
2023-02-17T11:49:27.4938277Z 12:49:27,492 DEBUG [wire] http-outgoing-0 << "Access-Control-Allow-Credentials: false[\r][\n]"
2023-02-17T11:49:27.4947802Z 12:49:27,493 DEBUG [wire] http-outgoing-0 << "Access-Control-Allow-Headers: *[\r][\n]"
2023-02-17T11:49:27.4956578Z 12:49:27,494 DEBUG [wire] http-outgoing-0 << "Access-Control-Allow-Methods: GET, HEAD, OPTIONS[\r][\n]"
2023-02-17T11:49:27.4963801Z 12:49:27,494 DEBUG [wire] http-outgoing-0 << "Access-Control-Allow-Origin: *[\r][\n]"
2023-02-17T11:49:27.4973112Z 12:49:27,495 DEBUG [wire] http-outgoing-0 << "Strict-Transport-Security: max-age=15768000[\r][\n]"
2023-02-17T11:49:27.4980300Z 12:49:27,496 DEBUG [wire] http-outgoing-0 << "[\r][\n]"
2023-02-17T11:49:27.4989369Z 12:49:27,497 DEBUG [headers] http-outgoing-0 << HTTP/1.1 304 Not Modified
2023-02-17T11:49:27.4996717Z 12:49:27,498 DEBUG [headers] http-outgoing-0 << Content-Type: application/json; charset=utf-8
2023-02-17T11:49:27.5003203Z 12:49:27,498 DEBUG [headers] http-outgoing-0 << Last-Modified: Wed, 06 Jul 2022 22:48:48 GMT
2023-02-17T11:49:27.5010279Z 12:49:27,499 DEBUG [headers] http-outgoing-0 << ETag: "e79f271fa7b677ce97677ee20d9e3d01"
2023-02-17T11:49:27.5018634Z 12:49:27,500 DEBUG [headers] http-outgoing-0 << Cache-Control: max-age=118
2023-02-17T11:49:27.5026255Z 12:49:27,501 DEBUG [headers] http-outgoing-0 << Date: Fri, 17 Feb 2023 11:49:27 GMT
2023-02-17T11:49:27.5032095Z 12:49:27,501 DEBUG [headers] http-outgoing-0 << Connection: keep-alive
2023-02-17T11:49:27.5040012Z 12:49:27,502 DEBUG [headers] http-outgoing-0 << Server-Timing: cdn-cache; desc=HIT
2023-02-17T11:49:27.5046888Z 12:49:27,503 DEBUG [headers] http-outgoing-0 << Server-Timing: edge; dur=4
2023-02-17T11:49:27.5056722Z 12:49:27,503 DEBUG [headers] http-outgoing-0 << Server-Timing: cdn;desc="AkamaiION";dur=0,rtt;desc="579";dur=0,cdnip;desc="23.206.208.144";dur=0,cdnmap;desc="a5048.dsca.akamaiedge.net";dur=0,proto;desc="";dur=0
2023-02-17T11:49:27.5061211Z 12:49:27,504 DEBUG [headers] http-outgoing-0 << Access-Control-Max-Age: 604800
2023-02-17T11:49:27.5105792Z 12:49:27,505 DEBUG [headers] http-outgoing-0 << Access-Control-Allow-Credentials: false
2023-02-17T11:49:27.5108765Z 12:49:27,506 DEBUG [headers] http-outgoing-0 << Access-Control-Allow-Headers: *
2023-02-17T11:49:27.5109898Z 12:49:27,506 DEBUG [headers] http-outgoing-0 << Access-Control-Allow-Methods: GET, HEAD, OPTIONS
2023-02-17T11:49:27.5111317Z 12:49:27,507 DEBUG [headers] http-outgoing-0 << Access-Control-Allow-Origin: *
2023-02-17T11:49:27.5112244Z 12:49:27,508 DEBUG [headers] http-outgoing-0 << Strict-Transport-Security: max-age=15768000
2023-02-17T11:49:27.5113110Z 12:49:27,508 DEBUG [MainClientExec] Connection can be kept alive indefinitely
2023-02-17T11:49:27.5114365Z 12:49:27,509 DEBUG [PoolingHttpClientConnectionManager] Connection [id: 0][route: {s}->https://cdn.optimizely.com:443] can be kept alive indefinitely
2023-02-17T11:49:27.5117398Z 12:49:27,510 DEBUG [PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {s}->https://cdn.optimizely.com:443][total kept alive: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2023-02-17T11:49:27.5127138Z 12:49:27,511 DEBUG [HttpProjectConfigManager] Not updating ProjectConfig as datafile has not updated since Wed, 06 Jul 2022 22:48:48 GMT

 

1 Reply

  • wpballard's avatar
    wpballard
    Frequent Visitor

    I'm having a similar error with 3.45.0 except the test is failing to execute through Jenkins build. 

    It's making a call to https://cdn.optimizely.com/datafiles/RTy3UXWtsK7jBQs1NxwdT.json which is failing with the message 

    // This Optimizely project has been deactivated. Visit app.optimizely.com to activate it.

    This isn't our fault. Smartbear needs to fix it. 

    The bug fixes posted in 3.40.0 stated

    • ReadyAPI Maven plug-in no longer tries to connect to Optimizely when it is disabled. (RIA-19028)

    So how do I disable the call to Optimizely at runtime?