Open asfimport opened 6 years ago
@pmouawad (migrated from Bugzilla): 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
Alex Podelko (migrated from Bugzilla): Created attachment Jmeter_timimg_10k_1.saz: Fiddler session including that request (../import)
@pmouawad (migrated from Bugzilla): Hello, Thanks. 1/ Did you set this property, I don't think so but double checking:
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 ?
Alex Podelko (migrated from Bugzilla): No, I didn't change that parameter:
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.
@pmouawad (migrated from Bugzilla): (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 ?
Alex Podelko (migrated from Bugzilla): 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.
@pmouawad (migrated from Bugzilla): (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:
Can you attach your jmeter.log and the gc.log after uncommenting in jmeter.bat this part: set VERBOSE_GC=-verbose:gc -Xloggc:gcjmeter%%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.
@pmouawad (migrated from Bugzilla): Any feedback on this ? Thanks
Alex Podelko (migrated from Bugzilla): 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)
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
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
Alex Podelko (migrated from Bugzilla): Created attachment jmeter.log: Jmeter log
Alex Podelko (migrated from Bugzilla): Created attachment gc_jmeter_pid4668.log: gc log
Alex Podelko (migrated from Bugzilla): Created attachment jmeter.log: jmeter log
Alex Podelko (migrated from Bugzilla): Created attachment 1804279_10k_request_cust1.saz: new Fiddler session
@pmouawad (migrated from Bugzilla): Hello, Getting back to this, did you check server logs to see how much time the server took to handle the request ?
Thank you
Alex Podelko (Bug 62045): 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.
Severity: normal OS: All