Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

CSRF token validation failed - SAP Business Application Studio destination with on-premise destination #1037

Closed
maxstreifeneder opened this issue Feb 23, 2021 · 14 comments
Closed

CSRF token validation failed - SAP Business Application Studio destination with on-premise destination #1037

maxstreifeneder opened this issue Feb 23, 2021 · 14 comments
Labels
bug Something isn't working

Comments

@maxstreifeneder
Copy link
Member

Describe the bug
Similar issue as #617 from my point of view.

Debugging a CAP + Cloud SDK app in BAS using a destination with type on-premise fails with "CSRF Token validation failed" (OData read/select works) while the deployed app in CF works fine.

Happy to provide more insights/guidance/explanation if necessary. Thanks already in advance :-)

To Reproduce
Steps to reproduce the behavior:

  1. git clone https://github.tools.sap/D063937/cloud-sdk-destination-issue.git in BAS

  2. npm install

  3. mbt build && f deploy mta_archives/test_1.0.0.mtar

  4. Create a run configuration of type CAP and connect to the destination (should start the built in proxy)
    image

  5. Bind the services from the previously deployed MTA (connectivity, destination, xsuaa) to your local app.

  6. merge the destination + VCAP_services information into one .env file (usually different files) and double check that the .env file in the .vscode/launch.jsonis properly set.

  7. Start the run configuration
    image

  8. Go to /test/requests.http and send the request to fire the getAllBupa function
    -> Business Partner from S/4 on prem will be listed in the console

  9. send the request to fire the insertBupa_ function. This won't work.

  10. Do the same with the URL for the deployed app and watch the logs with cf logs test-srv - you will see that the CSRF token handle works perfectly as expected.

Expected behavior
Cloud SDK takes care of the full CSRF token handling, no matter if there's a proxy of BAS between the connectivity the service and the locally running app in BAS or not.

Screenshots
If applicable, add screenshots to help explain your problem.

Used Versions:

  • node: v10.23.1
  • npm: 6.14.10
  • SAP Cloud SDK version: "@sap/cloud-sdk-vdm-business-partner-service": "^1.24.0",

Code Examples
https://github.tools.sap/D063937/cloud-sdk-destination-issue/blob/master/srv/catalog-service.js#L10-L18

Log file

Log output in BAS:

