Forum Discussion

ipsi's avatar
ipsi
Occasional Contributor
16 years ago

[SOLVED] Load Test against local machine takes ~100ms to get connection, remo...

I'm just wondering if anyone has any insights into this. While it's probably a problem with the actual machine I'm testing against, I'm not entirely sure where to start looking to find out what's going wrong. Basically, when testing against my local machine, it takes < 100ms to go from 'notifying no-one' to 'getConfig', but when testing against a remote machine (on the same network), it takes roughly 700ms to do the same thing, which destroys the TPS.

Logs from my machine to my machine:

17:18:46,279 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,279 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,294 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,294 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,346 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,346 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,362 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,362 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,399 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,399 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,418 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,418 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,451 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,451 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,471 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,471 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,513 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,513 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,535 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,535 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,586 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,586 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,607 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,607 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,644 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,644 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,661 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,661 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,707 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,707 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,728 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,728 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,771 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,771 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,790 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,790 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,829 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,829 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,857 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,857 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:18:46,905 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://localhost:8181], timeout = 0
17:18:46,905 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,918 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://localhost:8181]
17:18:46,918 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads


From my machine to the remote machine:

17:16:57,616 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:16:57,616 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:57,675 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:57,675 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:16:58,394 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:16:58,400 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:58,461 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:58,461 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:16:59,163 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:16:59,164 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:59,223 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:59,223 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:16:59,894 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:16:59,894 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:59,987 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:16:59,987 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:00,647 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:00,648 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:00,706 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:00,706 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:01,513 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:01,523 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:01,582 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:01,582 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:02,348 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:02,348 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:02,420 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:02,420 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:03,181 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:03,188 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:03,257 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:03,257 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:03,941 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:03,942 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:04,033 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:04,034 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:04,758 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:04,765 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:04,827 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:04,827 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads
17:17:05,533 DEBUG [SoapUIMultiThreadedHttpConnectionManager] HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0
17:17:05,533 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Getting free connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:05,594 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Freeing connection, hostConfig=HostConfiguration[host=https://192.168.2.71:8181]
17:17:05,594 DEBUG [SoapUIMultiThreadedHttpConnectionManager] Notifying no-one, there are no waiting threads


Note the amount of time it takes to go from "Notifying no-one, there are no waiting threads" to "HttpConnectionManager.getConnection:  config = HostConfiguration[host=https://192.168.2.71:8181], timeout = 0"

This isn't the complete test, obviously, but it will hopefully give you some idea of what's going on. Now, the fact that it's taking some time to actually process the requests on the remote machine is fine - that should be fairly easy to deal with. What I don't understand is why it takes so long to go from one connection to the next.
  • ipsi's avatar
    ipsi
    Occasional Contributor
    16 years ago
    Increasing the amount of logging done, I find that all the time is spent here:

    18:10:18,634 DEBUG [DefaultHttpParams] Set parameter http.socket.timeout = 60000
    18:10:19,344 TRACE [PostMethod] enter PostMethod.clearRequestBody()


    Not entirely sure what goes on between the two, but that's what happens...

    I've also posted this issue to the HttpClient list, as it seems like this is happening there, and they can probably offer more help.

    Thanks,

    - ipsi
  • ipsi's avatar
    ipsi
    Occasional Contributor
    16 years ago
    According to the HttpClient folks, this is not a problem with that, and is more likely to be a problem with the way SOAP UI is using it. Still looking for any suggestions as to what could be going on here...
  • ipsi's avatar
    ipsi
    Occasional Contributor
    16 years ago
    SOLVED - as it turns out, someone (me) had decided sometime in the distant past (earlier this year) that a key size of 4096 bits was a good idea. Unfortunately, I hadn't checked to make sure each environment was using the same key at the same size.

    I changed the key to one that was only 1024 bits, and that made a *huge* difference. So there we go. If you're having performance issues, check your key size!