Moving one my script to JMeter (3.3) I noticed a significant timing difference for some requests (between JMeter and measurements / other tools). For example, here is what I see in Fiddler for one request: POST http://xxx:9000/epm/ui-rest/v1/requests/52ea978d-e94d-4d37-8d2d-5b9049bd2916/import HTTP/1.1 Host: xxx:9000 Connection: keep-alive Content-Length: 157 Accept: */* Origin: http://xxx:9000 Timezone: America/DenverX-Requested-With: XMLHttpRequest User-Agent: Mozilla/5.0 (Windows NT 6.3; Win64;x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36 Content-Type: application/json Referer: http://xxx:9000/epm/?root=workarea&workarea=view&id=ui-rest%2Fv1%2Fviews%2F4c819c71-4cb4-4498-ad2d-7c93a3ec6b7d Accept-Encoding:gzip, deflate Accept-Language: en-US,en;q=0.9 Cookie: EPM_Remote_User=b8e6T+U6DAXmDCZyx8WntMnvce/g39f2Di5KKPTe9yS2jvCmac6KM11weVtqKwEY; JSESSIONID=TZviFRa7mudww7e1LIFyialL8CIo6MZS2Nu9yjyw6AYUCObhMgCt!-236747468 {"fileUri": "http://xxx:9000/epm/ui-rest/v1/requests/52ea978d-e94d-4d37-8d2d-5b9049bd2916/attachments/importFile/b94d2b50-d529-4a01-afb9-2bfdd0d78a4f" } Request Count: 1 Bytes Sent: 950 (headers:793; body:157) Bytes Received: 7,065,667 (headers:550; body:7,065,117) ACTUAL PERFORMANCE-------------- ClientConnected: 15:06:58.147 ClientBeginRequest: 15:07:11.094 GotRequestHeaders: 15:07:11.094 ClientDoneRequest: 15:07:11.094 Determine Gateway: 16ms DNS Lookup: 0ms TCP/IP Connect: 0ms HTTPS Handshake: 0ms ServerConnected: 15:07:10.964 FiddlerBeginRequest: 15:07:11.095 ServerGotRequest: 15:07:11.095 ServerBeginResponse: 15:08:26.158 GotResponseHeaders: 15:08:26.158 ServerDoneResponse: 15:08:26.210 ClientBeginResponse: 15:08:26.222 ClientDoneResponse: 15:08:26.227 Overall Elapsed: 0:01:15.132 RESPONSE BYTES (by Content-Type)--------------application/json: 7,065,117 ~headers~: 550 and here is what I see in JMeter (from the same machine): POST http://xxx:9000/epm/ui-rest/v1/requests/b079bd62-4964-4adf-8564-d35ec33d0993/import POST data:{"fileUri": "http://xxx:9000/epm/ui-rest/v1/requests/b079bd62-4964-4adf- 8564-d35ec33d0993/attachments/importFile/5eb5f197-ebfb-4de1-8238-35ad0060d857" } Cookie Data: EPM_Remote_User=UngMo7mbHE9R5SdofArYMZO44fBaRL3QcmxFT6e5kmnPp0a5QV5IbXoJFJmVCCzf; JSESSIONID=7GHhvdbivYNGxwfwd2MPPbsoFpj3hzd5nGD4_nE1RjeaAx_TT1tG!-236747468 Request Headers:Connection: keep-alive Referer: http://xxx:9000/epm/?root=workarea&workarea=view&id=ui-rest%2Fv1%2Fviews%2F4c819c71-4cb4-4498-ad2d-7c93a3ec6b7d Accept-Language: en-US,en;q=0.5 Timezone: America/DenverX-Requested-With: XMLHttp RequestContent-Type: application/json Accept-Encoding: gzip, deflate User-Agent: Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:52.0) Gecko/20100101 Firefox/52.0 Accept: */* Content-Length: 157 Host: xxx:9000 Thread Name: Thread Group 1-1Sample Start: 2018-01-10 13:28:41 MST Load time: 37327 Connect Time: 0 Latency: 37272 Size in bytes: 7065667 Sent bytes:863 Headers size in bytes: 550 Body size in bytes: 7065117 Sample Count: 1 Error Count: 0 Data type ("text"|"bin"|""): text Response code: 200 Response message: OK Response headers:HTTP/1.1 200 OKCache-Control: no-cache, no-store, max-age=0, must-revalidateDate: Wed, 10 Jan 2018 20:28:41 GMTPragma: no-cacheTransfer-Encoding: chunkedContent-Type: application/jsonExpires: 0Access-Control-Allow-Methods: GET, POST, DELETE, PUT, PATCHP3P: X-CONTENT-TYPE-OPTIONS:nosniffX-XSS-Protection: 1; mode=blockAccess-Control-Allow-Headers: X-Requested-With, Content-TypeX-Content-Type-Options: nosniffAccess-Control-Allow-Origin: *Content-Language: en-USX-Powered-By: Servlet/2.5 JSP/2.1X-Frame-Options: DENY HTTPSampleResult fields:ContentType: application/jsonDataEncoding: null So in JMeter it takes 37 sec while in the real product (and another load testing tool) it takes ab. 75 sec. I see some difference in other requests too, but this one looks as a better example (my guess is that the difference becomes bigger for larger requests - and this one returns 7M). Everything inside a single data center, latency (ping) < 1 ms. Was posted to the user mail list http://mail-archives.apache.org/mod_mbox/jmeter-user/201801.mbox/%3C998028789.728908.1515623551353%40mail.yahoo.com%3E , but no real answer there - so it may be a bug.
Hello, Does you file contain an uploaded file ? What does the response look like ? Would it be possible to attach the fiddler response ? Thank you On Thu, Jan 25, 2018 at 5:21 PM, Alexander Podelko <apodelko@yahoo.com> wrote: Hi, 1. For example, in Fiddler - as specified below. 2. Oracle Application Testing Suite. No rendering, it is recording on protocol level. 3. 3.3 4. Only that in real browser / Fiddler I see different time - and that pretty much matching what I see in OATS. I understand that here we may have interesting subtle issues - but I'd like to understand what they are as difference is quite noticeable. Clearly timing issues are very difficult to investigate - but this looks like may be a good example to check if there is any issue with that. I will be happy to do whatever further measurement is needed. Thanks, Alex On Thursday, January 25, 2018, 11:00:40 AM EST, Philippe Mouawad <philippe.mouawad@gmail.com> wrote: Hello Alexander, Could you give more details on: 1/ How you measure response time in real product ? Is it a browser ? 2/ In the other tool you use ? what is used ? does it take into account Rendering ? 3/ which version of JMeter are you using ? 4/ IMU, JMeter measures shorter response time, so what makes you think it's the other tool that is correct ? JMeter only computes time to receive last byte not full rendering time, but if your tool has some Rendering that takes time it would not be measured and would explain the difference. Unless you provide more details , I am afraid it is hard to help. Regards
Created attachment 35701 [details] Fiddler session including that request (../import)
Hello, Thanks. 1/ Did you set this property, I don't think so but double checking: - httpsampler.max_bytes_to_store_per_request 2/ What is the read buffer used by your application or 3/ Is the response time of this request constant ? Isn't it possible that by chance it was faster for JMeter and less for fiddler It seems you didn't record it at the same time 4/ Is this difference constant accross multiple runs ?
No, I didn't change that parameter: # Max size of bytes stored in memory per SampleResult # Ensure you don't exceed max capacity of a Java Array and remember # that the higher it is, the higher JMeter will consume heap # Defaults to 0, which means no truncation #httpsampler.max_bytes_to_store_per_request=0 Not sure what read buffer you are asking about - could you please elaborate? There is some variability between runs, but it is very small comparing to the difference between JMeter and Fiddler. And yes, it remains constant - I am running tests tests with each build. All happens inside one data center, so latency is <1ms.
(In reply to Alex Podelko from comment #4) > No, I didn't change that parameter: > > # Max size of bytes stored in memory per SampleResult > # Ensure you don't exceed max capacity of a Java Array and remember > # that the higher it is, the higher JMeter will consume heap > # Defaults to 0, which means no truncation > #httpsampler.max_bytes_to_store_per_request=0 > > Not sure what read buffer you are asking about - could you please elaborate? I am looking into a reason that would explain the difference. For now I see no reason. I was thinking about a difference in read buffer between JMeter and other tools when reading the response. > > There is some variability between runs, but it is very small comparing to > the difference between JMeter and Fiddler. And yes, it remains constant - I > am running tests tests with each build. All happens inside one data center, > so latency is <1ms. On how much runs do you see this difference ? Did you compute a percentile 90 for both tools for 1000 measurements for example ?
Even in JMeter it takes 37 sec - while in real life it takes 75 sec. There are few second variations, but overall the ratio is rather stable. Even if forget about time to do it repeatable - it is a part of the process and it creates a large number of entries. Doing that many times in a loop will create other performance issues in the system. That large request is specified more for example - because the difference is so large and evident that you can't ignore / misinterpret it. In most cases I use smaller requests in tests - where we still have the difference, but it is smaller.
(In reply to Alex Podelko from comment #6) > Even in JMeter it takes 37 sec - while in real life it takes 75 sec. There > are few second variations, but overall the ratio is rather stable. > > Even if forget about time to do it repeatable - it is a part of the process > and it creates a large number of entries. Doing that many times in a loop > will create other performance issues in the system. > > That large request is specified more for example - because the difference is > so large and evident that you can't ignore / misinterpret it. Ok, but in my experience, I have faced applications that were very unstable in terms of response time for the same request (not under load, but really during scripting/recording) but ran at different timings. That's why I was asking for this particularly because the logs you attach show that you ran them at very different timings: - 15h08 - 13h28 Can you attach your jmeter.log and the gc.log after uncommenting in jmeter.bat this part: set VERBOSE_GC=-verbose:gc -Xloggc:gc_jmeter_%%p.log -XX:+PrintGCDetails -XX:+PrintGCCause -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintAdaptiveSizePolicy > > In most cases I use smaller requests in tests - where we still have the > difference, but it is smaller. Frankly I have no idea of what is happening and it is very difficult to figure out without have the application available.
Any feedback on this ? Thanks
There were some changes in product, but the ratio is still somewhat hold. Fiddler 69 sec: POST /epm/ui-rest/v1/requests/67841168-5d29-4950-9c29-9af063a1f67a/import Request Count: 1 Bytes Sent: 868 (headers:711; body:157) Bytes Received: 7,065,667 (headers:550; body:7,065,117) ACTUAL PERFORMANCE -------------- ClientConnected: 10:42:59.074 ClientBeginRequest: 10:42:59.130 GotRequestHeaders: 10:42:59.130 ClientDoneRequest: 10:42:59.131 Determine Gateway: 0ms DNS Lookup: 0ms TCP/IP Connect: 0ms HTTPS Handshake: 0ms ServerConnected: 10:42:59.083 FiddlerBeginRequest: 10:42:59.131 ServerGotRequest: 10:42:59.131 ServerBeginResponse: 10:44:08.251 GotResponseHeaders: 10:44:08.251 ServerDoneResponse: 10:44:08.307 ClientBeginResponse: 10:44:08.311 ClientDoneResponse: 10:44:08.313 Overall Elapsed: 0:01:09.183 RESPONSE BYTES (by Content-Type) -------------- application/json: 7,065,117 ~headers~: 550 Jemeter 45 sec Thread Name: Thread Group 1-1 Sample Start: 2018-02-07 10:56:57 MST Load time: 45315 Connect Time: 0 Latency: 45252 Size in bytes: 7065667 Sent bytes:863 Headers size in bytes: 550 Body size in bytes: 7065117 Sample Count: 1 Error Count: 0 Data type ("text"|"bin"|""): text Response code: 200 Response message: OK Response headers: HTTP/1.1 200 OK Cache-Control: no-cache, no-store, max-age=0, must-revalidate Date: Wed, 07 Feb 2018 17:56:57 GMT Pragma: no-cache Transfer-Encoding: chunked Content-Type: application/json Expires: 0 Access-Control-Allow-Methods: GET, POST, DELETE, PUT, PATCH P3P: X-CONTENT-TYPE-OPTIONS:nosniff X-XSS-Protection: 1; mode=block Access-Control-Allow-Headers: X-Requested-With, Content-Type X-Content-Type-Options: nosniff Access-Control-Allow-Origin: * Content-Language: en-US X-Powered-By: Servlet/2.5 JSP/2.1 X-Frame-Options: DENY HTTPSampleResult fields: ContentType: application/json DataEncoding: null POST http://xxx:9000/epm/ui-rest/v1/requests/3ee9025d-761d-4557-b6df-7760a3ef07ac/import POST data: {"fileUri": "http://xxx:9000/epm/ui-rest/v1/requests/3ee9025d-761d-4557-b6df-7760a3ef07ac/attachments/importFile/7e0030de-cf2e-4be5-9fd4-e3cfac637082" } Cookie Data: EPM_Remote_User=pXpYvDEtl2VtSKJSuJW4X3oQVc+2XQjZ+SKT6I25aOB7QJyKMMm+eC0RSbNAJFqB; JSESSIONID=cJtxZ1oncdI2akQg9IXEK0gz6Pl_4lECPhYv3b49xIz_fMRnPns0!-348502596 Request Headers: Connection: keep-alive Referer: http://xxx:9000/epm/?root=workarea&workarea=view&id=ui-rest%2Fv1%2Fviews%2F4c819c71-4cb4-4498-ad2d-7c93a3ec6b7d Accept-Language: en-US,en;q=0.5 Timezone: America/Denver X-Requested-With: XMLHttpRequest Content-Type: application/json Accept-Encoding: gzip, deflate User-Agent: Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:52.0) Gecko/20100101 Firefox/52.0 Accept: */* Content-Length: 157
Created attachment 35717 [details] Jmeter log
Created attachment 35718 [details] gc log
Created attachment 35719 [details] jmeter log
Created attachment 35720 [details] new Fiddler session
Hello, Getting back to this, did you check server logs to see how much time the server took to handle the request ? Thank you
This issue has been migrated to GitHub: https://github.com/apache/jmeter/issues/4678