SBO 2311HF1 Service Layer issue - async logins bug - help!

[Andrew_CC]

Hi,

I believe with the changes in the last few patches we've found an issue with Service Layer failing. We have upgraded from 2108HF1 which was flawless in terms of logging in (although far from flawless in other areas), to 2311HF1 and are now seeing this login behaviour.

When more than 1 login is requested to Service Layer before a response has been issued, all requests apart from one (maybe the first or last?!) will fail with the following returned error:

{"error":{"code":"401","details":[{"code":"","message":""}],"message":"Internal error: Get access token error,{\"error\":\"invalid_client\",\"error_description\":\"Client authentication with signed JWT failed: Token reuse detected\"}."}}

This behaviour is consistent and shows up in the SL logs time and time again. You can see this where any login requests more than a single request before the response will result in this issue.

I believe this is due to the login changes in the past year or so which have permeated through the admin/control pages etc, and also seem to make SL slightly slower to login also.

Log extract showing 3 API requests requiring login, only 1 works the other 2 fail. It seems like there needs to be a queue/lock mechanism in place to handle these one after another if SL is now "consulting" with an local external auth mechanism.

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Request] "POST /b1s/v2/Login HTTP/1.1"
Host:sapserver:50000
OData-Version:4.0
OData-MaxVersion:4.0
Accept:application/json;odata.metadata=minimal
Accept-Charset:UTF-8
User-Agent:Microsoft.OData.Client/7.20.0
Connection:Keep-Alive
traceparent:00-e5c620d420926388cd85c99e82b2c206-26888ed84b10b1dd-00
Content-Type:application/json;odata.metadata=minimal
Content-Length:82
X-Forwarded-Proto:https

**********************************************************************************

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Request] "POST /b1s/v2/Login HTTP/1.1"
Host:sapserver:50000
OData-Version:4.0
OData-MaxVersion:4.0
Accept:application/json;odata.metadata=minimal
Accept-Charset:UTF-8
User-Agent:Microsoft.OData.Client/7.20.0
Connection:Keep-Alive
traceparent:00-233ce6b94219cf6d960db050098fc376-941d46b0949dfab9-00
Content-Type:application/json;odata.metadata=minimal
Content-Length:82
X-Forwarded-Proto:https

**********************************************************************************

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Request] "POST /b1s/v2/Login HTTP/1.1"
Host:sapserver:50000
OData-Version:4.0
OData-MaxVersion:4.0
Accept:application/json;odata.metadata=minimal
Accept-Charset:UTF-8
User-Agent:Microsoft.OData.Client/7.20.0
Connection:Keep-Alive
traceparent:00-cb1ead6233f310a515519e6303fbe202-7aad577539cbfe51-00
Content-Type:application/json;odata.metadata=minimal
Content-Length:82
X-Forwarded-Proto:https

**********************************************************************************

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Response] "POST /b1s/v2/Login HTTP/1.1"
Status Code:[500 Internal Server Error]
Date:Thu, 01 Feb 2024 23:05:34 GMT
Server:Apache
Content-Type:application/json;charset=utf-8

{
"error" : {
"code" : "401",
"details" : [
{
"code" : "",
"message" : ""
}
],
"message" : "Internal error: Get access token error,{\"error\":\"invalid_client\",\"error_description\":\"Client authentication with signed JWT failed: Token reuse detected\"}."
}
}

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Response] "POST /b1s/v2/Login HTTP/1.1"
Status Code:[500 Internal Server Error]
Date:Thu, 01 Feb 2024 23:05:34 GMT
Server:Apache
Content-Type:application/json;charset=utf-8

{
"error" : {
"code" : "401",
"details" : [
{
"code" : "",
"message" : ""
}
],
"message" : "Internal error: Get access token error,{\"error\":\"invalid_client\",\"error_description\":\"Client authentication with signed JWT failed: Token reuse detected\"}."
}
}

[Fri Feb 02 10:05:34 2024] [192.168.4.103] [pid=15144] [Response] "POST /b1s/v2/Login HTTP/1.1"
Status Code:[200 OK]
Date:Thu, 01 Feb 2024 23:05:34 GMT
Server:Apache
Content-Type:application/json;odata.metadata=minimal;charset=utf-8
Set-Cookie:********************************************************************

{
"@odata.context" : "https://sapserver:50000/b1s/v2/$metadata#B1Sessions/$entity",
"SessionId" : "67d11b44-c156-11ee-c000-00155dd85d00-13656-13068",
"Version" : "1000230",
"SessionTimeout" : 10
}

Can anyone provide a work around or suggestion to solve or mitigate this unwanted SL behaviour?

[ANKIT_CHAUHAN]

Hi Andrew_CC,

Please help to check this issue in the recently released SP2402 for SAP Business One version 10.0 as few enhancements are done in this patch for the mentioned error.

Kind regards,

ANKIT CHAUHAN

SAP Business One Support 

[Andrew_CC]

Hi Ankit, am in the process of installing 2402 on my test server now 🙂 Hopefully they've resolved a few things from 2311 (client memory leak, SL login issues). Thanks.

[ANKIT_CHAUHAN]

Hi Andrew_CC,

We will await your response.

Kind regards,

ANKIT CHAUHAN

SAP Business One Support

[Andrew_CC]

Can confirm we've successfully mitigated this Service Layer 2311 HF1 shortcoming by moving the login process to the C# ODATA BuildingRequest event handler, instead of at the scope creation, and using a lock to ensure only 1 login request is sent and resolved at a time. Using FIFO login as opposed to async has provided a fault free afternoon under heavy load.

We will migrate to 2402 after testing, I'll confirm if the bug still exists, I don't see any specific patch note related to this being fixed.