We're using SAP Cloud SDK 3.32.0 with SpringBoot. We've generated a typed OData service based on the EDMX metadata file generated by the service and use the generated client in our code. All logs entries showing our issue are below (cleaned them up a bit to show the important parts only)
The situation is the following:
- We send a
myservice.createEntity(MyEntity).exectureRequest(myDestination)
with the generated client. Since this is a modifying/creating call, the client first requests a CSRF token. This works fine as shown in the logs below (first HEAD and POST calls) - Next we call a function with
myservice.myFunction(p1, p2, p3).executeRequest(myDestination)
. This is a function exposed by the same OData service, so the service path is the same. Since this function is aPOST
, the client will again try to fetch a CSRF token. However, this results in aHTTP 403 Forbidden
status code. We do not get the CSRF token (see secondHEAD
request in the logs below). - The function call is still executed, but with an empty
X-CSRF-Token
http header (second POST request in logs). - Although we seem to receive a response from the OData service, the client finallly times out (Read time out) and we are unable to process the result of the function call.
Debugging/clicking through the code of the CloudSDK, I discovered that the generated "FluentHelperFunction" class has it's own logic for retrieving the CSRF token (e.g. it uses "Fetch" in the HEAD requests), where as the FluentHelperCreate class uses the DefaultCsrfRetriever class (which uses lower case "fetch" for the HEAD call).
So my questions are:
- Why does the HEAD call for CSRF fail when done by a function call (i.e.
myservice.myFunction()
) - Why does the FluentHelperFunction class have it's own logic for getting a CSRF token?
- What can I do to make this work properly. Or is this a bug in the SDK?
Logs:
=== HEAD before create entity - Returns CSRF token OK -
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"HEAD http://dev-gateway-cd:443/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV HTTP/1.1[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"x-csrf-token: fetch[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Accept: application/json[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Content-Type: application/json[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Proxy-Authorization: Bearer eyJh...." }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"SAP-Connectivity-Authentication: Bearer eyJh...." }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"X-Requested-With: X-Requested-With[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"sap-language: en[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Host: dev-gateway-cd:443[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Proxy-Connection: Keep-Alive[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.8)[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Accept-Encoding: gzip,deflate[\\r][\\n]\"" }
2020-11-19T08:54:57.02+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"HTTP/1.1 200 OK[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"content-type: text/html[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"content-length: 0[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"x-csrf-token: 38IQnzDSn6aZeqmFczbqQA==[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"sap-processing-info: microhub=,crp=,st=,MedCacheHub=,codeployed=,softstate=-[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"sap-perf-fesrec: 28128.000000[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"set-cookie: sap-usercontext=sap-language=en&sap-client=550; path=/[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"set-cookie: MYSAPSSO2=AjQxMDMBABhBAEwAMgAyADIANwA2ACAAIAAgACAAIAACAAY1ADUAMAADABBEAEcAVwAgACAAIAAgACAABAAYMgAwADIAMAAxADEAMQA5ADAANwA1ADQABQAEAAAACAYAAlgACQACRQD%2fASswggEnBgkqhkiG9w0BBwKgggEYMIIBFAIBATELMAkGBSsOAwIaBQAwCwYJKoZIhvcNAQcBMYH0MIHxAgEBMEcwOjEVMBMGA1UEChMMU0FQIFNlY3VyaXR5MSEwHwYDVQQDExhTZWN1cmUgTG9naW4gVXNlciBTdWIgQ0ECCQQz%21dD%2f97ncUTAJBgUrDgMCGgUAoF0wGAYJKoZIhvcNAQkDMQsGCSqGSIb3DQEHATAcBgkqhkiG9w0BCQUxDxcNMjAxMTE5MDc1NDU3WjAjBgkqhkiG9w0BCQQxFgQU4PBXYuos4C1Bm%21YztJ4J8CdsGQ4wCQYHKoZIzjgEAwQuMCwCFCavVSRTFJsKNa3srFhnEbOByT8GAhRHSbed50wUDAOB4AYClz%2ftvf3pYg%3d%3d; path=/; domain=dev-gateway-cd; HttpOnly[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"set-cookie: SAP_SESSIONID_DGW_550=4BFhS5Wq30GRv2nbzjuNh4RHkVUqPBHrpSgCOIUjX_g%3d; path=/; HttpOnly[\\r][\\n]\"" }
2020-11-19T08:54:57.10+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"[\\r][\\n]\"" }
=== POST Create entity - Uses CSRF token from previous HEAD request -
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"POST http://dev-gateway-cd:443/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/HeaderSet HTTP/1.1[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Accept: application/json[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"x-csrf-token: 38IQnzDSn6aZeqmFczbqQA==[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Content-Type: application/json[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Proxy-Authorization: Bearer eyJh...." }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"SAP-Connectivity-Authentication: Bearer eyJh...." }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"X-Requested-With: X-Requested-With[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"sap-language: en[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Content-Length: 1223[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Host: dev-gateway-cd:443[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Proxy-Connection: Keep-Alive[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.8)[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Cookie: MYSAPSSO2=AjQxMDMBABhBAEwAMgAyADIANwA2ACAAIAAgACAAIAACAAY1ADUAMAADABBEAEcAVwAgACAAIAAgACAABAAYMgAwADIAMAAxADEAMQA5ADAANwA1ADQABQAEAAAACAYAAlgACQACRQD%2fASswggEnBgkqhkiG9w0BBwKgggEYMIIBFAIBATELMAkGBSsOAwIaBQAwCwYJKoZIhvcNAQcBMYH0MIHxAgEBMEcwOjEVMBMGA1UEChMMU0FQIFNlY3VyaXR5MSEwHwYDVQQDExhTZWN1cmUgTG9naW4gVXNlciBTdWIgQ0ECCQQz%21dD%2f97ncUTAJBgUrDgMCGgUAoF0wGAYJKoZIhvcNAQkDMQsGCSqGSIb3DQEHATAcBgkqhkiG9w0BCQUxDxcNMjAxMTE5MDc1NDU3WjAjBgkqhkiG9w0BCQQxFgQU4PBXYuos4C1Bm%21YztJ4J8CdsGQ4wCQYHKoZIzjgEAwQuMCwCFCavVSRTFJsKNa3srFhnEbOByT8GAhRHSbed50wUDAOB4AYClz%2ftvf3pYg%3d%3d; SAP_SESSIONID_DGW_550=4BFhS5Wq30GRv2nbzjuNh4RHkVUqPBHrpSgCOIUjX_g%3d; sap-usercontext=sap-language=en&sap-client=550[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"Accept-Encoding: gzip,deflate[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"[\\r][\\n]\"" }
2020-11-19T08:54:57.11+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 >> \"{\"DesNum\":\"290272\",\"PeItemSet\":[{\"InternPeId\":3,\"Taaklijst\":\"4316\",\"DesGuid\":\"02656ec2-ef0e-1edb-87b8-8a32b6cf28c7\",\"LevelCounter\":1,\"DesNum\":\"290272\",\"Supcunr\":2,\"Parcunr\":2,\"PeId\":\"43004631\",\"ProductID\":\"114010\",\"PeLevel\":3,\"PeTxt\":\"Aansluiting E AC4a tm 3x160A\",\"PeType\":\"1\",\"Uitvoeringsfactor\":\"1\",\"Eenheid\":\"ST\",\"SoortWerk\":\"00\"},{\"InternPeId\":2,\"Taaklijst\":\"2766\",\"DesGuid\":\"02656ec2-ef0e-1edb-87b8-8a32b6cf28c7\",\"LevelCounter\":1,\"DesNum\":\"290272\",\"Supcunr\":1,\"Parcunr\":2,\"PeId\":\"43003082\",\"ProductID\":\"114010\",\"PeLevel\":2,\"PeTxt\":\"E MAKEN AC4A AANSLUITING\",\"PeType\":\"V\",\"Uitvoeringsfactor\":\"1\",\"OptOmp\":false,\"SoortWerk\":\"05\",\"SoortWerkOmschrijving\":\"Uitbreiding\"},{\"InternPeId\":4,\"Taaklijst\":\"6317\",\"DesGuid\":\"02656ec2-ef0e-1edb-87b8-8a32b6cf28c7\",\"LevelCounter\":2,\"DesNum\":\"290272\",\"Supcunr\":1,\"Parcunr\":4,\"PeId\":\"43006902\",\"PeLevel\":2,\"PeTxt\":\"E Combi SION Baas Flevo\",\"PeType\":\"1\",\"Uitvoeringsfactor\":\"0\",\"Eenheid\":\"ST\",\"OptOmp\":false},{\"InternPeId\":5,\"Taaklijst\":\"4977\",\"DesGuid\":\"02656ec2-ef0e-1edb-87b8-8a32b6cf28c7\",\"LevelCounter\":3,\"DesNum\":\"290272\",\"Supcunr\":1,\"Parcunr\":5,\"PeId\":\"43005291\",\"PeLevel\":2,\"PeTxt\":\"ALG. PE-UREN - R\\u0026N\",\"PeType\":\"1\",\"Uitvoeringsfactor\":\"0\",\"Eenheid\":\"ST\",\"OptOmp\":false}]}\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"HTTP/1.1 201 Created[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"content-type: application/json; charset=utf-8[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"content-length: 739[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"dataserviceversion: 2.0[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"sap-processing-info: microhub=,crp=,st=,MedCacheHub=SHM,codeployed=,softstate=[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"sap-perf-fesrec: 523322.000000[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"content-encoding: gzip[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"location: http://dev-gateway-cd:443/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/HeaderSet('290272')[\\r][\\n]\"" }
2020-11-19T08:54:57.65+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-15 << \"[\\r][\\n]\"" }
=== HEAD before function call (FinalizeConcept) - Return 403 Forbidden response and no CSRF token -
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"HEAD http://dev-gateway-cd:443/opu/odata/sap/ZCU_PE_CONCEPT_SRV HTTP/1.1[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"x-csrf-token: Fetch[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Proxy-Authorization: Bearer eyJh...." }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"SAP-Connectivity-Authentication: Bearer eyJh...." }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"X-Requested-With: X-Requested-With[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"sap-language: en[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Host: dev-gateway-cd:443[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Proxy-Connection: Keep-Alive[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.8)[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Accept-Encoding: gzip,deflate[\\r][\\n]\"" }
2020-11-19T08:54:57.69+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"HTTP/1.1 403 Forbidden[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"content-type: text/plain; charset=utf-8[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"content-length: 188[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"Access denied to resource /opu/odata/sap/ZCU_PE_CONCEPT_SRV on system dev-gateway-cd:443. In case this was a valid request, ensure to expose the resource correctly in your cloud connector.\"" }
=== POST call function (FinalizeConcept) - Still executes request without CSRF token -
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"POST http://dev-gateway-cd:443/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/FinalizeConcept?contractPositie='00001'&contract='4600001985'&desNum='290272'&$format=json HTTP/1.1[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"x-csrf-token: [\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Proxy-Authorization: Bearer eyJh...." }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"SAP-Connectivity-Authentication: Bearer eyJh...." }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"X-Requested-With: X-Requested-With[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"sap-language: en[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Host: dev-gateway-cd:443[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Proxy-Connection: Keep-Alive[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"User-Agent: Apache-HttpClient/4.5.12 (Java/11.0.8)[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"Accept-Encoding: gzip,deflate[\\r][\\n]\"" }
2020-11-19T08:54:57.70+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 >> \"[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"HTTP/1.1 200 OK[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"content-type: application/json; charset=utf-8[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"content-length: 856[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"dataserviceversion: 2.0[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"cache-control: no-cache, no-store[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"pragma: no-cache[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"sap-processing-info: microhub=,crp=,st=,MedCacheHub=SHM,codeployed=,softstate=[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"sap-perf-fesrec: 15758403.000000[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"set-cookie: sap-usercontext=sap-language=en&sap-client=550; path=/[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"set-cookie: MYSAPSSO2=AjQxMDMBABhBAEwAMgAyADIANwA2ACAAIAAgACAAIAACAAY1ADUAMAADABBEAEcAVwAgACAAIAAgACAABAAYMgAwADIAMAAxADEAMQA5ADAANwA1ADQABQAEAAAACAYAAlgACQACRQD%2fASswggEnBgkqhkiG9w0BBwKgggEYMIIBFAIBATELMAkGBSsOAwIaBQAwCwYJKoZIhvcNAQcBMYH0MIHxAgEBMEcwOjEVMBMGA1UEChMMU0FQIFNlY3VyaXR5MSEwHwYDVQQDExhTZWN1cmUgTG9naW4gVXNlciBTdWIgQ0ECCQQz%21dD%2f97ncUTAJBgUrDgMCGgUAoF0wGAYJKoZIhvcNAQkDMQsGCSqGSIb3DQEHATAcBgkqhkiG9w0BCQUxDxcNMjAxMTE5MDc1NDU3WjAjBgkqhkiG9w0BCQQxFgQU4PBXYuos4C1Bm%21YztJ4J8CdsGQ4wCQYHKoZIzjgEAwQuMCwCFAqryT5UyRSqtelnADn%214ExvPaHGAhQFUmkaZVG1UL%21iM4Wz3sb%21triClQ%3d%3d; path=/; domain=dev-gateway-cd; HttpOnly[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"set-cookie: SAP_SESSIONID_DGW_550=ufIRFLfZoVbkIXV-6RengoRHkVwqPBHrpSgCOIUjX_g%3d; path=/; HttpOnly[\\r][\\n]\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"[\\r][\\n]\"" }
=== We do seem to receive a response
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"{\"d\":{\"__metadata\":{\"id\":\"https://vhanddgwci.hec.alliander.local:44300/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/HeaderSet('290272')\",\"uri\":\"https://vhanddgwci.hec.alliander.local:44300/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/HeaderSet('290272')\",\"type\":\"ZCU_PE_CONCEPT_SRV.Header\"},\"Contract\":\"4600001985\",\"DesGuid\":\"02656ec2-ef0e-1edb-87b8-8a32b6cf28c7\",\"PsReference\":\"\",\"ContractPositie\":\"00001\",\"DesNum\":\"290272\",\"DesType\":\"D\",\"Ktext\":\"PMD - 20201103 Artemisweg 55 Lelystad\",\"OhOrganisatie\":\"2300\",\"OhPlanningsgroep\":\"MCR\",\"Werkplek\":\"IPRH\",\"OhPrestatie\":\"R&N\",\"BasisStart\":\"\\/Date(1596153600000)\\/\",\"BasisEinde\":\"\\/Date(1597363200000)\\/\",\"PeOrder\":\"4108510\",\"Bouwmaatregel\":\"223942\",\"Wbs\":\"IPR-21007813-0001\",\"PeItemSet\":{\"__deferred\":{\"uri\":\"https://vhanddgwci.hec.alliander.local:44300/sap/opu/odata/sap/ZCU_PE_CONCEPT_SRV/HeaderSet('290272')/PeItemSet\"}}}}\"" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: Access denied to resource /opu/odata/sap/ZCU_PE_CONCEPT_SRV on system dev-gateway-cd:443. In case this was a valid request, ensure to expose the resource correctly in your cloud connector.HTTP/1.1 200 OK" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: content-type: application/json; charset=utf-8" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: content-length: 856" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: dataserviceversion: 2.0" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: cache-control: no-cache, no-store" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: pragma: no-cache" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: sap-processing-info: microhub=,crp=,st=,MedCacheHub=SHM,codeployed=,softstate=" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: sap-perf-fesrec: 15758403.000000" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: set-cookie: sap-usercontext=sap-language=en&sap-client=550; path=/" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: set-cookie: MYSAPSSO2=AjQxMDMBABhBAEwAMgAyADIANwA2ACAAIAAgACAAIAACAAY1ADUAMAADABBEAEcAVwAgACAAIAAgACAABAAYMgAwADIAMAAxADEAMQA5ADAANwA1ADQABQAEAAAACAYAAlgACQACRQD%2fASswggEnBgkqhkiG9w0BBwKgggEYMIIBFAIBATELMAkGBSsOAwIaBQAwCwYJKoZIhvcNAQcBMYH0MIHxAgEBMEcwOjEVMBMGA1UEChMMU0FQIFNlY3VyaXR5MSEwHwYDVQQDExhTZWN1cmUgTG9naW4gVXNlciBTdWIgQ0ECCQQz%21dD%2f97ncUTAJBgUrDgMCGgUAoF0wGAYJKoZIhvcNAQkDMQsGCSqGSIb3DQEHATAcBgkqhkiG9w0BCQUxDxcNMjAxMTE5MDc1NDU3WjAjBgkqhkiG9w0BCQQxFgQU4PBXYuos4C1Bm%21YztJ4J8CdsGQ4wCQYHKoZIzjgEAwQuMCwCFAqryT5UyRSqtelnADn%214ExvPaHGAhQFUmkaZVG1UL%21iM4Wz3sb%21triClQ%3d%3d; path=/; domain=dev-gateway-cd; HttpOnly" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: set-cookie: SAP_SESSIONID_DGW_550=ufIRFLfZoVbkIXV-6RengoRHkVwqPBHrpSgCOIUjX_g%3d; path=/; HttpOnly" }
2020-11-19T08:55:13.56+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.impl.conn.DefaultHttpResponseParser","level":"DEBUG","msg":"Garbage in response: " }
=== Finally a "Read timeout"
2020-11-19T08:57:13.66+0100 [APP/PROC/WEB/0] OUT { "logger":"o.a.h.wire","level":"DEBUG","msg":"http-outgoing-16 << \"[read] I/O error: Read timed out\"" }
Thanks,
Danny