BillingWebJob error

[snpdev]

Hello,

I experience a problem on running BillingWebJob.exe for the first time.

In https://[MY APP NAME].scm.azurewebsites.net/azurejobs/#/jobs/continuous/BillingWebJob there is the following message:

The configuration is not properly set for the Microsoft Azure WebJobs Dashboard.
In your Microsoft Azure Website configuration you must set a connection string named AzureWebJobsDashboard by using the following format DefaultEndpointsProtocol=https;AccountName=NAME;AccountKey=KEY pointing to the Microsoft Azure Storage account where the Microsoft Azure WebJobs Runtime logs are stored.

Screenshot in Figure 1 below

The log output is as follows:

[02/07/2017 19:47:41 > 40f151: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
[02/07/2017 19:47:41 > 40f151: SYS INFO] Status changed to Stopping
[02/07/2017 19:47:41 > 40f151: INFO] Job host stopped
[02/07/2017 19:47:41 > 40f151: SYS INFO] Status changed to Success
[02/07/2017 19:47:41 > 40f151: SYS INFO] Status changed to Stopped
[02/07/2017 19:47:41 > 40f151: SYS INFO] Status changed to Starting
[02/07/2017 19:47:41 > 40f151: SYS INFO] Job directory change detected: Job file 'BillingWebJob.exe.config' timestamp differs between source and working directories.
[02/07/2017 19:47:47 > 40f151: SYS INFO] Run script 'BillingWebJob.exe' with script host - 'WindowsScriptHost'
[02/07/2017 19:47:47 > 40f151: SYS INFO] Status changed to Running
[02/07/2017 19:47:49 > 40f151: INFO] Found the following functions:
[02/07/2017 19:47:49 > 40f151: INFO] BillingWebJob.Program.CronJob
[02/07/2017 19:47:49 > 40f151: INFO] Executing: 'Program.CronJob' - Reason: 'Timer fired at 2017-02-07T19:47:49.4738668Z'
[02/07/2017 19:47:49 > 40f151: INFO] Job started for fetching billing data at 02/07/2017 19:47:49
[02/07/2017 19:47:49 > 40f151: INFO] Starting job processing for Customer Type csp
[02/07/2017 19:47:49 > 40f151: INFO] Starting CSP Routine. Current Usage, Historic Usage and Historic Billing data will be updated..
[02/07/2017 19:47:50 > 40f151: INFO]
[02/07/2017 19:47:50 > 40f151: INFO] Fetching records for Current Month's Usage from the API. This may take a while. If this operation is timimg out, consider increasing the TimeOut limit in Configuration file.
[02/07/2017 19:57:50 > 40f151: INFO]
[02/07/2017 19:57:50 > 40f151: INFO] Error encountered:
[02/07/2017 19:57:50 > 40f151: INFO] One or more errors occurred.
[02/07/2017 19:57:50 > 40f151: INFO] InnerException :
[02/07/2017 19:57:50 > 40f151: INFO] Exception of type 'Microsoft.Rest.HttpOperationException1[System.Object]' was thrown. [02/07/2017 19:57:50 > 40f151: INFO] StackTrace : [02/07/2017 19:57:50 > 40f151: INFO] at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions) [02/07/2017 19:57:50 > 40f151: INFO] at System.Threading.Tasks.Task1.GetResultCore(Boolean waitCompletionNotification)
[02/07/2017 19:57:50 > 40f151: INFO] at System.Threading.Tasks.Task`1.get_Result()
[02/07/2017 19:57:50 > 40f151: INFO] at BillingWebJob.Helpers.CspDataHelper.StartCspRoutine(Int32& status, Int32& totalRecordsCount, String& blobStorageUri)
[02/07/2017 19:57:50 > 40f151: INFO] at BillingWebJob.Program.CronJob(TimerInfo timer)
[02/07/2017 19:57:50 > 40f151: INFO]
[02/07/2017 19:57:50 > 40f151: INFO] Adding audit information in AuditData table..
[02/07/2017 19:57:50 > 40f151: INFO]
[02/07/2017 19:57:56 > 40f151: INFO]
[02/07/2017 19:57:56 > 40f151: INFO] Operation complete. Exiting this run.
[02/07/2017 19:57:56 > 40f151: INFO]
[02/07/2017 19:57:56 > 40f151: INFO] Executed: 'Program.CronJob' (Succeeded)
[02/07/2017 19:57:56 > 40f151: INFO] Job host started

The exception is written to the database table AuditData, but no data is written to any other table. I see no problem with the Storage connection strings. I started with a single Storage account, but have also tried with unique accounts for AzureWebJobsDashboard and AzureAnalyticsDbModel.

Suggestions to help troubleshoot the problem are appreciated.

Figure 1

[snpdev]

I just noticed the default timeout in App.config is 10 minutes, and the exception is thrown at the 10 minute mark. I will increase the value of ApiResponseWaitTimeOutInMinutes to 20 minutes and report back.

[snpdev]

Now the same exception occurs after 20 minutes.

[s3banerjee]

Same set of errors , i ' m also getting as mentioned above , it seems that there is some change in the SDK function or procedure.
it also means that API , database and webjob are communicating with each other but in such a fashion the results are not populating.

[s3banerjee]

In Swagger , i ' m getting back the below response as 200 and for some API response code is 500.

https://billing-data-api.azurewebsites.net/api/cspsummary/currentmonth

Response Body

[]

Response Code

200

Response Headers

{
"cache-control": "no-cache",
"pragma": "no-cache",
"content-length": "122",
"content-type": "application/json; charset=utf-8",
"content-encoding": "gzip",
"expires": "-1",
"vary": "Accept-Encoding",
"server": "Microsoft-IIS/8.0",
"x-aspnet-version": "4.0.30319",
"x-powered-by": "ASP.NET",
"date": "Fri, 10 Feb 2017 18:45:23 GMT"
}

   [ base url: , api version: v1 ]  

{"schemaValidationMessages":[{"level":"error","message":"Can't read from file https://billing-data-api.azurewebsites.net:443/swagger/docs/v1"}]}

[snpdev]

I receive accurate Response Body content when I click the "Try it out!" button for:

https://[my site].azurewebsites.net/swagger/ui/index#!/CspSummary/CspSummary_GetCurrentMonthData
AND
https://[my site].azurewebsites.net/swagger/ui/index#!/CspSummary/CspSummary_GetSingleMonthData

s3banerjee, for what requests do you receive a 500 error?

[s3banerjee]

/api/cspbilling : - Returning back response 200 , but nothing in response body
/api/cspbilling/currentmonth : - Returning back response 200 , but nothing in response body
/api/cspusage :- Response 500.
/api/userbilling :- Response 500.

for 200 response in body we have nothing.

Response Body

[]

for 500 response

Response Body

{
"Message": "An error has occurred."
}

[ssugar]

Check out my pull request for the /api/cspusage response 500 errors you are seeing. I saw the same error, and in my case it was because the current /api/cspusage code throws an exception if any of your clients in the partner center have a relationship other than "reseller" (e.g. "advisor" relationship). My pull request adds a check to see if there is a reseller relationship before pulling usage data.

[snpdev]

Hi ssugar,

I applied the code in your pull request #32. It resolves the problem for us. Thank you very much.

For the record, our successful BillingWebJob.exe run is copied below.

[02/17/2017 22:04:00 > 40f151: SYS INFO] Status changed to Starting
[02/17/2017 22:04:00 > 40f151: SYS INFO] WebJob singleton setting is False
[02/17/2017 22:04:12 > 40f151: SYS INFO] Run script 'BillingWebJob.exe' with script host - 'WindowsScriptHost'
[02/17/2017 22:04:12 > 40f151: SYS INFO] Status changed to Running
[02/17/2017 22:04:19 > 40f151: INFO] Found the following functions:
[02/17/2017 22:04:19 > 40f151: INFO] BillingWebJob.Program.CronJob
[02/17/2017 22:04:20 > 40f151: INFO] Executing: 'Program.CronJob' - Reason: 'Timer fired at 2017-02-17T22:04:20.1740855Z'
[02/17/2017 22:04:20 > 40f151: INFO] Job started for fetching billing data at 02/17/2017 22:04:20
[02/17/2017 22:04:20 > 40f151: INFO] Starting job processing for Customer Type csp
[02/17/2017 22:04:20 > 40f151: INFO] Starting CSP Routine. Current Usage, Historic Usage and Historic Billing data will be updated..
[02/17/2017 22:04:20 > 40f151: INFO]
[02/17/2017 22:04:20 > 40f151: INFO] Fetching records for Current Month's Usage from the API. This may take a while. If this operation is timimg out, consider increasing the TimeOut limit in Configuration file.
[02/17/2017 22:07:36 > 40f151: INFO]
[02/17/2017 22:07:36 > 40f151: INFO] 1216 records fetched from the API..
[02/17/2017 22:07:36 > 40f151: INFO]
[02/17/2017 22:07:36 > 40f151: INFO] All Usage data which exist in DB will be deleted and replaced by new line items.
[02/17/2017 22:07:42 > 40f151: INFO]
[02/17/2017 22:07:42 > 40f151: INFO] 0 usage records exist in DB and will be deleted.
[02/17/2017 22:07:42 > 40f151: INFO]
[02/17/2017 22:07:42 > 40f151: INFO] 1216 new usage records will be added to the database.
[02/17/2017 22:08:24 > 40f151: INFO]
[02/17/2017 22:08:24 > 40f151: INFO] Now fetching historic usage and billing records from the API month-by-month.
[02/17/2017 22:08:24 > 40f151: INFO]
[02/17/2017 22:08:24 > 40f151: INFO] Fetching dates from the config..
[02/17/2017 22:08:24 > 40f151: INFO]
[02/17/2017 22:08:24 > 40f151: INFO] Fetching Csp Billing and Summary data from 07/01/2016 00:00:00 to 02/17/2017 22:08:24
[02/17/2017 22:08:24 > 40f151: INFO]
[02/17/2017 22:08:24 > 40f151: INFO] Routine started for 7-2016
[02/17/2017 22:08:24 > 40f151: INFO] Checking Db for existing csp billing records for the month 7-2016..
[02/17/2017 22:08:24 > 40f151: INFO] No existing records found in Database for this month. Calling API for the data..
[02/17/2017 22:09:37 > 40f151: INFO] 244 data rows returned from the csp summary api.
[02/17/2017 22:09:37 > 40f151: INFO] 5703 data rows returned from the csp billing api.

[ssugar]

@snpdev - Glad to hear it helped.

[UtkarshVIT]

@ssugar thank you for pointing that out. merging the pull request.