Call the following enable method in the constructor of your business class to enable logging:
private void enableHeaderWireAndContextLogging(a){
System.setProperty("org.apache.commons.logging.Log"."org.apache.commons.logging.impl.SimpleLog");
System.setProperty("org.apache.commons.logging.simplelog.showdatetime"."true");
System.setProperty("org.apache.commons.logging.simplelog.log.httpclient.wire.header"."debug");
System.setProperty("org.apache.commons.logging.simplelog.log.org.apache.commons.httpclient"."debug");
System.setProperty("org.apache.commons.logging.simplelog.defaultlog"."debug");
}
Copy the codeIn the SimpleLog implementation, the following code reads the user’s code Settings from the SystemProperty:
Debug level log output is complete:
2019/05/24 16:58:16:397 CST [DEBUG] RequestAddCookies – CookieSpec selected: default
2019/05/24 16:58:16:417 CST [DEBUG] RequestAuthCache – Auth cache not set in the context
2019/05/24 16:58:16:614 CST [DEBUG] PoolingHttpClientConnectionManager – Connection request: [route: {s}->hybris.com:443][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
2019/05/24 16:58:21:265 CST [DEBUG] PoolingHttpClientConnectionManager – Connection leased: [id: 0][route: {s}->hybris.com:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
2019/05/24 16:58:21:271 CST [DEBUG] MainClientExec – Opening connection {s}->hybris.com:443
2019/05/24 16:58:21:271 CST [DEBUG] DefaultHttpClientConnectionOperator – Connecting to hybris.com/69.145.197.…
2019/05/24 16:58:21:271 CST [DEBUG] SSLConnectionSocketFactory – Connecting socket to hybris.com/69.145.197.… with timeout 0
2019/05/24 16:58:21:521 CST [DEBUG] SSLConnectionSocketFactory – Enabled protocols: [TLSv1, TLSv1.1, TLSv1.2]
2019/05/24 16:58:21:521 CST [DEBUG] SSLConnectionSocketFactory – Enabled cipher suites:[TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
2019/05/24 16:58:21:521 CST [DEBUG] SSLConnectionSocketFactory – Starting handshake
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – Secure session established
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – negotiated protocol: TLSv1.2
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – peer principal: CN=gdm-acdo.apjdemo.hybris.com
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – peer alternative names: []
2019/05/24 16:58:21:849 CST [DEBUG] SSLConnectionSocketFactory – issuer principal: CN=Let’s Encrypt Authority X3, O=Let’s Encrypt, C=US
2019/05/24 16:58:21:849 CST [DEBUG] DefaultHttpClientConnectionOperator – Connection established 10.130.197.181:60875<->169.145.197.197:443
2019/05/24 16:58:21:849 CST [DEBUG] MainClientExec – Executing request GET /sap/opu/odata/sap/CUAN_CONTACT_SRV HTTP/1.1
2019/05/24 16:58:21:849 CST [DEBUG] MainClientExec – Proxy auth state: UNCHALLENGED
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> GET /sap/opu/odata/sap/CUAN_CONTACT_SRV HTTP/1.1
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Authorization: basic bWt0X2R
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Cache-Control: no-cache
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> content-type: application/json
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Accept: application/json
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> x-csrf-token: fetch
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Host: gdm-hybris.com
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Connection: Keep-Alive
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.1 (Java/1.8.0_60)
2019/05/24 16:58:21:849 CST [DEBUG] headers – http-outgoing-0 >> Accept-Encoding: gzip,deflate
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “GET /sap/opu/odata/sap/CUAN_CONTACT_SRV HTTP/1.1[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Authorization: basic bWt0X2[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Cache-Control: no-cache[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “content-type: application/json[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Accept: application/json[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “x-csrf-token: fetch[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Host: gdm-acdo.apjdemo.hybris.com[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Connection: Keep-Alive[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “User-Agent: Apache-HttpClient/4.5.1 (Java/1.8.0_60)[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “Accept-Encoding: gzip,deflate[\r][\n]”
2019/05/24 16:58:21:849 CST [DEBUG] wire – http-outgoing-0 >> “[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “HTTP/1.1 307 Temporary Redirect[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “Server: nginx/1.14.2[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “Date: Fri, 24 May 2019 08:58:22 GMT[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “Content-Length: 0[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “Connection: keep-alive[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “set-cookie: sap-usercontext=sap-client=100; path=/[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “set-cookie: SAP_SEhIHE%3d; path=/; secure; HttpOnly[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “x-csrf-token: kVwN39IxT6wSsOnjgeSGww==[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “location: hybris.com:443/sap/opu/oda…”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “sap-processing-info: ODataBEP=,crp=,st=,MedCacheHub=,codeployed=X,softstate=[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “sap-server: true[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “sap-perf-fesrec: 42584.000000[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] wire – http-outgoing-0 << “[\r][\n]”
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << HTTP/1.1 307 Temporary Redirect
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << Server: nginx/1.14.2
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << Date: Fri, 24 May 2019 08:58:22 GMT
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << Content-Length: 0
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << Connection: keep-alive
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << set-cookie: sap-usercontext=sap-client=100; path=/
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << set-cookie: SAP_SESSIONID_E4T_100=a-dtZMlUCPrNMQYUQYcL8RULy6l-AhHpqRECAAohIHE%3d; path=/; secure; HttpOnly
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << x-csrf-token: kVwSGww==
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << location: hybris.com:443/sap/opu/oda…
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << sap-processing-info: ODataBEP=,crp=,st=,MedCacheHub=,codeployed=X,softstate=
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << sap-server: true
2019/05/24 16:58:22:061 CST [DEBUG] headers – http-outgoing-0 << sap-perf-fesrec: 42584.000000
2019/05/24 16:58:22:061 CST [DEBUG] MainClientExec – Connection can be kept alive indefinitely
2019/05/24 16:58:22:061 CST [DEBUG] PoolingHttpClientConnectionManager – Connection [id: 0][route: {s}->hybris.com:443] can be kept alive indefinitely
2019/05/24 16:58:22:061 CST [DEBUG] PoolingHttpClientConnectionManager – Connection released: [id: 0][route: {s}->hybris.com:443][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
2019/05/24 16:58:22:061 CST [DEBUG] ResponseProcessCookies – Cookie accepted [sap-usercontext=“sap-client=100”, version:0, domain:hybris.com, path:/, expiry:null]
2019/05/24 16:58:22:061 CST [DEBUG] ResponseProcessCookies – Cookie accepted [SAP_SESSIONID_E4T_100=“a-dtZMlUCPrNMQYUQYcL8RULy6l-AhHpqRECAAohIHE%3d”, version:0, domain:gdm-acdo.apjdemo.hybris.com, path:/, expiry:null]
2019/05/24 16:58:22:925 CST [DEBUG] DefaultRedirectStrategy – Redirect requested to location ‘hybris.com:443/sap/opu/oda…’
2019/05/24 16:58:24:219 CST [DEBUG] RedirectExec – Redirecting to ‘hybris.com:443/sap/opu/oda…’ via {s}->gdm-acdo.apjdemo.hybris.com:443
2019/05/24 16:58:24:230 CST [DEBUG] RequestAddCookies – CookieSpec selected: default
2019/05/24 16:58:24:230 CST [DEBUG] RequestAddCookies – Cookie [version: 0][name: SAP_SESSIONID_E4T_100][value: a-dtZMlUCPrNMQYUQYcL8RULy6l-AhHpqRECAAohIHE%3d][domain: gdm-acdo.apjdemo.hybris.com][path: /][expiry: null] match [(secure)hybris.com:443/sap/opu/oda…]
2019/05/24 16:58:24:230 CST [DEBUG] RequestAddCookies – Cookie [version: 0][name: sap-usercontext][value: sap-client=100][domain: gdm-acdo.apjdemo.hybris.com][path: /][expiry: null] match [(secure)hybris.com:443/sap/opu/oda…]
2019/05/24 16:58:24:231 CST [DEBUG] RequestAuthCache – Auth cache not set in the context
2019/05/24 16:58:24:995 CST [DEBUG] PoolingHttpClientConnectionManager – Connection request: [route: {s}->hybris.com:443][total kept alive: 1; route allocated: 1 of 2; total allocated: 1 of 20]
2019/05/24 16:58:24:997 CST [DEBUG] wire – http-outgoing-0 << “[read] I/O error: Read timed out”
2019/05/24 16:58:24:997 CST [DEBUG] PoolingHttpClientConnectionManager – Connection leased: [id: 0][route: {s}->hybris.com:443][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
2019/05/24 16:58:24:998 CST [DEBUG] MainClientExec – Executing request GET /sap/opu/odata/sap/CUAN_CONTACT_SRV/ HTTP/1.1
2019/05/24 16:58:24:998 CST [DEBUG] MainClientExec – Proxy auth state: UNCHALLENGED
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> GET /sap/opu/odata/sap/CUAN_CONTACT_SRV/ HTTP/1.1
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Authorization: basic bWt0X2Rl5
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Cache-Control: no-cache
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> content-type: application/json
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Accept: application/json
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> x-csrf-token: fetch
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Host: gdm-acdo.apjdemo.hybris.com:443
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Connection: Keep-Alive
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.1 (Java/1.8.0_60)
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Cookie: SAP_SESSIONID_E4T_100=a-dtZMlUYcL8RULy6l-AhHpqRECAAohIHE%3d; sap-usercontext=sap-client=100
2019/05/24 16:58:24:998 CST [DEBUG] headers – http-outgoing-0 >> Accept-Encoding: gzip,deflate
2019/05/24 16:58:24:998 CST [DEBUG] wire – http-outgoing-0 >> “GET /sap/opu/odata/sap/CUAN_CONTACT_SRV/ HTTP/1.1[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Authorization: basic bWt0X2RldjpNWVdlbGNvbWU5[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Cache-Control: no-cache[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “content-type: application/json[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Accept: application/json[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “x-csrf-token: fetch[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Host: hybris.com:443[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Connection: Keep-Alive[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “User-Agent: Apache-HttpClient/4.5.1 (Java/1.8.0_60)[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Cookie: SAP_SESSIONID_E4T_100=a-dtZMlUCPrhIHE%3d; sap-usercontext=sap-client=100[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “Accept-Encoding: gzip,deflate[\r][\n]”
2019/05/24 16:58:24:999 CST [DEBUG] wire – http-outgoing-0 >> “[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “HTTP/1.1 500 Internal Server Error[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “Server: nginx/1.14.2[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “Date: Fri, 24 May 2019 08:58:25 GMT[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “Content-Type: text/html[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “Content-Length: 193[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “Connection: close[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “[\r][\n]”
2019/05/24 16:58:25:154 CST [DEBUG] wire – http-outgoing-0 << “[\r][\n]”
2019/05/24 16:58:25:155 CST [DEBUG] wire – http-outgoing-0 << “[\r][\n]”
2019/05/24 16:58:25:155 CST [DEBUG] wire – http-outgoing-0 << “[\r][\n]”
2019/05/24 16:58:25:155 CST [DEBUG] wire – http-outgoing-0 << “
500 Internal Server Error
[\r][\n] “2019/05/24 16:58:25:155 CST [DEBUG] wire-http-outgoing-0 <<“
Nginx / 1.14.2
[\r][\n] “2019/05/24 16:58:25:155 CST [DEBUG] wire-http-outgoing -0 <<” [\r][\n] “2019/05/24 16:58:25:155 CST [DEBUG]” 2019/05/24 16:58:25:155 CST [DEBUG] Wire-http-outgoing-0 << “[\r][\n]” 2019/05/24 16:58:25:155 CST [DEBUG] headers http-outgoing-0 << HTTP/1.1 500 Internal Server Error 2019/05/24 16:58:25:155 CST [DEBUG] headers – http-outgoing-0 << Server: Nginx /1.14.2 2019/05/24 16:58:25:155 CST [DEBUG] headers http-outgoing-0 << Date: Fri, 24 May 2019 08:58:25 GMT 2019/05/24 16:58:25:155 CST [DEBUG] headers – http-outgoing-0 << Content-Type: text/html 2019/05/24 16:58:25:155 CST [DEBUG] headers – http-outgoing-0 << Content-Length: 193 2019/05/24 16:58:25:155 CST [DEBUG] headers – http-outgoing-0 << Connection: close Status code: 500 reason: Internal Server Error