Itgencun016: Fout invalid_request: Signed data extraction has failed

Ik krijg een automatische mail van Invantive Data Hub.

Het logboek geeft aan:

itgencun016: Fout invalid_request: invalid_request: Signed data extraction has failed The request is missing a required parameter, includes an invalid parameter value, includes a parameter more than once, or is otherwise malformed.

Het betreft:

File Version Label: 20.0.117-PROD+1680
Build Date (UTC): 13-11-2020 15:49:23

Het relevante deel van de trace log is:

01:42:16.88597-0-4: A new refresh token was retrieved 5 times. Last one was retrieved at 8-1-2021 01:23:12 (UTC).
01:42:16.88597-0-4: A token was retrieved 6 times. Last one was retrieved at 8-1-2021 01:23:12 (UTC).
01:42:16.88597-0-4: Skipped sensitive information.
01:42:16.88597-0-4: POST try #1 on '***'.
01:42:16.88597-0-4: The URI '***' is already absolute. No need to prefix it.
01:42:16.88597-0-4: POST 602 bytes of data to URL '***'. Disk cache: False/False, memory cache False/False.
01:42:16.88597-0-4: Rate limit 'partition-slots-ExactOnlineRest - DEFAULT' slot 6 of 272, 6 hits, no previous use of slot: sleep not needed. Context: https://start.exactonline.nl/api/oauth2/token
01:42:16.88597-0-4: Request was not canceled and was neither a connect failure: status is ProtocolError.
01:42:16.88597-0-4: HTTP bad request on 'https://start.exactonline.nl/api/oauth2/token'. Skip exception based upon 'ignore-http-400-errors': False.
01:42:16.88597-0-4: Connection was opened at 8-1-2021 00:00:23 (UTC), error occurred at 8-1-2021 01:42:16 (UTC).
01:42:16.88597-0-4: Instantiate 'ValidationException', ID 'a6188df4-21de-43f5-a7b4-a025343961af', code 'invalid_request': Signed data extraction has failed The request is missing a required parameter, includes an invalid parameter value, includes a parameter more than once, or is otherwise malformed.
01:42:16.88597-0-4: Last seen start: 8-1-2021 01:42:16 (UTC), my start 8-1-2021 01:42:16 (UTC), ended at 8-1-2021 01:42:16 (UTC), URL: https://start.exactonline.nl/api/oauth2/token
01:42:16.88597-0-4: WRITE action on URL 'https://start.exactonline.nl/api/oauth2/token' took 187 ms.
01:42:16.88597-0-4: Reduced maximum number of usable partitions from 100.000 to 10.000 due to license constraints of license contract code 'L***' with ID ***.
01:42:16.88597-0-4: Non-recoverable generic exception of type 'ValidationException' when retrieving text data of partition '' after 219 ms using '***' of ''.
Invantive.Basics.ValidationException: invalid_request: Signed data extraction has failed The request is missing a required parameter, includes an invalid parameter value, includes a parameter more than once, or is otherwise malformed. ---> System.Net.WebException: De externe server heeft een fout geretourneerd: (400) Ongeldige opdracht.
   bij System.Net.HttpWebRequest.GetResponse()
   bij Invantive.Data.Providers.OData.ODataProvider.DoRequest(GlobalState owner, ExecutionOptions executionOptions, HttpWebRequest request, String url, ObjectDefinition objectDefinition, String partitionCode, String callSafeNameOverrule, String anonymizedPostText, Boolean allowRetryOnConnectionLoss, ExecutionStatistics& statistics, ODataErrorProcessingInstructions& oDataErrorProcessingInstructions)
   --- Einde van intern uitzonderingsstackpad ---
   bij System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   bij Invantive.Data.Providers.OData.ODataProvider.DoRequest(GlobalState owner, ExecutionOptions executionOptions, HttpWebRequest request, String url, ObjectDefinition objectDefinition, String partitionCode, String callSafeNameOverrule, String anonymizedPostText, Boolean allowRetryOnConnectionLoss, ExecutionStatistics& statistics, ODataErrorProcessingInstructions& oDataErrorProcessingInstructions)
   bij Invantive.Data.Providers.OData.ODataProvider.Post(GlobalState owner, ExecutionOptions executionOptions, String relativeUrl, Dictionary`2 inHeaders, Byte[] postData, String anonymizedPostText, CacheSettings cacheSettings, ObjectDefinition objectDefinition, Boolean allowRetry, ExecutionStatistics& statistics, String acceptMimeType, String contentType, Boolean authenticate, Boolean preventRetryOnAuthenticationFailure, String partitionCode, String method, String callSafeNameOverrule)
01:42:16.88597-0-4: An exception occurred during posting a form with URL encoded values.
01:42:16.88597-0-4: MIME type: application/json
01:42:16.88597-0-4: Skipped sensitive information.
01:42:16.88597-0-4: Skipped sensitive information.
01:42:16.88597-0-4: Skipped sensitive information.
01:42:16.88597-0-4: Generic exception of type 'ValidationException' when retrieving page 0 of partition '***' after 531 ms using '***' of 'ExactOnlineREST.Financial.GLAccounts'. 

Dit is op de tabel GLAccounts. De trace duidt op een verlopen token op het moment dat de request wordt uitgevoerd. Wat kan er aan de hand zijn?

Deze foutmelding treedt incidenteel op. Ik zie dat hij vaak in de nacht optreedt op verschillende omgevingen vanaf verschillende IP-adressen zowel op AWS, Azure als on-premise locaties, bijvoorbeeld:

  • 11 december 2020 00:30 (UTC)
  • 11 december 2020 01:08 (UTC)
  • 24 december 2020 03:05 (UTC)
  • 25 december 2020 03:02 (UTC)
  • 31 december 2020 03:03 (UTC)
  • 5 januari 03:03 (UTC)
  • 8 januari 01:42 (UTC)
  • 8 januari 02:14 (UTC)

Maar de melding ‘Signed data extraction has failed’ treedt soms ook overdag op:

  • 7 januari 10:51 (UTC)
  • 7 januari 10:59 (UTC)
  • 7 januari 11:01 (UTC)

Het is een foutmelding die Exact Online teruggeeft.

Het is een probleem in de Exact Online API, waarbij het blijkbaar niet lukt om het refresh token “uit te pakken” (dat is een gokje). Mogelijk is tijdelijk intern een authenticatieserver offline of slecht bereikbaar en zit er geen retry mechanism in de API server.

Een zwak punt van de Exact Online API’s is dat men rond herstartmomenten een slechte logica heeft voor het offline brengen en geen foutcodes. Gedurende de momenten dat een statuswisseling plaatsvindt, treden de meest varierende en exotische foutmeldingen op. Principieel willen we niet blindelings opnieuw proberen; de SQL driver voor Exact Online dient een hernieuwde poging alleen te doen als bekend is wat de oorzaak is.

We hebben dit punt bij Exact API support aangekaart en het blijkt een bekend probleem te zijn dat men wil oplossen.

We wachten een aantal weken af of men hiervoor een oplossing vindt.

Zo nee, dan zullen we de logica van SQL Exact Online driver aanpassen dat hij vaker gaat proberen een nieuw access token te verwerven als specifiek deze melding terugkomt.

Vanaf de volgende 20.0 en 20.1 BETA wordt in ieder geval een itgeneor234 teruggegeven als foutcode in plaats van het algemeen invalid_request.

Update
De frequentie van optreden van dit probleem is dusdanig laag geworden dat we de fout niet meer ontvangen hebben.