Attachment 34725 Details for Bug 60682 – log from nightly build

log from nightly build

jmeter.log (text/plain), 75.25 KB, created by Amar on 2017-02-06 21:16:08 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Amar

Created: 2017-02-06 21:16:08 UTC

Size: 75.25 KB

patch

obsolete

>2017-02-06 21:10:35,127 INFO o.a.j.u.JMeterUtils: Setting Locale to en_IE
>2017-02-06 21:10:35,136 INFO o.a.j.JMeter: Loading user properties from: /Users/Amar/Downloads/apache-jmeter-r1781918/bin/user.properties
>2017-02-06 21:10:35,137 INFO o.a.j.JMeter: Loading system properties from: /Users/Amar/Downloads/apache-jmeter-r1781918/bin/system.properties
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: Copyright (c) 1998-2017 The Apache Software Foundation
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: Version r1781918
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: java.version=1.8.0_112
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: java.vm.name=Java HotSpot(TM) 64-Bit Server VM
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: os.name=Mac OS X
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: os.arch=x86_64
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: os.version=10.12.3
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: file.encoding=UTF-8
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: Max memory     =3817865216
>2017-02-06 21:10:35,192 INFO o.a.j.JMeter: Available Processors =8
>2017-02-06 21:10:35,198 INFO o.a.j.JMeter: Default Locale=English (Ireland)
>2017-02-06 21:10:35,198 INFO o.a.j.JMeter: JMeter  Locale=English (Ireland)
>2017-02-06 21:10:35,198 INFO o.a.j.JMeter: JMeterHome=/Users/Amar/Downloads/apache-jmeter-r1781918
>2017-02-06 21:10:35,198 INFO o.a.j.JMeter: user.dir  =/Users/Amar/Downloads/apache-jmeter-r1781918/bin
>2017-02-06 21:10:35,198 INFO o.a.j.JMeter: PWD       =/Users/Amar/Downloads/apache-jmeter-r1781918/bin
>2017-02-06 21:10:40,206 INFO o.a.j.JMeter: IP: 192.168.0.13 Name: Amarendras-MacBook-Pro-2.local FullName: 192.168.0.13
>2017-02-06 21:10:42,191 INFO o.a.j.g.a.LookAndFeelCommand: Using look and feel: com.apple.laf.AquaLookAndFeel [Mac OS X, System]
>2017-02-06 21:10:42,193 INFO o.a.j.JMeter: Loaded icon properties from org/apache/jmeter/images/icon.properties
>2017-02-06 21:10:42,606 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must contain the string: '.functions.'
>2017-02-06 21:10:42,606 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must not contain the string: '.gui.'
>2017-02-06 21:10:43,014 WARN o.a.j.g.u.JMeterToolBar: No definition for toolbar entry: close
>2017-02-06 21:10:43,295 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.assertions.BSFAssertion
>2017-02-06 21:10:43,641 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.extractor.BSFPostProcessor
>2017-02-06 21:10:43,665 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.modifiers.BSFPreProcessor
>2017-02-06 21:10:43,684 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
>2017-02-06 21:10:43,685 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
>2017-02-06 21:10:43,685 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
>2017-02-06 21:10:43,685 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
>2017-02-06 21:10:43,685 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser
>2017-02-06 21:10:43,685 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser
>2017-02-06 21:10:43,715 DEBUG o.a.j.p.h.c.g.HttpMirrorControlGui: Creating HttpMirrorControlGui
>2017-02-06 21:10:43,728 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.protocol.http.control.gui.SoapSamplerGui
>2017-02-06 21:10:43,792 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Creating ProxyControlGui
>2017-02-06 21:10:43,966 INFO o.a.j.e.KeyToolUtils: keytool found at 'keytool'
>2017-02-06 21:10:43,967 INFO o.a.j.p.h.p.ProxyControl: HTTP(S) Test Script Recorder SSL Proxy will use keys that support embedded 3rd party resources in file /Users/Amar/Downloads/apache-jmeter-r1781918/bin/proxyserver.jks
>2017-02-06 21:10:43,980 DEBUG o.a.j.p.h.s.AccessLogSamplerBeanInfo: Entered access log sampler bean info
>2017-02-06 21:10:43,984 DEBUG o.a.j.p.h.s.AccessLogSamplerBeanInfo: found parsers: [org.apache.jmeter.protocol.http.util.accesslog.OrderPreservingLogParser, org.apache.jmeter.protocol.http.util.accesslog.SharedTCLogParser, org.apache.jmeter.protocol.http.util.accesslog.TCLogParser]
>2017-02-06 21:10:43,988 DEBUG o.a.j.p.h.s.AccessLogSamplerBeanInfo: Got to end of access log samper bean info init
>2017-02-06 21:10:44,022 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.protocol.java.sampler.BSFSampler
>2017-02-06 21:10:44,088 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.protocol.mongodb.config.MongoSourceElement
>2017-02-06 21:10:44,088 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.protocol.mongodb.sampler.MongoScriptSampler
>2017-02-06 21:10:44,170 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.timers.BSFTimer
>2017-02-06 21:10:44,188 INFO o.a.j.g.u.MenuFactory: Skipping org.apache.jmeter.visualizers.BSFListener
>2017-02-06 21:10:44,273 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times
>2017-02-06 21:10:44,273 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to ISO-8859-1
>2017-02-06 21:10:44,274 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true
>2017-02-06 21:10:44,274 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000
>2017-02-06 21:12:13,344 INFO o.a.j.s.FileServer: Default base='/Users/Amar/Downloads/apache-jmeter-r1781918/bin'
>2017-02-06 21:12:13,345 INFO o.a.j.g.a.Load: Loading file: /Users/Amar/mySA/test/load/GetAPIs.jmx
>2017-02-06 21:12:13,345 INFO o.a.j.s.FileServer: Set new base='/Users/Amar/mySA/test/load'
>2017-02-06 21:12:13,433 INFO o.a.j.s.SaveService: Testplan (JMX) version: 2.2. Testlog (JTL) version: 2.2
>2017-02-06 21:12:13,447 INFO o.a.j.s.SaveService: Using SaveService properties file encoding UTF-8
>2017-02-06 21:12:13,450 INFO o.a.j.s.SaveService: Using SaveService properties version 3.2
>2017-02-06 21:12:13,450 INFO o.a.j.s.SaveService: Loading file: /Users/Amar/mySA/test/load/GetAPIs.jmx
>2017-02-06 21:12:13,471 INFO o.a.j.p.h.c.CookieManager: Settings: Delete null: true Check: true Allow variable: true Save: false Prefix: COOKIE_
>2017-02-06 21:12:13,471 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:12:13,544 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:12:13,633 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Creating ProxyControlGui
>2017-02-06 21:12:13,637 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Configuring gui with org.apache.jmeter.protocol.http.proxy.ProxyControl@1bc893f6
>2017-02-06 21:12:13,638 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Reinitializing target combo
>2017-02-06 21:12:13,638 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Selecting item Use Recording Controller for model org.apache.jmeter.protocol.http.proxy.ProxyControl@1bc893f6 in org.apache.jmeter.protocol.http.proxy.gui.ProxyControlGui[HTTP(S) Test Script Recorder,0,0,0x0,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=javax.swing.border.EmptyBorder@47dc6f13,flags=9,maximumSize=,minimumSize=,preferredSize=]
>2017-02-06 21:12:13,638 DEBUG o.a.j.p.h.p.g.ProxyControlGui: Reinitialization complete
>2017-02-06 21:12:13,658 INFO o.a.j.s.FileServer: Set new base='/Users/Amar/mySA/test/load'
>2017-02-06 21:12:13,709 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:13:10,629 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:13:10,636 INFO o.a.j.e.StandardJMeterEngine: Running the test!
>2017-02-06 21:13:10,636 INFO o.a.j.s.SampleEvent: List of sample_variables: []
>2017-02-06 21:13:10,636 INFO o.a.j.s.SampleEvent: List of sample_variables: []
>2017-02-06 21:13:10,639 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:13:10,649 DEBUG o.a.j.p.h.c.CookieManager: Policy: compatibility Clear: false
>2017-02-06 21:13:10,651 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true,*local*)
>2017-02-06 21:13:10,757 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Main test thread
>2017-02-06 21:13:10,757 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Main test thread.
>2017-02-06 21:13:10,757 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
>2017-02-06 21:13:10,757 INFO o.a.j.t.ThreadGroup: Starting thread group number 1 threads 1 ramp-up 1 perThread 1000.0 delayedStart=false
>2017-02-06 21:13:10,759 DEBUG o.a.j.p.h.c.CookieManager: Clear all cookies from store
>2017-02-06 21:13:10,765 INFO o.a.j.t.ThreadGroup: Started thread group number 1
>2017-02-06 21:13:10,765 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
>2017-02-06 21:13:10,767 INFO o.a.j.t.JMeterThread: Thread started: Main test thread 1-1
>2017-02-06 21:13:10,769 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Existing HeaderManager 'HTTP Header Manager' merged with 'HTTP Header Manager:HTTP Header Manager'
>2017-02-06 21:13:10,769 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Content-Type=application/json
>2017-02-06 21:13:10,769 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Cache-Control=no-cache
>2017-02-06 21:13:10,769 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Accept=application/json
>2017-02-06 21:13:10,779 INFO o.a.j.p.h.s.HTTPHCAbstractImpl: Local host = Amarendras-MacBook-Pro-2.local
>2017-02-06 21:13:10,784 INFO o.a.j.p.h.s.HTTPHC4Impl: HTTP request retry count = 0
>2017-02-06 21:13:10,792 DEBUG o.a.j.p.h.s.HTTPHC4Impl: notifyFirstSampleAfterLoopRestart
>2017-02-06 21:13:10,792 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:10,792 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method GET followingRedirect false depth 0
>2017-02-06 21:13:10,809 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Created new HttpClient: @1233359 https://prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:10,812 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 0 cookies for https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:10,812 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Storing in HttpContext the user token:Main test thread 1-1
>2017-02-06 21:13:10,840 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>2017-02-06 21:13:10,850 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:11,004 INFO o.a.j.p.h.s.LazySchemeSocketFactory: Setting up HTTPS TrustAll Socket Factory
>2017-02-06 21:13:11,011 INFO o.a.j.u.JsseSSLManager: Using default SSL protocol: TLS
>2017-02-06 21:13:11,011 INFO o.a.j.u.JsseSSLManager: SSL session context: per-thread
>2017-02-06 21:13:11,171 INFO o.a.j.u.SSLManager: JmeterKeyStore Location:  type JKS
>2017-02-06 21:13:11,172 INFO o.a.j.u.SSLManager: KeyStore created OK
>2017-02-06 21:13:11,172 WARN o.a.j.u.SSLManager: Keystore file not found, loading empty keystore
>2017-02-06 21:13:11,198 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator: Connecting to prepiam.toronto.ca.ibm.com:443
>2017-02-06 21:13:11,859 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:11,860 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:11,860 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:11,861 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:11,861 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:11,861 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: GET /idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser HTTP/1.1
>2017-02-06 21:13:11,861 DEBUG o.a.h.wire:  >> "GET /idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser HTTP/1.1[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Content-Length: 0[\r][\n]"
>2017-02-06 21:13:11,862 DEBUG o.a.h.wire:  >> "Host: prepiam.toronto.ca.ibm.com[\r][\n]"
>2017-02-06 21:13:11,863 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:11,863 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> GET /idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser HTTP/1.1
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Content-Type: application/json
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Content-Length: 0
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> Host: prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:11,863 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:12,158 DEBUG o.a.h.wire:  << "HTTP/1.1 200 OK[\r][\n]"
>2017-02-06 21:13:12,161 DEBUG o.a.h.wire:  << "X-Backside-Transport: OK OK[\r][\n]"
>2017-02-06 21:13:12,161 DEBUG o.a.h.wire:  << "Content-Language: en-US[\r][\n]"
>2017-02-06 21:13:12,161 DEBUG o.a.h.wire:  << "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:12,161 DEBUG o.a.h.wire:  << "p3p: CP="NON CUR OTPi OUR NOR UNI"[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "x-frame-options: SAMEORIGIN[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Cache-Control: no-cache,max-age=0,                             no-cache, no-store, max-age=0, must-revalidate[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Expires: Thu, 01 Dec 1994 16:00:00 GMT,                             0[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "content-security-policy: frame-ancestors 'self'[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "strict-transport-security: max-age=31536000; includeSubDomains[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Pragma: no-cache[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "X-Client-IP: 184.51.147.10[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 1149532513[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Content-Length: 241[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:12 GMT[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Set-Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; Path=/idaas/; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Set-Cookie: PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; Path=/[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Set-Cookie: PD-S-SESSION-ID=1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc; Path=/; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,162 DEBUG o.a.h.wire:  << "Set-Cookie: DPJSESSIONID=PBC5YS:123972063; Path=/; Domain=.prepiam.toronto.ca.ibm.com; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,163 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:12,163 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 200 OK
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << HTTP/1.1 200 OK
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << X-Backside-Transport: OK OK
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << Content-Language: en-US
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << Content-Type: application/json
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << p3p: CP="NON CUR OTPi OUR NOR UNI"
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << x-frame-options: SAMEORIGIN
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << Cache-Control: no-cache,max-age=0,                             no-cache, no-store, max-age=0, must-revalidate
>2017-02-06 21:13:12,163 DEBUG o.a.h.headers: << Expires: Thu, 01 Dec 1994 16:00:00 GMT,                             0
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << content-security-policy: frame-ancestors 'self'
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << strict-transport-security: max-age=31536000; includeSubDomains
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Pragma: no-cache
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << X-Client-IP: 184.51.147.10
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 1149532513
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Content-Length: 241
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:12 GMT
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Connection: keep-alive
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Set-Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; Path=/idaas/; Secure; HttpOnly
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Set-Cookie: PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; Path=/
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Set-Cookie: PD-S-SESSION-ID=1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc; Path=/; Secure; HttpOnly
>2017-02-06 21:13:12,164 DEBUG o.a.h.headers: << Set-Cookie: DPJSESSIONID=PBC5YS:123972063; Path=/; Domain=.prepiam.toronto.ca.ibm.com; Secure; HttpOnly
>2017-02-06 21:13:12,167 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:12,171 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:12,171 DEBUG o.a.h.wire:  << "{"execptionMsg":"NA","location":"/idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5","state":"6afbf328-bf46-4d88-9a06-6651204d16a5","message":"","mechanism":"urn:ibm:security:authentication:asf:mechanism:basicldapuser"}"
>2017-02-06 21:13:12,171 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:12,172 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,172 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=1045 Content-Length=241 Total=1286
>2017-02-06 21:13:12,172 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; Path=/idaas/; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/idaas/	TRUE	0	JSESSIONID	00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; Path=/ From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/	FALSE	0	PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc	%2Fidaas
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: PD-S-SESSION-ID=1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc; Path=/; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/	TRUE	0	PD-S-SESSION-ID	1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc
>2017-02-06 21:13:12,174 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: DPJSESSIONID=PBC5YS:123972063; Path=/; Domain=.prepiam.toronto.ca.ibm.com; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?PolicyId=urn:ibm:security:authentication:asf:basicldapuser
>2017-02-06 21:13:12,175 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/	TRUE	0	DPJSESSIONID	PBC5YS:123972063
>2017-02-06 21:13:12,190 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Existing HeaderManager 'HTTP Header Manager' merged with 'HTTP Header Manager:HTTP Header Manager'
>2017-02-06 21:13:12,190 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Content-Type=application/json
>2017-02-06 21:13:12,190 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Cache-Control=no-cache
>2017-02-06 21:13:12,190 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Accept=application/json
>2017-02-06 21:13:12,191 DEBUG o.a.j.p.h.s.HTTPHC4Impl: notifyFirstSampleAfterLoopRestart
>2017-02-06 21:13:12,191 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5
>2017-02-06 21:13:12,191 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method PUT followingRedirect false depth 0
>2017-02-06 21:13:12,191 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Reusing the HttpClient: @1233359 https://prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:12,192 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 4 cookies for https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5
>2017-02-06 21:13:12,192 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:12,192 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,193 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,193 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:12,193 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:12,193 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:12,193 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:12,193 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:12,193 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: PUT /idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5 HTTP/1.1
>2017-02-06 21:13:12,193 DEBUG o.a.h.wire:  >> "PUT /idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5 HTTP/1.1[\r][\n]"
>2017-02-06 21:13:12,193 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:12,193 DEBUG o.a.h.wire:  >> "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; PD-S-SESSION-ID=1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc; DPJSESSIONID=PBC5YS:123972063[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "Content-Length: 65[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "Host: prepiam.toronto.ca.ibm.com[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> PUT /idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5 HTTP/1.1
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Content-Type: application/json
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; PD-S-SESSION-ID=1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc; DPJSESSIONID=PBC5YS:123972063
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Content-Length: 65
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> Host: prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:12,194 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:12,194 DEBUG o.a.h.wire:  >> "{"username":"mypwdev+autofocal@gmail.com", "password":"mypw@ut0"}"
>2017-02-06 21:13:12,479 DEBUG o.a.h.wire:  << "HTTP/1.1 204 No Content[\r][\n]"
>2017-02-06 21:13:12,479 DEBUG o.a.h.wire:  << "X-Backside-Transport: OK OK[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "Content-Language: en-US[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "p3p: CP="NON CUR OTPi OUR NOR UNI"[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "x-frame-options: SAMEORIGIN[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "Cache-Control: no-cache,max-age=0,                             no-cache, no-store, max-age=0, must-revalidate[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "Expires: 0[\r][\n]"
>2017-02-06 21:13:12,480 DEBUG o.a.h.wire:  << "fim.action: signin[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "content-security-policy: frame-ancestors 'self'[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "strict-transport-security: max-age=31536000; includeSubDomains[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "Pragma: no-cache[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "X-Client-IP: 184.51.147.10[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 1066720342[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:13 GMT[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "Set-Cookie: PD-S-SESSION-ID=1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY; Path=/; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,481 DEBUG o.a.h.wire:  << "Set-Cookie: PD-ID=zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==; Domain=.ibm.com; Path=/; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,482 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:12,482 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 204 No Content
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << HTTP/1.1 204 No Content
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << X-Backside-Transport: OK OK
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << Content-Language: en-US
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << Content-Type: application/json
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << p3p: CP="NON CUR OTPi OUR NOR UNI"
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << x-frame-options: SAMEORIGIN
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << Cache-Control: no-cache,max-age=0,                             no-cache, no-store, max-age=0, must-revalidate
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << Expires: 0
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << fim.action: signin
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << content-security-policy: frame-ancestors 'self'
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << strict-transport-security: max-age=31536000; includeSubDomains
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << Pragma: no-cache
>2017-02-06 21:13:12,482 DEBUG o.a.h.headers: << X-Client-IP: 184.51.147.10
>2017-02-06 21:13:12,483 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 1066720342
>2017-02-06 21:13:12,483 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:13 GMT
>2017-02-06 21:13:12,483 DEBUG o.a.h.headers: << Connection: keep-alive
>2017-02-06 21:13:12,483 DEBUG o.a.h.headers: << Set-Cookie: PD-S-SESSION-ID=1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY; Path=/; Secure; HttpOnly
>2017-02-06 21:13:12,483 DEBUG o.a.h.headers: << Set-Cookie: PD-ID=zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==; Domain=.ibm.com; Path=/; Secure; HttpOnly
>2017-02-06 21:13:12,483 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:12,483 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:12,483 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,483 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=999 Content-Length=0 Total=999
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: PD-S-SESSION-ID=1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY; Path=/; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.c.CookieManager: New Cookie = prepiam.toronto.ca.ibm.com	TRUE	/	TRUE	0	PD-S-SESSION-ID	1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY removing matching Cookie prepiam.toronto.ca.ibm.com	TRUE	/	TRUE	0	PD-S-SESSION-ID	1_2_0_P7MwpTY50oj7SWaP3MCMAXx+WNFuqtGx47EnsJS0PSdUOtuc
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/	TRUE	0	PD-S-SESSION-ID	1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: PD-ID=zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==; Domain=.ibm.com; Path=/; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/mtfim/sps/apiauthsvc?StateId=6afbf328-bf46-4d88-9a06-6651204d16a5
>2017-02-06 21:13:12,484 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store ibm.com	TRUE	/	TRUE	0	PD-ID	zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==
>2017-02-06 21:13:12,485 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Existing HeaderManager 'HTTP Header Manager' merged with 'HTTP Header Manager:HTTP Header Manager'
>2017-02-06 21:13:12,485 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Content-Type=application/x-www-form-urlencoded
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Cache-Control=no-cache
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Accept=application/json
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPHC4Impl: notifyFirstSampleAfterLoopRestart
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://prepiam.toronto.ca.ibm.com/idaas/oidc/endpoint/default/authorize
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method POST followingRedirect false depth 0
>2017-02-06 21:13:12,486 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Reusing the HttpClient: @1233359 https://prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:12,487 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 5 cookies for https://prepiam.toronto.ca.ibm.com/idaas/oidc/endpoint/default/authorize
>2017-02-06 21:13:12,487 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:12,487 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,487 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,487 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:12,488 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:12,488 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:12,488 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:12,488 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:12,488 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: POST /idaas/oidc/endpoint/default/authorize HTTP/1.1
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "POST /idaas/oidc/endpoint/default/authorize HTTP/1.1[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Content-Type: application/x-www-form-urlencoded[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; DPJSESSIONID=PBC5YS:123972063; PD-S-SESSION-ID=1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY; PD-ID=zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Content-Length: 134[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "Host: prepiam.toronto.ca.ibm.com[\r][\n]"
>2017-02-06 21:13:12,488 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:12,489 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> POST /idaas/oidc/endpoint/default/authorize HTTP/1.1
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Content-Type: application/x-www-form-urlencoded
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Cookie: JSESSIONID=00004Y3DNugrdHgjq0Z6USL0JVy:d1be1f44-6a5d-4bf1-b58a-416c087e4249; PD_STATEFUL_914de426-1ed3-11e6-a935-000c29c338dc=%2Fidaas; DPJSESSIONID=PBC5YS:123972063; PD-S-SESSION-ID=1_2_1_5pVewQlzpEiz55s+OTZjLaDTDjBJOit4UtLQ0aLf5ABE9FbY; PD-ID=zumbbLTvdbtGjfCBXI1l+FRWQtE9YI6cucF+3v8nhpma10Ac5yRfkaZrNhIVHVgoRtqky0bHg4c8ifxsDBcAVrTW9YTIJ895uIuuroAep9/zfwU5dyd53qRftwS3MU2//kYuC1zLROhqXnQ532h1uFP+FyByA8m6rwN7qrM0a8FodLhajDDcP2MssUZ6ajvakoKWIa3LhyrCtEkjMGo6A2FA2W123XtoCqr+fkyAZ3WFzVf7YthVCg==
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Content-Length: 134
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> Host: prepiam.toronto.ca.ibm.com
>2017-02-06 21:13:12,489 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:12,489 DEBUG o.a.h.wire:  >> "scope=openid&response_type=code&client_id=MDc2Yzg1ZDktNmVlYS00&redirect_uri=https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "HTTP/1.1 302 Moved Temporarily[\r][\n]"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "X-Backside-Transport: OK OK[\r][\n]"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "Content-Language: en-US[\r][\n]"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "Location: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw[\r][\n]"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "p3p: CP="NON CUR OTPi OUR NOR UNI"[\r][\n]"
>2017-02-06 21:13:12,719 DEBUG o.a.h.wire:  << "x-frame-options: SAMEORIGIN[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Cache-Control: no-store, no-cache=set-cookie,                             no-cache, no-store, max-age=0, must-revalidate[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Expires: Thu, 01 Dec 1994 16:00:00 GMT,                             0[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "content-security-policy: frame-ancestors 'self'[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "strict-transport-security: max-age=31536000; includeSubDomains[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Pragma: no-cache,                             no-cache[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "X-Client-IP: 184.51.147.10[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 1149532609[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Content-Length: 0[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:13 GMT[\r][\n]"
>2017-02-06 21:13:12,720 DEBUG o.a.h.wire:  << "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:12,721 DEBUG o.a.h.wire:  << "Set-Cookie: WAS_p1937755787=4laedComJYfOd+8LlvujYEAU5ziN2yI6hxDL+dvRbhc1bLSNM4af55BW7psQG/9izZaTjZCPECSqTO3+sWwYXXNrtfWliUOIbZFYi8UzE73RRsPCXP6l38gQAww5IHfIbmhuNKsrfC3JFrQR4Ll+iZne4oL9s1L8yQTU5Hwwzk2Ig0V0nkHAL5R/czoh+XF9zrToyVFjbeOOs7zYHtZcg2H/3zxDVOeC7vbxNPKCJYsee4HFPJJuAEpEPjGu2TV+0N38PnIlTB83Dy6RwlYusZmNVz9Q3to+pkXhoQCimICm1b+LuGDbxOXihwORQDdo9nIaQNq9LEZ7c1YiAKE9qnaoHDkQJRq6JB/NrCAnhgtTCcHYw05bDe+8tIX84vIQ3EK79qZv2ZE5nCAfiQ5z7svoxkm4VpaCLsuPuiXX7TA=; Path=/idaas/; Secure; HttpOnly[\r][\n]"
>2017-02-06 21:13:12,721 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:12,721 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 302 Moved Temporarily
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << HTTP/1.1 302 Moved Temporarily
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << X-Backside-Transport: OK OK
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << Content-Language: en-US
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << Location: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << p3p: CP="NON CUR OTPi OUR NOR UNI"
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << x-frame-options: SAMEORIGIN
>2017-02-06 21:13:12,721 DEBUG o.a.h.headers: << Cache-Control: no-store, no-cache=set-cookie,                             no-cache, no-store, max-age=0, must-revalidate
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Expires: Thu, 01 Dec 1994 16:00:00 GMT,                             0
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << content-security-policy: frame-ancestors 'self'
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << strict-transport-security: max-age=31536000; includeSubDomains
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Pragma: no-cache,                             no-cache
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << X-Client-IP: 184.51.147.10
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 1149532609
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Content-Length: 0
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:13 GMT
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Connection: keep-alive
>2017-02-06 21:13:12,722 DEBUG o.a.h.headers: << Set-Cookie: WAS_p1937755787=4laedComJYfOd+8LlvujYEAU5ziN2yI6hxDL+dvRbhc1bLSNM4af55BW7psQG/9izZaTjZCPECSqTO3+sWwYXXNrtfWliUOIbZFYi8UzE73RRsPCXP6l38gQAww5IHfIbmhuNKsrfC3JFrQR4Ll+iZne4oL9s1L8yQTU5Hwwzk2Ig0V0nkHAL5R/czoh+XF9zrToyVFjbeOOs7zYHtZcg2H/3zxDVOeC7vbxNPKCJYsee4HFPJJuAEpEPjGu2TV+0N38PnIlTB83Dy6RwlYusZmNVz9Q3to+pkXhoQCimICm1b+LuGDbxOXihwORQDdo9nIaQNq9LEZ7c1YiAKE9qnaoHDkQJRq6JB/NrCAnhgtTCcHYw05bDe+8tIX84vIQ3EK79qZv2ZE5nCAfiQ5z7svoxkm4VpaCLsuPuiXX7TA=; Path=/idaas/; Secure; HttpOnly
>2017-02-06 21:13:12,722 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:12,722 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:12,723 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:12,723 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 0][route: {s}->https://prepiam.toronto.ca.ibm.com:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,723 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=1269 Content-Length=0 Total=1269
>2017-02-06 21:13:12,723 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: WAS_p1937755787=4laedComJYfOd+8LlvujYEAU5ziN2yI6hxDL+dvRbhc1bLSNM4af55BW7psQG/9izZaTjZCPECSqTO3+sWwYXXNrtfWliUOIbZFYi8UzE73RRsPCXP6l38gQAww5IHfIbmhuNKsrfC3JFrQR4Ll+iZne4oL9s1L8yQTU5Hwwzk2Ig0V0nkHAL5R/czoh+XF9zrToyVFjbeOOs7zYHtZcg2H/3zxDVOeC7vbxNPKCJYsee4HFPJJuAEpEPjGu2TV+0N38PnIlTB83Dy6RwlYusZmNVz9Q3to+pkXhoQCimICm1b+LuGDbxOXihwORQDdo9nIaQNq9LEZ7c1YiAKE9qnaoHDkQJRq6JB/NrCAnhgtTCcHYw05bDe+8tIX84vIQ3EK79qZv2ZE5nCAfiQ5z7svoxkm4VpaCLsuPuiXX7TA=; Path=/idaas/; Secure; HttpOnly From: https://prepiam.toronto.ca.ibm.com/idaas/oidc/endpoint/default/authorize
>2017-02-06 21:13:12,723 DEBUG o.a.j.p.h.c.CookieManager: Add cookie to store prepiam.toronto.ca.ibm.com	TRUE	/idaas/	TRUE	0	WAS_p1937755787	4laedComJYfOd+8LlvujYEAU5ziN2yI6hxDL+dvRbhc1bLSNM4af55BW7psQG/9izZaTjZCPECSqTO3+sWwYXXNrtfWliUOIbZFYi8UzE73RRsPCXP6l38gQAww5IHfIbmhuNKsrfC3JFrQR4Ll+iZne4oL9s1L8yQTU5Hwwzk2Ig0V0nkHAL5R/czoh+XF9zrToyVFjbeOOs7zYHtZcg2H/3zxDVOeC7vbxNPKCJYsee4HFPJJuAEpEPjGu2TV+0N38PnIlTB83Dy6RwlYusZmNVz9Q3to+pkXhoQCimICm1b+LuGDbxOXihwORQDdo9nIaQNq9LEZ7c1YiAKE9qnaoHDkQJRq6JB/NrCAnhgtTCcHYw05bDe+8tIX84vIQ3EK79qZv2ZE5nCAfiQ5z7svoxkm4VpaCLsuPuiXX7TA=
>2017-02-06 21:13:12,724 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Location set to - https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,724 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Initial location: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,724 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Location after /. and space transforms: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,724 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Location as URL: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,725 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,725 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method GET followingRedirect true depth 0
>2017-02-06 21:13:12,725 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Created new HttpClient: @1161352258 https://mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:12,725 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 0 cookies for https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:12,725 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:12,726 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>2017-02-06 21:13:12,726 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 1][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:12,772 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator: Connecting to mysa-dev-amar.w3ibm.mybluemix.net:443
>2017-02-06 21:13:13,431 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:13,431 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:13,432 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:13,432 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:13,432 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:13,432 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: GET /auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw HTTP/1.1
>2017-02-06 21:13:13,432 DEBUG o.a.h.wire:  >> "GET /auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw HTTP/1.1[\r][\n]"
>2017-02-06 21:13:13,432 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:13,432 DEBUG o.a.h.wire:  >> "Content-Type: application/x-www-form-urlencoded[\r][\n]"
>2017-02-06 21:13:13,432 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:13,432 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:13,433 DEBUG o.a.h.wire:  >> "Host: mysa-dev-amar.w3ibm.mybluemix.net[\r][\n]"
>2017-02-06 21:13:13,433 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:13,433 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> GET /auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw HTTP/1.1
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> Content-Type: application/x-www-form-urlencoded
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> Host: mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:13,433 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:15,462 DEBUG o.a.h.wire:  << "HTTP/1.1 302 Found[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "X-Backside-Transport: OK OK[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Connection: Keep-Alive[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Transfer-Encoding: chunked[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:14 GMT[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Location: /[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Set-Cookie: mySASession=s%3AcafPSGf6UJguyhddGFFeLdHBy9CYbzIS.NhYyA26LGTAVoLxhCQUK%2F2Bs34MW5kGHmErKzG6r3XI; Path=/; Expires=Tue, 07 Feb 2017 09:13:14 GMT; HttpOnly[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "Vary: Accept[\r][\n]"
>2017-02-06 21:13:15,463 DEBUG o.a.h.wire:  << "X-Powered-By: Express[\r][\n]"
>2017-02-06 21:13:15,464 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 733223309[\r][\n]"
>2017-02-06 21:13:15,464 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:15,464 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 302 Found
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << HTTP/1.1 302 Found
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << X-Backside-Transport: OK OK
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Connection: Keep-Alive
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Transfer-Encoding: chunked
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:14 GMT
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Location: /
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Set-Cookie: mySASession=s%3AcafPSGf6UJguyhddGFFeLdHBy9CYbzIS.NhYyA26LGTAVoLxhCQUK%2F2Bs34MW5kGHmErKzG6r3XI; Path=/; Expires=Tue, 07 Feb 2017 09:13:14 GMT; HttpOnly
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << Vary: Accept
>2017-02-06 21:13:15,464 DEBUG o.a.h.headers: << X-Powered-By: Express
>2017-02-06 21:13:15,465 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 733223309
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:15,466 DEBUG o.a.h.wire:  << "0[\r][\n]"
>2017-02-06 21:13:15,466 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 1][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 1][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=391 Content-Length=5 Total=396
>2017-02-06 21:13:15,466 DEBUG o.a.j.p.h.c.HC4CookieHandler: Received Cookie: mySASession=s%3AcafPSGf6UJguyhddGFFeLdHBy9CYbzIS.NhYyA26LGTAVoLxhCQUK%2F2Bs34MW5kGHmErKzG6r3XI; Path=/; Expires=Tue, 07 Feb 2017 09:13:14 GMT; HttpOnly From: https://mysa-dev-amar.w3ibm.mybluemix.net/auth/oidc/return?scope=openid&code=l9TOSC0ow6Nw5U6YKcJWeKeDIFKcSw
>2017-02-06 21:13:15,469 ERROR o.a.j.p.h.c.HC4CookieHandler: Unable to add the cookie
>org.apache.http.cookie.MalformedCookieException: Invalid 'expires' attribute: Tue, 07 Feb 2017 09:13:14 GMT
>	at org.apache.http.impl.cookie.BasicExpiresHandler.parse(BasicExpiresHandler.java:64) ~[httpclient-4.5.3.jar:4.5.3]
>	at org.apache.http.impl.cookie.CookieSpecBase.parse(CookieSpecBase.java:113) ~[httpclient-4.5.3.jar:4.5.3]
>	at org.apache.http.impl.cookie.DefaultCookieSpec.parse(DefaultCookieSpec.java:140) ~[httpclient-4.5.3.jar:4.5.3]
>	at org.apache.jmeter.protocol.http.control.HC4CookieHandler.addCookieFromHeader(HC4CookieHandler.java:125) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.control.CookieManager.addCookieFromHeader(CookieManager.java:375) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.saveConnectionCookies(HTTPHC4Impl.java:1526) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:486) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.followRedirects(HTTPSamplerBase.java:1526) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.resultProcessing(HTTPSamplerBase.java:1620) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPAbstractImpl.resultProcessing(HTTPAbstractImpl.java:519) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPHC4Impl.sample(HTTPHC4Impl.java:494) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerProxy.sample(HTTPSamplerProxy.java:74) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1176) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.protocol.http.sampler.HTTPSamplerBase.sample(HTTPSamplerBase.java:1165) [ApacheJMeter_http.jar:r1781918]
>	at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:473) [ApacheJMeter_core.jar:r1781918]
>	at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:416) [ApacheJMeter_core.jar:r1781918]
>	at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:252) [ApacheJMeter_core.jar:r1781918]
>	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Initial location: /
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Location after /. and space transforms: /
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Location as URL: https://mysa-dev-amar.w3ibm.mybluemix.net/
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://mysa-dev-amar.w3ibm.mybluemix.net/
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method GET followingRedirect true depth 0
>2017-02-06 21:13:15,473 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Reusing the HttpClient: @1161352258 https://mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:15,474 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 0 cookies for https://mysa-dev-amar.w3ibm.mybluemix.net/
>2017-02-06 21:13:15,474 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:15,474 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:15,475 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id:1][route:{s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state:Main test thread 1-1] expired @ Mon Feb 06 21:13:14 GMT 2017
>2017-02-06 21:13:15,476 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Connection 0.0.0.0:62580<->9.45.69.137:443 closed
>2017-02-06 21:13:15,476 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:15,476 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator: Connecting to mysa-dev-amar.w3ibm.mybluemix.net:443
>2017-02-06 21:13:16,134 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:16,134 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:16,134 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:16,135 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:16,135 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:16,135 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: GET / HTTP/1.1
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "GET / HTTP/1.1[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "Content-Type: application/x-www-form-urlencoded[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "Host: mysa-dev-amar.w3ibm.mybluemix.net[\r][\n]"
>2017-02-06 21:13:16,135 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:16,136 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> GET / HTTP/1.1
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> Content-Type: application/x-www-form-urlencoded
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> Host: mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:16,136 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:16,306 DEBUG o.a.h.wire:  << "HTTP/1.1 200 OK[\r][\n]"
>2017-02-06 21:13:16,306 DEBUG o.a.h.wire:  << "X-Backside-Transport: OK OK[\r][\n]"
>2017-02-06 21:13:16,306 DEBUG o.a.h.wire:  << "Connection: Keep-Alive[\r][\n]"
>2017-02-06 21:13:16,306 DEBUG o.a.h.wire:  << "Transfer-Encoding: chunked[\r][\n]"
>2017-02-06 21:13:16,306 DEBUG o.a.h.wire:  << "Content-Type: text/html[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:16 GMT[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.h.wire:  << "Etag: W/"24b-Y3ibdo7JGNfStuHNUjDbJA"[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.h.wire:  << "X-Powered-By: Express[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 661961833[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,307 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 200 OK
>2017-02-06 21:13:16,307 DEBUG o.a.h.headers: << HTTP/1.1 200 OK
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << X-Backside-Transport: OK OK
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << Connection: Keep-Alive
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << Transfer-Encoding: chunked
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << Content-Type: text/html
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:16 GMT
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << Etag: W/"24b-Y3ibdo7JGNfStuHNUjDbJA"
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << X-Powered-By: Express
>2017-02-06 21:13:16,308 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 661961833
>2017-02-06 21:13:16,309 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:16,309 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "24b[\r][\n]"
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "<!doctype html>[\n]"
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "<html lang="en-US">[\n]"
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "<head>[\n]"
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "    <meta charset="utf-8">[\n]"
>2017-02-06 21:13:16,309 DEBUG o.a.h.wire:  << "    <script type="text/javascript">[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "        // if there's a hash fragment, and it's not just # or #/ save to cookie[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "        var h = window.location.hash;[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "        if (h.length > 0 && !h.match(/^#[/]{0,1}$/)) {[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "            var expire = new Date(Date.now() + (60 * 60 * 1000));[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "            document.cookie = 'mySATargetState=' + window.location.hash + '; expires=' + expire.toUTCString();[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "        }[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "        window.location.href = window.location.origin + '/auth/oidc/login';[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "    </script>[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "</head>[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "<body>[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "</body>[\n]"
>2017-02-06 21:13:16,310 DEBUG o.a.h.wire:  << "</html>[\n]"
>2017-02-06 21:13:16,313 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,313 DEBUG o.a.h.wire:  << "0[\r][\n]"
>2017-02-06 21:13:16,313 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,313 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:16,314 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,314 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=259 Content-Length=599 Total=858
>2017-02-06 21:13:16,315 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Existing HeaderManager 'HTTP Header Manager' merged with 'HTTP Header Manager:HTTP Header Manager'
>2017-02-06 21:13:16,315 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Cache-Control=no-cache
>2017-02-06 21:13:16,315 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Accept=application/json
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.HTTPHC4Impl: notifyFirstSampleAfterLoopRestart
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://mysa-dev-amar.w3ibm.mybluemix.net/salesactivities/api/opportunities/getTeaserOppties?ceid=18z7gjzz
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method GET followingRedirect false depth 0
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Reusing the HttpClient: @1161352258 https://mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 0 cookies for https://mysa-dev-amar.w3ibm.mybluemix.net/salesactivities/api/opportunities/getTeaserOppties?ceid=18z7gjzz
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:16,317 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,318 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,318 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:16,318 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:16,318 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:16,318 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:16,318 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:16,318 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: GET /salesactivities/api/opportunities/getTeaserOppties?ceid=18z7gjzz HTTP/1.1
>2017-02-06 21:13:16,318 DEBUG o.a.h.wire:  >> "GET /salesactivities/api/opportunities/getTeaserOppties?ceid=18z7gjzz HTTP/1.1[\r][\n]"
>2017-02-06 21:13:16,318 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.wire:  >> "Host: mysa-dev-amar.w3ibm.mybluemix.net[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> GET /salesactivities/api/opportunities/getTeaserOppties?ceid=18z7gjzz HTTP/1.1
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> Host: mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:16,319 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:16,485 DEBUG o.a.h.wire:  << "HTTP/1.1 401 Unauthorized[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "X-Backside-Transport: FAIL FAIL[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "Connection: Keep-Alive[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "Transfer-Encoding: chunked[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:17 GMT[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "Etag: W/"49-cZsNmT+1ebT7EUEhudBqxg"[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "X-Powered-By: Express[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 693385057[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,486 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 401 Unauthorized
>2017-02-06 21:13:16,486 DEBUG o.a.h.headers: << HTTP/1.1 401 Unauthorized
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << X-Backside-Transport: FAIL FAIL
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << Connection: Keep-Alive
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << Transfer-Encoding: chunked
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << Content-Type: application/json
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:17 GMT
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << Etag: W/"49-cZsNmT+1ebT7EUEhudBqxg"
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << X-Powered-By: Express
>2017-02-06 21:13:16,487 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 693385057
>2017-02-06 21:13:16,487 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:16,488 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Authentication required
>2017-02-06 21:13:16,488 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: mysa-dev-amar.w3ibm.mybluemix.net:443 requested authentication
>2017-02-06 21:13:16,488 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Response contains no authentication challenges
>2017-02-06 21:13:16,488 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:16,488 DEBUG o.a.h.wire:  << "49[\r][\n]"
>2017-02-06 21:13:16,488 DEBUG o.a.h.wire:  << "{"message":"[MySA]:Authorization session expired or invalid.","code":401}"
>2017-02-06 21:13:16,488 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,489 DEBUG o.a.h.wire:  << "0[\r][\n]"
>2017-02-06 21:13:16,489 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,489 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:16,489 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,489 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=279 Content-Length=84 Total=363
>2017-02-06 21:13:16,489 DEBUG o.a.j.p.h.s.HTTPSamplerBase: Existing HeaderManager 'HTTP Header Manager' merged with 'HTTP Header Manager:HTTP Header Manager'
>2017-02-06 21:13:16,489 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Cache-Control=no-cache
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPSamplerBase:     Accept=application/json
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPHC4Impl: notifyFirstSampleAfterLoopRestart
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Start : sample https://mysa-dev-amar.w3ibm.mybluemix.net/salesactivities/api/incentives/getIncentives/?ceid=18z7gjzz&forceLoad=true
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPHC4Impl: method GET followingRedirect false depth 0
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Reusing the HttpClient: @1161352258 https://mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.c.HC4CookieHandler: Found 0 cookies for https://mysa-dev-amar.w3ibm.mybluemix.net/salesactivities/api/incentives/getIncentives/?ceid=18z7gjzz&forceLoad=true
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Found user token:Main test thread 1-1 as JMeter variable:__jmeter.USER_TOKEN__, storing it in HttpContext
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection request: [route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,490 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection leased: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,491 DEBUG o.a.h.c.p.RequestAddCookies: CookieSpec selected: ignoreCookies
>2017-02-06 21:13:16,491 DEBUG o.a.h.c.p.RequestAuthCache: Auth cache not set in the context
>2017-02-06 21:13:16,491 DEBUG o.a.h.c.p.RequestTargetAuthentication: Target auth state: UNCHALLENGED
>2017-02-06 21:13:16,491 DEBUG o.a.h.c.p.RequestProxyAuthentication: Proxy auth state: UNCHALLENGED
>2017-02-06 21:13:16,491 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Attempt 1 to execute request
>2017-02-06 21:13:16,491 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Sending request: GET /salesactivities/api/incentives/getIncentives/?ceid=18z7gjzz&forceLoad=true HTTP/1.1
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "GET /salesactivities/api/incentives/getIncentives/?ceid=18z7gjzz&forceLoad=true HTTP/1.1[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "Connection: keep-alive[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "Cache-Control: no-cache[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "Accept: application/json[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "Host: mysa-dev-amar.w3ibm.mybluemix.net[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.wire:  >> "[\r][\n]"
>2017-02-06 21:13:16,491 DEBUG o.a.h.headers: >> GET /salesactivities/api/incentives/getIncentives/?ceid=18z7gjzz&forceLoad=true HTTP/1.1
>2017-02-06 21:13:16,491 DEBUG o.a.h.headers: >> Connection: keep-alive
>2017-02-06 21:13:16,491 DEBUG o.a.h.headers: >> Cache-Control: no-cache
>2017-02-06 21:13:16,491 DEBUG o.a.h.headers: >> Accept: application/json
>2017-02-06 21:13:16,491 DEBUG o.a.h.headers: >> Host: mysa-dev-amar.w3ibm.mybluemix.net
>2017-02-06 21:13:16,492 DEBUG o.a.h.headers: >> User-Agent: Apache-HttpClient/4.5.3 (Java/1.8.0_112)
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "HTTP/1.1 401 Unauthorized[\r][\n]"
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "X-Backside-Transport: FAIL FAIL[\r][\n]"
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "Connection: Keep-Alive[\r][\n]"
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "Transfer-Encoding: chunked[\r][\n]"
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "Content-Type: application/json[\r][\n]"
>2017-02-06 21:13:16,669 DEBUG o.a.h.wire:  << "Date: Mon, 06 Feb 2017 21:13:17 GMT[\r][\n]"
>2017-02-06 21:13:16,670 DEBUG o.a.h.wire:  << "Etag: W/"49-cZsNmT+1ebT7EUEhudBqxg"[\r][\n]"
>2017-02-06 21:13:16,670 DEBUG o.a.h.wire:  << "X-Powered-By: Express[\r][\n]"
>2017-02-06 21:13:16,670 DEBUG o.a.h.wire:  << "X-Global-Transaction-ID: 661962137[\r][\n]"
>2017-02-06 21:13:16,670 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,670 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Receiving response: HTTP/1.1 401 Unauthorized
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << HTTP/1.1 401 Unauthorized
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << X-Backside-Transport: FAIL FAIL
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << Connection: Keep-Alive
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << Transfer-Encoding: chunked
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << Content-Type: application/json
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << Date: Mon, 06 Feb 2017 21:13:17 GMT
>2017-02-06 21:13:16,670 DEBUG o.a.h.headers: << Etag: W/"49-cZsNmT+1ebT7EUEhudBqxg"
>2017-02-06 21:13:16,671 DEBUG o.a.h.headers: << X-Powered-By: Express
>2017-02-06 21:13:16,671 DEBUG o.a.h.headers: << X-Global-Transaction-ID: 661962137
>2017-02-06 21:13:16,671 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Connection can be kept alive indefinitely
>2017-02-06 21:13:16,671 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Authentication required
>2017-02-06 21:13:16,671 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: mysa-dev-amar.w3ibm.mybluemix.net:443 requested authentication
>2017-02-06 21:13:16,671 DEBUG o.a.j.p.h.s.HTTPHC4Impl$4: Response contains no authentication challenges
>2017-02-06 21:13:16,671 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Extracted from HttpContext user token:Main test thread 1-1, storing it as JMeter variable:__jmeter.USER_TOKEN__
>2017-02-06 21:13:16,672 DEBUG o.a.h.wire:  << "49[\r][\n]"
>2017-02-06 21:13:16,672 DEBUG o.a.h.wire:  << "{"message":"[MySA]:Authorization session expired or invalid.","code":401}"
>2017-02-06 21:13:16,672 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,672 DEBUG o.a.h.wire:  << "0[\r][\n]"
>2017-02-06 21:13:16,672 DEBUG o.a.h.wire:  << "[\r][\n]"
>2017-02-06 21:13:16,672 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1] can be kept alive indefinitely
>2017-02-06 21:13:16,672 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection released: [id: 2][route: {s}->https://mysa-dev-amar.w3ibm.mybluemix.net:443][state: Main test thread 1-1][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
>2017-02-06 21:13:16,672 DEBUG o.a.j.p.h.s.HTTPHC4Impl: ResponseHeadersSize=279 Content-Length=84 Total=363
>2017-02-06 21:13:16,673 INFO o.a.j.t.JMeterThread: Thread is done: Main test thread 1-1
>2017-02-06 21:13:16,673 INFO o.a.j.t.JMeterThread: Thread finished: Main test thread 1-1
>2017-02-06 21:13:16,673 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Thread Finished
>2017-02-06 21:13:16,673 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager is shutting down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Connection 0.0.0.0:62582<->9.45.69.137:443 closed
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Connection 0.0.0.0:62582<->9.45.69.137:443 closed
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager shut down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager is shutting down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager shut down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager is shutting down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Connection 0.0.0.0:62578<->23.60.135.191:443 closed
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.JMeterClientConnectionOperator$JMeterDefaultClientConnection: Connection 0.0.0.0:62578<->23.60.135.191:443 closed
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager shut down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager is shutting down
>2017-02-06 21:13:16,674 DEBUG o.a.j.p.h.s.MeasuringConnectionManager: Connection manager shut down
>2017-02-06 21:13:16,675 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Thread Finished
>2017-02-06 21:13:16,675 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Thread Finished
>2017-02-06 21:13:16,675 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Thread Finished
>2017-02-06 21:13:16,675 DEBUG o.a.j.p.h.s.HTTPHC4Impl: Thread Finished
>2017-02-06 21:13:16,675 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
>2017-02-06 21:13:16,677 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false,*local*)

Actions: View

Attachments on bug 60682: 34712 | 34713 | 34718 | 34721 | 34722 | 34723 | 34724 | 34725 | 34726 | 34727