box / box-windows-sdk-v2

Windows SDK for v2 of the Box API. The SDK is built upon .NET Framework 4.5
https://developer.box.com
Apache License 2.0
186 stars 163 forks source link

Intermittent The API returned an error Unauthorized #507

Closed dkopesky closed 5 years ago

dkopesky commented 5 years ago

DeltaLadderBoxFeed_Runs.xlsx

I have opened a support case about this as well: https://community.box.com/t5/custom/page/page-id/BoxViewTicketDetail?ticket_id=1763935 Matt Behn suggested I contact you…

Description of the Issue

We are running a job nightly to upload files. The job in question uploads files to a single Box folder (typically 30 per day, but it can vary quite a bit). It also looks for and deletes files older than a configurable age (currently set for five days).

The attached spreadsheet shows the results of numerous runs for which I have log files on disk. (I have also run many manual test runs, but I don't have logs for those.) Some of the failures look like transients, timeouts, whatever. However the "Unauthorized" exception has recurred several times, and is the one that concerns me most at this time.

It does not happen every night, but when it does, it appears to be persistent. I recently configured our job to retry at 10-minute intervals for an hour, and when the exception does occur, it persists across those retries – so it's not a "transient" error. For example, on 10/08, it failed at 20:30, 20:40, 20:50, 21:01, 21:11, 21:21, 21:32 (Central Time).

The last occurrence we saw was on 10/08. The job has run fine the past several nights.

Do you know what might be causing this, and how I can avoid it? Please advise. Thanks much.

Versions Used

.NET SDK: Box.V2.dll v4.0.30319
.NET Framework/Core: 4.5

Steps to Reproduce

Here is the method in which the exceptions occur:

    protected override void StartRun()
    {
        var config = new BoxConfig(ClientID, ClientSecret, EnterpriseID, PrivateKey, Password, PubKeyID);
        var boxJwt = new BoxJWTAuth(config);
        var adminToken = boxJwt.AdminToken();  // exception occurs here…
        Client = boxJwt.AdminClient(adminToken, UserID);
        RemoteFolderId = Client.GetItemIdByPath(RemoteFolder);
    }

Here are the parameters we are passing in to the BoxConfig constructor (I've deleted a few):

ParamName ParamValue
ClientID 3n7bo6msbhqi938igsndtcvy7hunwgw5
ClientSecret [deleted]
EnterpriseID 373288
PrivateKey [deleted]
Password [deleted]
PubKeyID emtwrp47

The UserID we pass in to the AdminClient() call is 3664549228 (however, that's past the point of the exception).

Error Message, Including Stack Trace

Box.V2.Exceptions.BoxException: The API returned an error [Unauthorized] at Box.V2.JWTAuth.BoxJWTAuth.GetToken(String subType, String subId) at Box.V2.JWTAuth.BoxJWTAuth.AdminToken() at FeedRunner.BoxUploader.StartRun() in C:\MarketData\src\master\MarketData\FeedRunner\FileHandlers\BoxUploader.cs:line 48 at FeedRunner.FeedFileHandler.RunOnePass() in C:\MarketData\src\master\MarketData\FeedRunner\FeedFileHandler.cs:line 138 at FeedRunner.FeedRunner.RunOnce() in C:\MarketData\src\master\MarketData\FeedRunner\FeedRunner.cs:line 105 at AIMLib.LoopedApplication.Run() in C:\MarketData\src\master\AIMLib\LoggedApplication.cs:line 209 at AIMLib.LoggedApplication.Launch(Func`1 ctor) in C:\MarketData\src\master\AIMLib\LoggedApplication.cs:line 64

mattwiller commented 5 years ago

@dkopesky I checked in our server logs and can't find the 401 Unauthorized errors at the time you mentioned (10/8 around 8:30pm Central Time), so unfortunately there's not much I can tell you at this time. In case the error happens again, could you try catching the exception and logging out ex.ResponseHeaders to see if there's any useful error message (401s commonly have the error message in the headers) or other information I could use to trace down the specific error request/response?

dkopesky commented 5 years ago

Thanks, Matt. I have added some more diagnostics, which hopefully will help if/when the problem recurs. (We've run the past eight nights without problems.) -Dean

From: Matt Willer [mailto:notifications@github.com] Sent: Wednesday, October 17, 2018 18:27 To: box/box-windows-sdk-v2 Cc: Kopesky, Dean (Allianz Life Insurance Company); Mention Subject: Re: [box/box-windows-sdk-v2] Intermittent The API returned an error Unauthorized (#507)

This email originated from outside the company. Please exercise caution before clicking links or opening attachments.


@dkopeskyhttps://github.com/dkopesky I checked in our server logs and can't find the 401 Unauthorized errors at the time you mentioned (10/8 around 8:30pm Central Time), so unfortunately there's not much I can tell you at this time. In case the error happens again, could you try catching the exception and logging out ex.ResponseHeaders to see if there's any useful error message (401s commonly have the error message in the headers) or other information I could use to trace down the specific error request/response?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/box/box-windows-sdk-v2/issues/507#issuecomment-430823718, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AqMLrsor-ah-mU6QhzBamPM_uCN-ex7Fks5ul7y_gaJpZM4Xkzkt.


CONFIDENTIALITY NOTICE: The information in this message, and any files transmitted with it, is confidential, may be legally privileged, and intended only for the use of the individual(s) named above. Be aware that the use of any confidential or personal information may be restricted by state and federal privacy laws. If you are not the intended recipient, do not further disseminate this message. If this message was received in error, please notify the sender and delete it.

dkopesky commented 5 years ago

After ten successful nights in a row, the Unauthorized exception recurred last night. The job retried six times at ten-minute intervals from 20:30 – 21:32 Central Time, and failed every time. A rerun this morning worked fine. Here is the log of the first failure (they're all the same), with the ResponseHeaders and Error fields (the latter is null). Please let me know if there is anything else I can try to capture to shed light on this… Thanks much. -Dean

2018-10-22 20:30:02 [Information] Running feed: "DeltaLadderBoxFeed" (build 10/19/2018 14:31:04) 2018-10-22 20:30:02 [Information] DeltaLadderBoxUpload starting RunID 46185 ... 2018-10-22 20:30:03 [Error] Message = "The API returned an error [Unauthorized]" 2018-10-22 20:30:03 [Error] StatusCode = "Unauthorized" 2018-10-22 20:30:03 [Error] ResponseHeaders = "Pragma: no-cache Cache-Control: no-cache WWW-Authenticate: NTLM, BASIC realm=\"AllianzTransparent\" Set-Cookie: BCSI-CS-3c9c5d458153d233=2; Path=/ Connection: close " 2018-10-22 20:30:03 [Error] Error = null 2018-10-22 20:30:03 [Warning] DeltaLadderBoxUpload RunID 46185: The API returned an error [Unauthorized] 2018-10-22 20:30:03 [Information] DeltaLadderBoxUpload RunID 46185 done: found null, processed null, cleaned null, forgotten null 2018-10-22 20:30:03 [Fatal] Caught exception; exiting. Box.V2.Exceptions.BoxException: The API returned an error [Unauthorized] at Box.V2.JWTAuth.BoxJWTAuth.GetToken(String subType, String subId) at Box.V2.JWTAuth.BoxJWTAuth.AdminToken() at FeedRunner.BoxUploader.StartRun() in C:\MarketData\src\master\MarketData\FeedRunner\FileHandlers\BoxUploader.cs:line 57 at FeedRunner.FeedFileHandler.RunOnePass() in C:\MarketData\src\master\MarketData\FeedRunner\FeedFileHandler.cs:line 138 at FeedRunner.FeedRunner.RunOnce() in C:\MarketData\src\master\MarketData\FeedRunner\FeedRunner.cs:line 110 at AIMLib.LoopedApplication.Run() in C:\MarketData\src\master\AIMLib\LoggedApplication.cs:line 209 at AIMLib.LoggedApplication.Launch(Func`1 ctor) in C:\MarketData\src\master\AIMLib\LoggedApplication.cs:line 64

mattwiller commented 5 years ago

@dkopesky The WWW-Authenticate: NTLM, BASIC realm="AllianzTransparent" header you're getting in the response seems to indicate that this is an issue with a proxy somewhere between your host and the Box API server. This proxy is likely somewhere in your own environment, which would explain why I wasn't able to find the errors in our server logs — the request probably never made it to the Box API. You'll probably want to investigate on your end to see why this is happening sporadically.

guilmori commented 5 years ago

We got the same error between Nov 25th and Nov 28th. The sdk suddenly started to flood my logs with exception "The API returned an error [Unauthorized]". It took 4-5 retries (sometimes more) for each request to succeed. Since Nov 28th, it never happened again. We are on Azure Web App. I contacted Box support but they haven't found anything relevant in their logs.

mattwiller commented 5 years ago

@guilmori Unfortunately, without more information there's nothing I can do to help diagnose this issue. Since the issue is only happening during a certain time, it's likely that it's an API problem and not one with this SDK — if Box Support hasn't found anything in the logs then there isn't anything more I can offer. The one thing I can suggest is that you could try catching the exception and logging out ex.ResponseHeaders to see if there's any useful error message (401s commonly have the error message in the headers) or other information that we could use to trace down the specific error request/response.