[cds] - GET /test/insertBupa()
{"message":"Attempting to retrieve destination from environment variable.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.890Z","msg":"Attempting to retrieve destination from environment variable.","written_ts":1614115793890,"written_at":"2021-02-23T21:29:53.890Z"}
{"message":"Environment variable 'destinations' is set. Destinations will be read from this variable. This is discouraged for a productive application! Unset the variable to read destinations from the destination service on SAP Cloud Platform.","level":"warn","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.891Z","msg":"Environment variable 'destinations' is set. Destinations will be read from this variable. This is discouraged for a productive application! Unset the variable to read destinations from the destination service on SAP Cloud Platform.","written_ts":1614115793891,"written_at":"2021-02-23T21:29:53.891Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.892Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614115793892,"written_at":"2021-02-23T21:29:53.892Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.892Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614115793892,"written_at":"2021-02-23T21:29:53.892Z"}
{"message":"Proxy settings for http are found in environment variables.","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.893Z","msg":"Proxy settings for http are found in environment variables.","written_ts":1614115793893,"written_at":"2021-02-23T21:29:53.893Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.893Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614115793893,"written_at":"2021-02-23T21:29:53.893Z"}
{"message":"Successfully retrieved destination from environment variable.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.894Z","msg":"Successfully retrieved destination from environment variable.","written_ts":1614115793894,"written_at":"2021-02-23T21:29:53.894Z"}
{"message":"The custom headers are provided with the keys: x-csrf-token. These keys will overwrite the headers created by the SDK.","level":"warn","custom_fields":{"package":"core","messageContext":"http-client"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:53.898Z","msg":"The custom headers are provided with the keys: x-csrf-token. These keys will overwrite the headers created by the SDK.","written_ts":1614115793898,"written_at":"2021-02-23T21:29:53.898Z"}
{"message":"Destination did not return a CSRF token. This may cause a failure when sending the OData request.","level":"warn","custom_fields":{"package":"core","messageContext":"csrf-token-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:54.659Z","msg":"Destination did not return a CSRF token. This may cause a failure when sending the OData request.","written_ts":1614115794659,"written_at":"2021-02-23T21:29:54.659Z"}
{"message":"CSRF header response does not include cookies.","level":"warn","custom_fields":{"package":"core","messageContext":"csrf-token-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:54.659Z","msg":"CSRF header response does not include cookies.","written_ts":1614115794659,"written_at":"2021-02-23T21:29:54.659Z"}
{"message":"The custom headers are provided with the keys: content-type,accept. These keys will overwrite the headers created by the SDK.","level":"warn","custom_fields":{"package":"core","messageContext":"http-client"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:29:54.660Z","msg":"The custom headers are provided with the keys: content-type,accept. These keys will overwrite the headers created by the SDK.","written_ts":1614115794660,"written_at":"2021-02-23T21:29:54.660Z"}
  • (some lines cut off in between)
                    needReadable: true,
                    emittedReadable: false,
                    readableListening: false,
                    resumeScheduled: false,
                    paused: false,
                    emitClose: false,
                    autoDestroy: false,
                    destroyed: false,
                    defaultEncoding: 'utf8',
                    awaitDrain: 0,
                    readingMore: false,
                    decoder: null,
                    encoding: null },
                 readable: true,
                 _events:
                  [Object: null prototype] {
                    end: [Function: onReadableStreamEnd],
                    free: { [Function: bound onceWrapper] listener: [Function] },
                    drain: [Function: ondrain],
                    error: [Function: socketErrorListener],
                    close: [Function: socketCloseListener],
                    finish:
                     { [Function: bound onceWrapper] listener: [Function: destroy] } },
                 _eventsCount: 6,
                 _maxListeners: undefined,
                 _writableState:
                  WritableState {
                    objectMode: false,
                    highWaterMark: 16384,
                    finalCalled: true,
                    needDrain: false,
                    ending: true,
                    ended: true,
                    finished: false,
                    destroyed: false,
                    decodeStrings: false,
                    defaultEncoding: 'utf8',
                    length: 0,
                    writing: false,
                    corked: 0,
                    sync: false,
                    bufferProcessing: false,
                    onwrite: [Function: bound onwrite],
                    writecb: null,
                    writelen: 0,
                    bufferedRequest: null,
                    lastBufferedRequest: null,
                    pendingcb: 1,
                    prefinished: false,
                    errorEmitted: false,
                    emitClose: false,
                    autoDestroy: false,
                    bufferedRequestCount: 0,
                    corkedRequestsFree:
                     { next:
                        { next: null,
                          entry: null,
                          finish: [Function: bound onCorkedFinish] },
                       entry: null,
                       finish: [Function: bound onCorkedFinish] } },
                 writable: false,
                 allowHalfOpen: false,
                 _sockname: null,
                 _pendingData: null,
                 _pendingEncoding: '',
                 server: null,
                 _server: null,
                 parser: null,
                 _httpMessage: [Circular],
                 [Symbol(asyncId)]: 402,
                 [Symbol(lastWriteQueueSize)]: 0,
                 [Symbol(timeout)]: null,
                 [Symbol(kBytesRead)]: 0,
                 [Symbol(kBytesWritten)]: 0 },
              connection:
               Socket {
                 connecting: false,
                 _hadError: false,
                 _handle:
                  TCP {
                    reading: true,
                    onread: [Function: onStreamRead],
                    onconnection: null,
                    [Symbol(owner)]: [Circular] },
                 _parent: null,
                 _host: null,
                 _readableState:
                  ReadableState {
                    objectMode: false,
                    highWaterMark: 16384,
                    buffer: BufferList { head: null, tail: null, length: 0 },
                    length: 0,
                    pipes: null,
                    pipesCount: 0,
                    flowing: true,
                    ended: false,
                    endEmitted: false,
                    reading: true,
                    sync: false,
                    needReadable: true,
                    emittedReadable: false,
                    readableListening: false,
                    resumeScheduled: false,
                    paused: false,
                    emitClose: false,
                    autoDestroy: false,
                    destroyed: false,
                    defaultEncoding: 'utf8',
                    awaitDrain: 0,
                    readingMore: false,
                    decoder: null,
                    encoding: null },
                 readable: true,
                 _events:
                  [Object: null prototype] {
                    end: [Function: onReadableStreamEnd],
                    free: { [Function: bound onceWrapper] listener: [Function] },
                    drain: [Function: ondrain],
                    error: [Function: socketErrorListener],
                    close: [Function: socketCloseListener],
                    finish:
                     { [Function: bound onceWrapper] listener: [Function: destroy] } },
                 _eventsCount: 6,
                 _maxListeners: undefined,
                 _writableState:
                  WritableState {
                    objectMode: false,
                    highWaterMark: 16384,
                    finalCalled: true,
                    needDrain: false,
                    ending: true,
                    ended: true,
                    finished: false,
                    destroyed: false,
                    decodeStrings: false,
                    defaultEncoding: 'utf8',
                    length: 0,
                    writing: false,
                    corked: 0,
                    sync: false,
                    bufferProcessing: false,
                    onwrite: [Function: bound onwrite],
                    writecb: null,
                    writelen: 0,
                    bufferedRequest: null,
                    lastBufferedRequest: null,
                    pendingcb: 1,
                    prefinished: false,
                    errorEmitted: false,
                    emitClose: false,
                    autoDestroy: false,
                    bufferedRequestCount: 0,
                    corkedRequestsFree:
                     { next:
                        { next: null,
                          entry: null,
                          finish: [Function: bound onCorkedFinish] },
                       entry: null,
                       finish: [Function: bound onCorkedFinish] } },
                 writable: false,
                 allowHalfOpen: false,
                 _sockname: null,
                 _pendingData: null,
                 _pendingEncoding: '',
                 server: null,
                 _server: null,
                 parser: null,
                 _httpMessage: [Circular],
                 [Symbol(asyncId)]: 402,
                 [Symbol(lastWriteQueueSize)]: 0,
                 [Symbol(timeout)]: null,
                 [Symbol(kBytesRead)]: 0,
                 [Symbol(kBytesWritten)]: 0 },
              _header:
               'PATCH http://businesspartner.dest/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27) HTTP/1.1\r\nAccept: application/json\r\nContent-Type: application/json\r\nUser-Agent: axios/0.21.1\r\nContent-Length: 48\r\nHost: businesspartner.dest\r\nConnection: close\r\n\r\n',
              _onPendingData: [Function: noopPendingOutput],
              agent:
               HttpProxyAgent {
                 _events: [Object: null prototype] {},
                 _eventsCount: 0,
                 _maxListeners: undefined,
                 timeout: null,
                 maxFreeSockets: 1,
                 maxSockets: 1,
                 maxTotalSockets: Infinity,
                 sockets: {},
                 freeSockets: {},
                 requests: {},
                 options: {},
                 secureProxy: false,
                 proxy:
                  { protocol: 'http:',
                    slashes: true,
                    auth: null,
                    host: '127.0.0.1',
                    port: 8887,
                    hostname: '127.0.0.1',
                    hash: null,
                    search: null,
                    query: null,
                    href: 'http://127.0.0.1:8887/' },
                 promisifiedCallback: [Function: callback] },
              socketPath: undefined,
              timeout: undefined,
              method: 'PATCH',
              insecureHTTPParser: undefined,
              path:
               'http://businesspartner.dest/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27)',
              _ended: true,
              res:
               IncomingMessage {
                 _readableState:
                  ReadableState {
                    objectMode: false,
                    highWaterMark: 16384,
                    buffer: BufferList { head: null, tail: null, length: 0 },
                    length: 0,
                    pipes: null,
                    pipesCount: 0,
                    flowing: true,
                    ended: true,
                    endEmitted: true,
                    reading: false,
                    sync: true,
                    needReadable: false,
                    emittedReadable: false,
                    readableListening: false,
                    resumeScheduled: false,
                    paused: false,
                    emitClose: true,
                    autoDestroy: false,
                    destroyed: false,
                    defaultEncoding: 'utf8',
                    awaitDrain: 0,
                    readingMore: true,
                    decoder: null,
                    encoding: null },
                 readable: false,
                 _events:
                  [Object: null prototype] {
                    end: [ [Function: responseOnEnd], [Function: handleStreamEnd] ],
                    data: [Function: handleStreamData],
                    error: [Function: handleStreamError] },
                 _eventsCount: 3,
                 _maxListeners: undefined,
                 socket:
                  Socket {
                    connecting: false,
                    _hadError: false,
                    _handle:
                     TCP {
                       reading: true,
                       onread: [Function: onStreamRead],
                       onconnection: null,
                       [Symbol(owner)]: [Circular] },
                    _parent: null,
                    _host: null,
                    _readableState:
                     ReadableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       buffer: BufferList { head: null, tail: null, length: 0 },
                       length: 0,
                       pipes: null,
                       pipesCount: 0,
                       flowing: true,
                       ended: false,
                       endEmitted: false,
                       reading: true,
                       sync: false,
                       needReadable: true,
                       emittedReadable: false,
                       readableListening: false,
                       resumeScheduled: false,
                       paused: false,
                       emitClose: false,
                       autoDestroy: false,
                       destroyed: false,
                       defaultEncoding: 'utf8',
                       awaitDrain: 0,
                       readingMore: false,
                       decoder: null,
                       encoding: null },
                    readable: true,
                    _events:
                     [Object: null prototype] {
                       end: [Function: onReadableStreamEnd],
                       free: { [Function: bound onceWrapper] listener: [Function] },
                       drain: [Function: ondrain],
                       error: [Function: socketErrorListener],
                       close: [Function: socketCloseListener],
                       finish:
                        { [Function: bound onceWrapper] listener: [Function: destroy] } },
                    _eventsCount: 6,
                    _maxListeners: undefined,
                    _writableState:
                     WritableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       finalCalled: true,
                       needDrain: false,
                       ending: true,
                       ended: true,
                       finished: false,
                       destroyed: false,
                       decodeStrings: false,
                       defaultEncoding: 'utf8',
                       length: 0,
                       writing: false,
                       corked: 0,
                       sync: false,
                       bufferProcessing: false,
                       onwrite: [Function: bound onwrite],
                       writecb: null,
                       writelen: 0,
                       bufferedRequest: null,
                       lastBufferedRequest: null,
                       pendingcb: 1,
                       prefinished: false,
                       errorEmitted: false,
                       emitClose: false,
                       autoDestroy: false,
                       bufferedRequestCount: 0,
                       corkedRequestsFree:
                        { next:
                           { next: null,
                             entry: null,
                             finish: [Function: bound onCorkedFinish] },
                          entry: null,
                          finish: [Function: bound onCorkedFinish] } },
                    writable: false,
                    allowHalfOpen: false,
                    _sockname: null,
                    _pendingData: null,
                    _pendingEncoding: '',
                    server: null,
                    _server: null,
                    parser: null,
                    _httpMessage: [Circular],
                    [Symbol(asyncId)]: 402,
                    [Symbol(lastWriteQueueSize)]: 0,
                    [Symbol(timeout)]: null,
                    [Symbol(kBytesRead)]: 0,
                    [Symbol(kBytesWritten)]: 0 },
                 connection:
                  Socket {
                    connecting: false,
                    _hadError: false,
                    _handle:
                     TCP {
                       reading: true,
                       onread: [Function: onStreamRead],
                       onconnection: null,
                       [Symbol(owner)]: [Circular] },
                    _parent: null,
                    _host: null,
                    _readableState:
                     ReadableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       buffer: BufferList { head: null, tail: null, length: 0 },
                       length: 0,
                       pipes: null,
                       pipesCount: 0,
                       flowing: true,
                       ended: false,
                       endEmitted: false,
                       reading: true,
                       sync: false,
                       needReadable: true,
                       emittedReadable: false,
                       readableListening: false,
                       resumeScheduled: false,
                       paused: false,
                       emitClose: false,
                       autoDestroy: false,
                       destroyed: false,
                       defaultEncoding: 'utf8',
                       awaitDrain: 0,
                       readingMore: false,
                       decoder: null,
                       encoding: null },
                    readable: true,
                    _events:
                     [Object: null prototype] {
                       end: [Function: onReadableStreamEnd],
                       free: { [Function: bound onceWrapper] listener: [Function] },
                       drain: [Function: ondrain],
                       error: [Function: socketErrorListener],
                       close: [Function: socketCloseListener],
                       finish:
                        { [Function: bound onceWrapper] listener: [Function: destroy] } },
                    _eventsCount: 6,
                    _maxListeners: undefined,
                    _writableState:
                     WritableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       finalCalled: true,
                       needDrain: false,
                       ending: true,
                       ended: true,
                       finished: false,
                       destroyed: false,
                       decodeStrings: false,
                       defaultEncoding: 'utf8',
                       length: 0,
                       writing: false,
                       corked: 0,
                       sync: false,
                       bufferProcessing: false,
                       onwrite: [Function: bound onwrite],
                       writecb: null,
                       writelen: 0,
                       bufferedRequest: null,
                       lastBufferedRequest: null,
                       pendingcb: 1,
                       prefinished: false,
                       errorEmitted: false,
                       emitClose: false,
                       autoDestroy: false,
                       bufferedRequestCount: 0,
                       corkedRequestsFree:
                        { next:
                           { next: null,
                             entry: null,
                             finish: [Function: bound onCorkedFinish] },
                          entry: null,
                          finish: [Function: bound onCorkedFinish] } },
                    writable: false,
                    allowHalfOpen: false,
                    _sockname: null,
                    _pendingData: null,
                    _pendingEncoding: '',
                    server: null,
                    _server: null,
                    parser: null,
                    _httpMessage: [Circular],
                    [Symbol(asyncId)]: 402,
                    [Symbol(lastWriteQueueSize)]: 0,
                    [Symbol(timeout)]: null,
                    [Symbol(kBytesRead)]: 0,
                    [Symbol(kBytesWritten)]: 0 },
                 httpVersionMajor: 1,
                 httpVersionMinor: 1,
                 httpVersion: '1.1',
                 complete: true,
                 headers:
                  { 'content-length': '28',
                    'content-type': 'text/plain; charset=utf-8',
                    date: 'Tue, 23 Feb 2021 21:29:55 GMT',
                    'sap-perf-fesrec': '20749.000000',
                    'sap-processing-info':
                     'ODataBEP=,crp=,RAL=,st=,MedCacheHub=,codeployed=X,softstate=',
                    'sap-server': 'true',
                    'set-cookie':
                     [ 'ARBE=b495e4ffe60015994d0fa318954b96f235a5706c18ad8aeca366ae15c23680b8d3e794ee3403ca4a22e6611b885ec55cb13394db382a9e54f5c6a710ab25525d9fc6e186192c55114450b0be5d24c4dcaef6521c562edb3aa942eafac59abc85391cdb0966817bc55b4a2cbf766f69d732c973817bd3088b6a8f4b4ac1ee95f2e1d5d1f1963d0f0fe74603e42030843d875337c75d0bac4854b8e1354aea20805a75a839cbfc52baa810ff58df6937e7eb5dbf99f35cc2c103eb2495caad5f1b96b05374d9985999d350284dbdc641f6196ca26a444f602f93a4162894520a975df182428e3c17fc5f434842588c6fd326833b9c72e11a0d4c4d81ea9e77f1a196c250d801b14e0d5c8e4e4c932f02ca47989bfd95cedf8b89adc9e61231321649793401716fac36efd05825e76b121c973dbf021e1d2922b389eb34215187edadb4da447d1a542f43ed6f04bb850798d983cc9cd636d998c029a886c0172680dbd746d6f2b5d917e0382b19b854bf3c262d1ec3be4c13974283edd92309e9c2010e7985abe20334e440a935aef1430906afc681b94abd8331f329eb3d95f60e68f459550f53395113ffb75104167746ee783484b1eecf6410a0d7ff32e3fc3b3e24435bbbea79d5a716cd868114fcdcbbfa56c9c08f550512332efd97e0b9a7aa081c9284a9702f6433f0ea3e6f643dfaa0c6ade9e7a157492bed1985dbdcb5f780cd4f7fbbce6429c1c4cd444fcad7d4f1efa056c0eb5ecf62ec686d3f4c4e95c83704acf9b28e098a65f1c3dea5c008674868611bd0391659c1bdbecd6790801649e4898814035d7a84b624463e84910d335d52435bc6c2c72de4bd7d8755efcd7b0f0a7f77c0a516b035db6e41acb45235774b42f08bb1190dfe99c69998; Path=/; HttpOnly;' ],
                    'strict-transport-security': 'max-age=31536000; includeSubDomains; preload;',
                    vary: 'Accept-Encoding',
                    'x-csrf-token': 'Required',
                    'x-frame-options': 'SAMEORIGIN',
                    'x-request-id': '82dffecf-5f64-4a40-4d73-d173f8b5d96f',
                    'x-vcap-request-id': '82dffecf-5f64-4a40-4d73-d173f8b5d96f',
                    connection: 'close' },
                 rawHeaders:
                  [ 'Content-Length',
                    '28',
                    'Content-Type',
                    'text/plain; charset=utf-8',
                    'Date',
                    'Tue, 23 Feb 2021 21:29:55 GMT',
                    'Sap-Perf-Fesrec',
                    '20749.000000',
                    'Sap-Processing-Info',
                    'ODataBEP=,crp=,RAL=,st=,MedCacheHub=,codeployed=X,softstate=',
                    'Sap-Server',
                    'true',
                    'Set-Cookie',
                    'ARBE=b495e4ffe60015994d0fa318954b96f235a5706c18ad8aeca366ae15c23680b8d3e794ee3403ca4a22e6611b885ec55cb13394db382a9e54f5c6a710ab25525d9fc6e186192c55114450b0be5d24c4dcaef6521c562edb3aa942eafac59abc85391cdb0966817bc55b4a2cbf766f69d732c973817bd3088b6a8f4b4ac1ee95f2e1d5d1f1963d0f0fe74603e42030843d875337c75d0bac4854b8e1354aea20805a75a839cbfc52baa810ff58df6937e7eb5dbf99f35cc2c103eb2495caad5f1b96b05374d9985999d350284dbdc641f6196ca26a444f602f93a4162894520a975df182428e3c17fc5f434842588c6fd326833b9c72e11a0d4c4d81ea9e77f1a196c250d801b14e0d5c8e4e4c932f02ca47989bfd95cedf8b89adc9e61231321649793401716fac36efd05825e76b121c973dbf021e1d2922b389eb34215187edadb4da447d1a542f43ed6f04bb850798d983cc9cd636d998c029a886c0172680dbd746d6f2b5d917e0382b19b854bf3c262d1ec3be4c13974283edd92309e9c2010e7985abe20334e440a935aef1430906afc681b94abd8331f329eb3d95f60e68f459550f53395113ffb75104167746ee783484b1eecf6410a0d7ff32e3fc3b3e24435bbbea79d5a716cd868114fcdcbbfa56c9c08f550512332efd97e0b9a7aa081c9284a9702f6433f0ea3e6f643dfaa0c6ade9e7a157492bed1985dbdcb5f780cd4f7fbbce6429c1c4cd444fcad7d4f1efa056c0eb5ecf62ec686d3f4c4e95c83704acf9b28e098a65f1c3dea5c008674868611bd0391659c1bdbecd6790801649e4898814035d7a84b624463e84910d335d52435bc6c2c72de4bd7d8755efcd7b0f0a7f77c0a516b035db6e41acb45235774b42f08bb1190dfe99c69998; Path=/; HttpOnly;',
                    'Strict-Transport-Security',
                    'max-age=31536000; includeSubDomains; preload;',
                    'Vary',
                    'Accept-Encoding',
                    'X-Csrf-Token',
                    'Required',
                    'X-Frame-Options',
                    'SAMEORIGIN',
                    'X-Request-Id',
                    '82dffecf-5f64-4a40-4d73-d173f8b5d96f',
                    'X-Vcap-Request-Id',
                    '82dffecf-5f64-4a40-4d73-d173f8b5d96f',
                    'Connection',
                    'close' ],
                 trailers: {},
                 rawTrailers: [],
                 aborted: false,
                 upgrade: false,
                 url: '',
                 method: null,
                 statusCode: 403,
                 statusMessage: 'Forbidden',
                 client:
                  Socket {
                    connecting: false,
                    _hadError: false,
                    _handle:
                     TCP {
                       reading: true,
                       onread: [Function: onStreamRead],
                       onconnection: null,
                       [Symbol(owner)]: [Circular] },
                    _parent: null,
                    _host: null,
                    _readableState:
                     ReadableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       buffer: BufferList { head: null, tail: null, length: 0 },
                       length: 0,
                       pipes: null,
                       pipesCount: 0,
                       flowing: true,
                       ended: false,
                       endEmitted: false,
                       reading: true,
                       sync: false,
                       needReadable: true,
                       emittedReadable: false,
                       readableListening: false,
                       resumeScheduled: false,
                       paused: false,
                       emitClose: false,
                       autoDestroy: false,
                       destroyed: false,
                       defaultEncoding: 'utf8',
                       awaitDrain: 0,
                       readingMore: false,
                       decoder: null,
                       encoding: null },
                    readable: true,
                    _events:
                     [Object: null prototype] {
                       end: [Function: onReadableStreamEnd],
                       free: { [Function: bound onceWrapper] listener: [Function] },
                       drain: [Function: ondrain],
                       error: [Function: socketErrorListener],
                       close: [Function: socketCloseListener],
                       finish:
                        { [Function: bound onceWrapper] listener: [Function: destroy] } },
                    _eventsCount: 6,
                    _maxListeners: undefined,
                    _writableState:
                     WritableState {
                       objectMode: false,
                       highWaterMark: 16384,
                       finalCalled: true,
                       needDrain: false,
                       ending: true,
                       ended: true,
                       finished: false,
                       destroyed: false,
                       decodeStrings: false,
                       defaultEncoding: 'utf8',
                       length: 0,
                       writing: false,
                       corked: 0,
                       sync: false,
                       bufferProcessing: false,
                       onwrite: [Function: bound onwrite],
                       writecb: null,
                       writelen: 0,
                       bufferedRequest: null,
                       lastBufferedRequest: null,
                       pendingcb: 1,
                       prefinished: false,
                       errorEmitted: false,
                       emitClose: false,
                       autoDestroy: false,
                       bufferedRequestCount: 0,
                       corkedRequestsFree:
                        { next:
                           { next: null,
                             entry: null,
                             finish: [Function: bound onCorkedFinish] },
                          entry: null,
                          finish: [Function: bound onCorkedFinish] } },
                    writable: false,
                    allowHalfOpen: false,
                    _sockname: null,
                    _pendingData: null,
                    _pendingEncoding: '',
                    server: null,
                    _server: null,
                    parser: null,
                    _httpMessage: [Circular],
                    [Symbol(asyncId)]: 402,
                    [Symbol(lastWriteQueueSize)]: 0,
                    [Symbol(timeout)]: null,
                    [Symbol(kBytesRead)]: 0,
                    [Symbol(kBytesWritten)]: 0 },
                 _consuming: false,
                 _dumped: false,
                 req: [Circular],
                 responseUrl:
                  'http://businesspartner.dest/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27)',
                 redirects: [] },
              aborted: undefined,
              timeoutCb: null,
              upgradeOrConnect: false,
              parser: null,
              maxHeadersCount: null,
              _redirectable:
               Writable {
                 _writableState:
                  WritableState {
                    objectMode: false,
                    highWaterMark: 16384,
                    finalCalled: false,
                    needDrain: false,
                    ending: false,
                    ended: false,
                    finished: false,
                    destroyed: false,
                    decodeStrings: true,
                    defaultEncoding: 'utf8',
                    length: 0,
                    writing: false,
                    corked: 0,
                    sync: true,
                    bufferProcessing: false,
                    onwrite: [Function: bound onwrite],
                    writecb: null,
                    writelen: 0,
                    bufferedRequest: null,
                    lastBufferedRequest: null,
                    pendingcb: 0,
                    prefinished: false,
                    errorEmitted: false,
                    emitClose: true,
                    autoDestroy: false,
                    bufferedRequestCount: 0,
                    corkedRequestsFree:
                     { next: null,
                       entry: null,
                       finish: [Function: bound onCorkedFinish] } },
                 writable: true,
                 _events:
                  [Object: null prototype] {
                    response: [Function: handleResponse],
                    error: [Function: handleRequestError] },
                 _eventsCount: 2,
                 _maxListeners: undefined,
                 _options:
                  { maxRedirects: 21,
                    maxBodyLength: 10485760,
                    protocol: 'http:',
                    path:
                     '/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27)',
                    method: 'PATCH',
                    headers:
                     { Accept: 'application/json',
                       'Content-Type': 'application/json',
                       'User-Agent': 'axios/0.21.1',
                       'Content-Length': 48 },
                    agent:
                     HttpProxyAgent {
                       _events: [Object: null prototype] {},
                       _eventsCount: 0,
                       _maxListeners: undefined,
                       timeout: null,
                       maxFreeSockets: 1,
                       maxSockets: 1,
                       maxTotalSockets: Infinity,
                       sockets: {},
                       freeSockets: {},
                       requests: {},
                       options: {},
                       secureProxy: false,
                       proxy:
                        { protocol: 'http:',
                          slashes: true,
                          auth: null,
                          host: '127.0.0.1',
                          port: 8887,
                          hostname: '127.0.0.1',
                          hash: null,
                          search: null,
                          query: null,
                          href: 'http://127.0.0.1:8887/' },
                       promisifiedCallback: [Function: callback] },
                    agents:
                     { http:
                        HttpProxyAgent {
                          _events: [Object: null prototype] {},
                          _eventsCount: 0,
                          _maxListeners: undefined,
                          timeout: null,
                          maxFreeSockets: 1,
                          maxSockets: 1,
                          maxTotalSockets: Infinity,
                          sockets: {},
                          freeSockets: {},
                          requests: {},
                          options: {},
                          secureProxy: false,
                          proxy:
                           { protocol: 'http:',
                             slashes: true,
                             auth: null,
                             host: '127.0.0.1',
                             port: 8887,
                             hostname: '127.0.0.1',
                             hash: null,
                             search: null,
                             query: null,
                             href: 'http://127.0.0.1:8887/' },
                          promisifiedCallback: [Function: callback] },
                       https:
                        Agent {
                          _events: [Object: null prototype] { free: [Function] },
                          _eventsCount: 1,
                          _maxListeners: undefined,
                          defaultPort: 443,
                          protocol: 'https:',
                          options: { path: null },
                          requests: {},
                          sockets: {},
                          freeSockets: {},
                          keepAliveMsecs: 1000,
                          keepAlive: false,
                          maxSockets: Infinity,
                          maxFreeSockets: 256,
                          maxCachedSessions: 100,
                          _sessionCache: { map: {}, list: [] } } },
                    auth: undefined,
                    hostname: 'businesspartner.dest',
                    port: null,
                    nativeProtocols:
                     { 'http:':
                        { _connectionListener: [Function: connectionListener],
                          METHODS:
                           [ 'ACL',
                             'BIND',
                             'CHECKOUT',
                             'CONNECT',
                             'COPY',
                             'DELETE',
                             'GET',
                             'HEAD',
                             'LINK',
                             'LOCK',
                             'M-SEARCH',
                             'MERGE',
                             'MKACTIVITY',
                             'MKCALENDAR',
                             'MKCOL',
                             'MOVE',
                             'NOTIFY',
                             'OPTIONS',
                             'PATCH',
                             'POST',
                             'PROPFIND',
                             'PROPPATCH',
                             'PURGE',
                             'PUT',
                             'REBIND',
                             'REPORT',
                             'SEARCH',
                             'SOURCE',
                             'SUBSCRIBE',
                             'TRACE',
                             'UNBIND',
                             'UNLINK',
                             'UNLOCK',
                             'UNSUBSCRIBE' ],
                          STATUS_CODES:
                           { '100': 'Continue',
                             '101': 'Switching Protocols',
                             '102': 'Processing',
                             '103': 'Early Hints',
                             '200': 'OK',
                             '201': 'Created',
                             '202': 'Accepted',
                             '203': 'Non-Authoritative Information',
                             '204': 'No Content',
                             '205': 'Reset Content',
                             '206': 'Partial Content',
                             '207': 'Multi-Status',
                             '208': 'Already Reported',
                             '226': 'IM Used',
                             '300': 'Multiple Choices',
                             '301': 'Moved Permanently',
                             '302': 'Found',
                             '303': 'See Other',
                             '304': 'Not Modified',
                             '305': 'Use Proxy',
                             '307': 'Temporary Redirect',
                             '308': 'Permanent Redirect',
                             '400': 'Bad Request',
                             '401': 'Unauthorized',
                             '402': 'Payment Required',
                             '403': 'Forbidden',
                             '404': 'Not Found',
                             '405': 'Method Not Allowed',
                             '406': 'Not Acceptable',
                             '407': 'Proxy Authentication Required',
                             '408': 'Request Timeout',
                             '409': 'Conflict',
                             '410': 'Gone',
                             '411': 'Length Required',
                             '412': 'Precondition Failed',
                             '413': 'Payload Too Large',
                             '414': 'URI Too Long',
                             '415': 'Unsupported Media Type',
                             '416': 'Range Not Satisfiable',
                             '417': 'Expectation Failed',
                             '418': 'I\'m a Teapot',
                             '421': 'Misdirected Request',
                             '422': 'Unprocessable Entity',
                             '423': 'Locked',
                             '424': 'Failed Dependency',
                             '425': 'Unordered Collection',
                             '426': 'Upgrade Required',
                             '428': 'Precondition Required',
                             '429': 'Too Many Requests',
                             '431': 'Request Header Fields Too Large',
                             '451': 'Unavailable For Legal Reasons',
                             '500': 'Internal Server Error',
                             '501': 'Not Implemented',
                             '502': 'Bad Gateway',
                             '503': 'Service Unavailable',
                             '504': 'Gateway Timeout',
                             '505': 'HTTP Version Not Supported',
                             '506': 'Variant Also Negotiates',
                             '507': 'Insufficient Storage',
                             '508': 'Loop Detected',
                             '509': 'Bandwidth Limit Exceeded',
                             '510': 'Not Extended',
                             '511': 'Network Authentication Required' },
                          Agent:
                           { [Function: Agent]
                             super_:
                              { [Function: EventEmitter]
                                once: [Function: once],
                                EventEmitter: [Circular],
                                usingDomains: false,
                                defaultMaxListeners: [Getter/Setter],
                                init: [Function],
                                listenerCount: [Function] },
                             defaultMaxSockets: Infinity },
                          ClientRequest:
                           { [Function: ClientRequest]
                             super_:
                              { [Function: OutgoingMessage]
                                super_:
                                 { [Function: Stream]
                                   super_: [Function],
                                   Readable: [Function],
                                   Writable: [Function],
                                   Duplex: [Function],
                                   Transform: [Function],
                                   PassThrough: [Function],
                                   pipeline: [Function: pipeline],
                                   finished: [Function: eos],
                                   Stream: [Circular],
                                   _isUint8Array: [Function: isUint8Array],
                                   _uint8ArrayToBuffer: [Function: _uint8ArrayToBuffer] } } },
                          IncomingMessage:
                           { [Function: IncomingMessage]
                             super_:
                              { [Function: Readable]
                                ReadableState: [Function: ReadableState],
                                super_:
                                 { [Function: Stream]
                                   super_: [Function],
                                   Readable: [Circular],
                                   Writable: [Function],
                                   Duplex: [Function],
                                   Transform: [Function],
                                   PassThrough: [Function],
                                   pipeline: [Function: pipeline],
                                   finished: [Function: eos],
                                   Stream: [Circular],
                                   _isUint8Array: [Function: isUint8Array],
                                   _uint8ArrayToBuffer: [Function: _uint8ArrayToBuffer] },
                                _fromList: [Function: fromList],
                                from: [Function] } },
                          OutgoingMessage:
                           { [Function: OutgoingMessage]
                             super_:
                              { [Function: Stream]
                                super_:
                                 { [Function: EventEmitter]
                                   once: [Function: once],
                                   EventEmitter: [Circular],
                                   usingDomains: false,
                                   defaultMaxListeners: [Getter/Setter],
                                   init: [Function],
                                   listenerCount: [Function] },
                                Readable:
                                 { [Function: Readable]
                                   ReadableState: [Function: ReadableState],
                                   super_: [Circular],
                                   _fromList: [Function: fromList],
                                   from: [Function] },
                                Writable:
                                 { [Function: Writable] WritableState: [Function: WritableState], super_: [Circular] },
                                Duplex: { [Function: Duplex] super_: [Function] },
                                Transform: { [Function: Transform] super_: [Function] },
                                PassThrough: { [Function: PassThrough] super_: [Function] },
                                pipeline: [Function: pipeline],
                                finished: [Function: eos],
                                Stream: [Circular],
                                _isUint8Array: [Function: isUint8Array],
                                _uint8ArrayToBuffer: [Function: _uint8ArrayToBuffer] } },
                          Server:
                           { [Function: Server]
                             super_:
                              { [Function: Server]
                                super_:
                                 { [Function: EventEmitter]
                                   once: [Function: once],
                                   EventEmitter: [Circular],
                                   usingDomains: false,
                                   defaultMaxListeners: [Getter/Setter],
                                   init: [Function],
                                   listenerCount: [Function] } } },
                          ServerResponse:
                           { [Function: ServerResponse]
                             super_:
                              { [Function: OutgoingMessage]
                                super_:
                                 { [Function: Stream]
                                   super_: [Function],
                                   Readable: [Function],
                                   Writable: [Function],
                                   Duplex: [Function],
                                   Transform: [Function],
                                   PassThrough: [Function],
                                   pipeline: [Function: pipeline],
                                   finished: [Function: eos],
                                   Stream: [Circular],
                                   _isUint8Array: [Function: isUint8Array],
                                   _uint8ArrayToBuffer: [Function: _uint8ArrayToBuffer] } } },
                          createServer: [Function: createServer],
                          get: [Function: get],
                          request: [Function: request],
                          maxHeaderSize: [Getter],
                          globalAgent: [Getter/Setter] },
                       'https:':
                        { Agent:
                           { [Function: Agent]
                             super_:
                              { [Function: Agent]
                                super_:
                                 { [Function: EventEmitter]
                                   once: [Function: once],
                                   EventEmitter: [Circular],
                                   usingDomains: false,
                                   defaultMaxListeners: [Getter/Setter],
                                   init: [Function],
                                   listenerCount: [Function] },
                                defaultMaxSockets: Infinity } },
                          globalAgent:
                           Agent {
                             _events: [Object: null prototype] { free: [Function] },
                             _eventsCount: 1,
                             _maxListeners: undefined,
                             defaultPort: 443,
                             protocol: 'https:',
                             options: { path: null },
                             requests: {},
                             sockets: {},
                             freeSockets: {},
                             keepAliveMsecs: 1000,
                             keepAlive: false,
                             maxSockets: Infinity,
                             maxFreeSockets: 256,
                             maxCachedSessions: 100,
                             _sessionCache: { map: {}, list: [] } },
                          Server:
                           { [Function: Server]
                             super_:
                              { [Function: Server] super_: { [Function: Server] super_: [Function] } } },
                          createServer: [Function: createServer],
                          get: [Function: get],
                          request: [Function: request] } },
                    pathname:
                     '/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27)' },
                 _ended: true,
                 _ending: true,
                 _redirectCount: 0,
                 _redirects: [],
                 _requestBodyLength: 48,
                 _requestBodyBuffers: [],
                 _onNativeResponse: [Function],
                 _currentRequest: [Circular],
                 _currentUrl:
                  'http://businesspartner.dest/sap/opu/odata/sap/API_BUSINESS_PARTNER/A_BusinessPartner(BusinessPartner=%27HARUT%27)' },
              [Symbol(isCorked)]: false,
              [Symbol(outHeadersKey)]:
               [Object: null prototype] {
                 accept: [ 'Accept', 'application/json' ],
                 'content-type': [ 'Content-Type', 'application/json' ],
                 'user-agent': [ 'User-Agent', 'axios/0.21.1' ],
                 'content-length': [ 'Content-Length', 48 ],
                 host: [ 'Host', 'businesspartner.dest' ] } },
           data: 'CSRF token validation failed' },
        isAxiosError: true,
        toJSON: [Function: toJSON] },
     name: 'ErrorWithCause' },
  name: 'ErrorWithCause' }

Log output in CF:

2021-02-23T21:33:08.16+0000 [APP/PROC/WEB/0] ERR [cds] - GET /test/insertBupa()
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"Attempting to retrieve destination from environment variable.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.172Z","msg":"Attempting to retrieve destination from environment variable.","written_ts":1614115988172,"written_at":"2021-02-23T21:33:08.172Z"}
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"No environment variable set.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.172Z","msg":"No environment variable set.","written_ts":1614115988172,"written_at":"2021-02-23T21:33:08.172Z"}
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"Attempting to retrieve destination from service binding.","level":"info","custom_fields":{"package":"core","messageContext":"destination-accessor-vcap"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.172Z","msg":"Attempting to retrieve destination from service binding.","written_ts":1614115988172,"written_at":"2021-02-23T21:33:08.172Z"}
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"Could not retrieve destination from service binding. If you are not using SAP Extension Factory, this information probably does not concern you. Unable to find a service binding for given name \"BusinessPartner\"! Found the following bindings: BusinessPartnerVerification-dest, BusinessPartnerVerification-cs, test-uaa.\n      ","level":"info","custom_fields":{"package":"core","messageContext":"destination-accessor-vcap"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.173Z","msg":"Could not retrieve destination from service binding. If you are not using SAP Extension Factory, this information probably does not concern you. Unable to find a service binding for given name \"BusinessPartner\"! Found the following bindings: BusinessPartnerVerification-dest, BusinessPartnerVerification-cs, test-uaa.\n      ","written_ts":1614115988173,"written_at":"2021-02-23T21:33:08.173Z"}
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"Attempting to retrieve destination from destination service.","level":"info","custom_fields":{"package":"core","messageContext":"destination-accessor-service"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.173Z","msg":"Attempting to retrieve destination from destination service.","written_ts":1614115988173,"written_at":"2021-02-23T21:33:08.173Z"}
   2021-02-23T21:33:08.17+0000 [APP/PROC/WEB/0] OUT {"message":"Unable to match a specific XSUAA service instance to the given JWT. The following XSUAA instances are bound: test!t75418. The following one will be selected: test!t75418. This might produce errors in other parts of the system!","level":"warn","custom_fields":{"package":"core","messageContext":"environment-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.173Z","msg":"Unable to match a specific XSUAA service instance to the given JWT. The following XSUAA instances are bound: test!t75418. The following one will be selected: test!t75418. This might produce errors in other parts of the system!","written_ts":1614115988173,"written_at":"2021-02-23T21:33:08.173Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"Successfully retrieved destination from destination service.","level":"info","custom_fields":{"package":"core","messageContext":"destination-accessor-service"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.206Z","msg":"Successfully retrieved destination from destination service.","written_ts":1614115988206,"written_at":"2021-02-23T21:33:08.206Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"OnPrem destination proxy settings from connectivity service will be used.","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.206Z","msg":"OnPrem destination proxy settings from connectivity service will be used.","written_ts":1614115988206,"written_at":"2021-02-23T21:33:08.206Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"Unable to match a specific XSUAA service instance to the given JWT. The following XSUAA instances are bound: test!t75418. The following one will be selected: test!t75418. This might produce errors in other parts of the system!","level":"warn","custom_fields":{"package":"core","messageContext":"environment-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.206Z","msg":"Unable to match a specific XSUAA service instance to the given JWT. The following XSUAA instances are bound: test!t75418. The following one will be selected: test!t75418. This might produce errors in other parts of the system!","written_ts":1614115988206,"written_at":"2021-02-23T21:33:08.206Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"Unable to create \"SAP-Connectivity-Authentication\" header: no JWT found on the current request.\n    Continuing without header. Connecting to on-premise systems may not be possible.","level":"warn","custom_fields":{"package":"core","messageContext":"connectivity-service"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.206Z","msg":"Unable to create \"SAP-Connectivity-Authentication\" header: no JWT found on the current request.\n    Continuing without header. Connecting to on-premise systems may not be possible.","written_ts":1614115988206,"written_at":"2021-02-23T21:33:08.206Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"The custom headers are provided with the keys: x-csrf-token,authorization,Proxy-Authorization,sap-client. These keys will overwrite the headers created by the SDK.","level":"warn","custom_fields":{"package":"core","messageContext":"http-client"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.208Z","msg":"The custom headers are provided with the keys: x-csrf-token,authorization,Proxy-Authorization,sap-client. These keys will overwrite the headers created by the SDK.","written_ts":1614115988208,"written_at":"2021-02-23T21:33:08.208Z"}
   2021-02-23T21:33:08.20+0000 [APP/PROC/WEB/0] OUT {"message":"Found custom authorization headers. The given destination also provides authorization headers. This might be unintended. The custom headers from the request config will be used.","level":"warn","custom_fields":{"package":"core","messageContext":"authorization-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.208Z","msg":"Found custom authorization headers. The given destination also provides authorization headers. This might be unintended. The custom headers from the request config will be used.","written_ts":1614115988208,"written_at":"2021-02-23T21:33:08.208Z"}
   2021-02-23T21:33:08.42+0000 [APP/PROC/WEB/0] OUT {"message":"The custom headers are provided with the keys: authorization,Proxy-Authorization,sap-client,x-csrf-token,cookie,content-type,accept. These keys will overwrite the headers created by the SDK.","level":"warn","custom_fields":{"package":"core","messageContext":"http-client"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.420Z","msg":"The custom headers are provided with the keys: authorization,Proxy-Authorization,sap-client,x-csrf-token,cookie,content-type,accept. These keys will overwrite the headers created by the SDK.","written_ts":1614115988420,"written_at":"2021-02-23T21:33:08.420Z"}
   2021-02-23T21:33:08.42+0000 [APP/PROC/WEB/0] OUT {"message":"Found custom authorization headers. The given destination also provides authorization headers. This might be unintended. The custom headers from the request config will be used.","level":"warn","custom_fields":{"package":"core","messageContext":"authorization-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-23T21:33:08.420Z","msg":"Found custom authorization headers. The given destination also provides authorization headers. This might be unintended. The custom headers from the request config will be used.","written_ts":1614115988420,"written_at":"2021-02-23T21:33:08.420Z"}
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT ┌─────────────────┬──────────────┐
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT │     (index)     │    Values    │
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT ├─────────────────┼──────────────┤
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT │ businessPartner │   'HARUT'    │
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT │    firstName    │ 'First Name' │
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT │    lastName     │  'LastName'  │
   2021-02-23T21:33:13.72+0000 [APP/PROC/WEB/0] OUT └─────────────────┴──────────────┘
   2021-02-23T21:33:13.72+0000 [RTR/20] OUT tfe-dev-dev-test-srv.cfapps.eu10.hana.ondemand.com - [2021-02-23T21:33:08.159080370Z] "GET /test/insertBupa() HTTP/1.1" 204 0 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 11_2_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.152 Safari/537.36" "-" "10.0.73.192:61235" x_forwarded_for:"-" x_forwarded_proto:"https" vcap_request_id:"0396b65e-5f73-4a6c-6584-9c517c775eec" response_time:5.563391 gorouter_time:0.000129 app_id:"c6d4999b-a9c6-4fd8-b07e-fa31250d588e" app_index:"0" x_cf_routererror:"-" x_correlationid:"-" tenantid:"-" sap_passport:"-" x_scp_request_id:"10cb1a4a-d6b0-450b-bcb9-e68cbd243342-6035748D-41FA43" x_cf_app_instance:"-" x_b3_traceid:"f9dec6be9bbd9e67" x_b3_spanid:"f9dec6be9bbd9e67" x_b3_parentspanid:"-" b3:"f9dec6be9bbd9e67-f9dec6be9bbd9e67"
   2021-02-23T21:33:13.72+0000 [RTR/20] OUT

Additional context
Destination configuration:
image
@maxstreifeneder maxstreifeneder added the bug Something isn't working label Feb 23, 2021
@artemkovalyov
Copy link
Member

Hi Max,

We'll be taking a look soon. Thanks for reporting this. Can you communicate the urgency so that we can think of the timeframe?

@maxstreifeneder
Copy link
Member Author

Hi Artem,

not anything super urgent. We are about to create a Use Case demo for SAP Extension suite in general - so we are not really impacted other than significantly increased development time (redeploy to CF + ssh + remote debugging) ;-)

Cheers,
Max

@artemkovalyov
Copy link
Member

Understood Max, we'll be interested in the Use Case and hopefully can help sooner. @FrankEssenberger , maybe you can have a closer look?

@FrankEssenberger
Copy link
Contributor

Hello @maxstreifeneder,

I made a little test in our BAS test application and for me the fetching of the CSRF token worked:

      const myDest = await getDestination(destinationNameBasic)
        const url = BusinessPartner.requestBuilder().getAll().build().relativeServiceUrl()
        const csrfToken = await buildCsrfHeaders(myDest,{url})

Since fetching the CSRF token is the first thing done towards the S/4 system are you sure your connection to the backend works? Could you perhaps make a getAll().top(5) test to see if you get some data? If this is also not working I assume that something is wrong with your connectivity setup.

Note that you have to set the destinations array in the SDK as described here: https://sap.github.io/cloud-sdk/docs/js/guides/bas-external-system

Best
Frank

P.S.:Note that the PrincipalPropgation section is potentially wrong so stick to basic.

@FrankEssenberger
Copy link
Contributor

Here is also a good reference in case you want to test the connection without coding just with a curl command:

https://blogs.sap.com/2020/10/13/how-to-check-the-connectivity-to-your-backend-system-in-business-application-studio/

Best
Frank

@maxstreifeneder
Copy link
Member Author

maxstreifeneder commented Feb 25, 2021 •
edited

Hi Frank,

selecting the data works fine (see the other lines I've provided in the test https://github.tools.sap/D063937/cloud-sdk-destination-issue/blob/master/srv/catalog-service.js#L20-L28) with the provided destination while only the update fails..

@FrankEssenberger
Copy link
Contributor

Sorry I missed that. Hm so let's do the following. I will try to do an update in our test app and you try to fetch a csrfToken via:

      const myDest = await getDestination(destinationNameBasic)
      const url = BusinessPartner.requestBuilder().getAll().build().relativeServiceUrl()
      const csrfToken = await buildCsrfHeaders(myDest,{url})

let's see if I can reproduce the error or you can fetch a token.

@FrankEssenberger
Copy link
Contributor

So I have included the update in our sample app and could change the first name of Jürgen to Jürgen123 with the SDK. So I guess there is perhaps something special for your system. The error points in the direction that you can not get a CSRF token, but why this is? Perhaps we get a better exception or error when you execute the csrfToken snipped above.

@maxstreifeneder
Copy link
Member Author

Hi Frank,

log output for the stuff you have just poted:

{"message":"Attempting to retrieve destination from environment variable.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.072Z","msg":"Attempting to retrieve destination from environment variable.","written_ts":1614270897072,"written_at":"2021-02-25T16:34:57.072Z"}
{"message":"Environment variable 'destinations' is set. Destinations will be read from this variable. This is discouraged for a productive application! Unset the variable to read destinations from the destination service on SAP Cloud Platform.","level":"warn","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.073Z","msg":"Environment variable 'destinations' is set. Destinations will be read from this variable. This is discouraged for a productive application! Unset the variable to read destinations from the destination service on SAP Cloud Platform.","written_ts":1614270897073,"written_at":"2021-02-25T16:34:57.073Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.074Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614270897074,"written_at":"2021-02-25T16:34:57.074Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.074Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614270897074,"written_at":"2021-02-25T16:34:57.074Z"}
{"message":"Proxy settings for http are found in environment variables.","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.075Z","msg":"Proxy settings for http are found in environment variables.","written_ts":1614270897075,"written_at":"2021-02-25T16:34:57.075Z"}
{"message":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","level":"info","custom_fields":{"package":"core","messageContext":"proxy-util"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.075Z","msg":"Try to fetch http_proxy or HTTP_PROXY from the process env. Found value is http://127.0.0.1:8887","written_ts":1614270897075,"written_at":"2021-02-25T16:34:57.075Z"}
{"message":"Successfully retrieved destination from environment variable.","level":"info","custom_fields":{"package":"core","messageContext":"env-destination-accessor"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.076Z","msg":"Successfully retrieved destination from environment variable.","written_ts":1614270897076,"written_at":"2021-02-25T16:34:57.076Z"}
{"message":"The custom headers are provided with the keys: x-csrf-token. These keys will overwrite the headers created by the SDK.","level":"warn","custom_fields":{"package":"core","messageContext":"http-client"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.077Z","msg":"The custom headers are provided with the keys: x-csrf-token. These keys will overwrite the headers created by the SDK.","written_ts":1614270897077,"written_at":"2021-02-25T16:34:57.077Z"}
{"message":"Destination did not return a CSRF token. This may cause a failure when sending the OData request.","level":"warn","custom_fields":{"package":"core","messageContext":"csrf-token-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.622Z","msg":"Destination did not return a CSRF token. This may cause a failure when sending the OData request.","written_ts":1614270897622,"written_at":"2021-02-25T16:34:57.622Z"}
{"message":"CSRF header response does not include cookies.","level":"warn","custom_fields":{"package":"core","messageContext":"csrf-token-header"},"logger":"sap-cloud-sdk-logger","timestamp":"2021-02-25T16:34:57.622Z","msg":"CSRF header response does not include cookies.","written_ts":1614270897622,"written_at":"2021-02-25T16:34:57.622Z"}

@FrankEssenberger
Copy link
Contributor

FrankEssenberger commented Feb 25, 2021 •
edited

So after the call and with a quick thinking over I understand the issue now:

  • It works on my machine because the ERP does not require a redirect to fetch the CSRF token (tested via CURL)
  • It works in production because there is no connectivity proxy which seems to handle the redirect so we do not enter the catch blog
  • It does not work in BAS because the connectivity proxy handles does the redirect, but the response is then different so that our response.headers does not contain the actual header -> potential candidates are casing different or some subproperty like response.redirect.headers.

I have to debug this tomorrow using a system with redirect and make the call with axios in the BAS to see the response.

@FrankEssenberger
Copy link
Contributor

FrankEssenberger commented Feb 26, 2021 •
edited

I have investigated the issue now. First thing the redirect issue is not solved in axios: axios/axios#3369 the issue was closed but I tried with versin 0.21.1 and still get an error when calling the backend.

Situation on our dev system:

  • When you make a call curl name.dest/path -H ..csrf tokens... you see a redirect and get the token
  • When you make a call curl name.dest/path/ -H ..csrf tokens... you see no redirect and get the token
  • In the code also the / makes the difference, but axios fails for the redirect and gives no response and _isRedirect:true in the request so our workaround works

Situation on Maxs dev system:

  • When you make a call curl name.dest/path -H ..csrf tokens... you see a redirect and get the token
  • When you make a call curl name.dest/path/ -H ..csrf tokens... you see no redirect and get the token
  • In the code also the / makes the difference, but axios fails for the redirect this time with response in the exception and status 502 so our workaround is not triggered and the token is empty.

So this CSRF token fetching issue might be related to #1051 - at least the 502 part. @marikaner should we fix this by simply adding also the 502 error case to the workaround? In principle in both cases one could to a retry and add the / to the initial requestConfig.url?

@FrankEssenberger FrankEssenberger mentioned this issue Mar 1, 2021
Merged
@FrankEssenberger
Copy link
Contributor

@maxstreifeneder cloud you perhaps check with the canary version of this fixes your issue.

@maxstreifeneder
Copy link
Member Author

works - as discussed. Needed to remove the @sap-cloud-sdk/core package coming from the vdm package (which doesn't include the canary changes)

@FrankEssenberger
Copy link
Contributor

Cool I close the issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@artemkovalyov @maxstreifeneder @FrankEssenberger