Scheduled Cloud Script Task fails from time to time

Question

question

Fausto Bernardini asked Oct 28, '23

Scheduled Cloud Script Task fails from time to time

I have an Azure Cloud Script to reset my game's Leaderboard at 2am UTC. The script has been running for 4 months. It normally executes successfully, but every 10-20 days it will fail. When that happens, the leaderboard is not updated and my users play the previous day's game, which is a bad experience.

This happened yesterday:

 {
     "TaskInstanceId": "DD11FE5A615B4ADF-122",
     "TaskIdentifier": {
         "Name": "Reset Daily Highest Score 2",
         "Id": "DD11FE5A615B4ADF"
     },
     "StartedAt": "2023-10-28T02:01:13.2659967Z",
     "CompletedAt": "2023-10-28T02:21:15.8530709Z",
     "Status": "Aborted"
 }

And this on October 11:

 {
     "TaskInstanceId": "DD11FE5A615B4ADF-104",
     "TaskIdentifier": {
         "Name": "Reset Daily Highest Score 2",
         "Id": "DD11FE5A615B4ADF"
     },
     "StartedAt": "2023-10-11T02:01:10.4123393Z",
     "CompletedAt": "2023-10-11T02:01:45.2545085Z",
     "Status": "Failed",
     "Error": "The function Reset Daily Highest Score Leaderboard 2 was terminated after the maximum execution time limit: 4500ms"
 }

What should I do? Should I check for failure of the script's execution and retry until success?

I should mentions that I have been using the Free Tier of PlayFab so far, but have now upgraded to pays-as-you-go. Will that help? (I'm thinking I may have had lower priority in acquiring resources to run the script).

Please help as I'm launching my Title and cannot risk these failures. Happy to provide logs and/or code samples as needed.

Thanks, Fausto

CloudScript

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

Answer 1 · 2023-10-30T09:59:21Z

Neils Shi answered Oct 30, '23

If the scheduled task failing with a timeout, then it does not mean that the Azure Function execution failed, it means that PlayFab did not get a response to the current request within the time limit, but the function is still running. If your Azure Function is running properly, timeout errors in the scheduled task should not affect the results of the function run. However, since you mention that when the scheduled task fails, the leaderboard will not be updated, so, we suggest you check the Azure Portal Log Stream page to see if the function generates any error message when the Task fails. In addition, if you just want to reset the leaderboards, you can refer to Using resettable statistics and leaderboards - PlayFab | Microsoft Learn.

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

Answer 2 · 2023-11-01T00:33:38Z

Fausto Bernardini answered Nov 1, '23

Thank you for your answer Neils:

If the scheduled task failing with a timeout, then it does not mean that the Azure Function execution failed, it means that PlayFab did not get a response to the current request within the time limit, but the function is still running. If your Azure Function is running properly, timeout errors in the scheduled task should not affect the results of the function run.

Well, the end result is that the leaderboards are not reset when the task fails (you can see from my post that in once case it was a timeout, in the other is says "Aborted")

However, since you mention that when the scheduled task fails, the leaderboard will not be updated, so, we suggest you check the Azure Portal Log Stream page to see if the function generates any error message when the Task fails.

I did that, but the task succeeded tonight, below is the log:

 2023-10-31T02:00:58Z   [Verbose]   Initiating background SyncTriggers operation
 2023-10-31T02:01:04Z   [Information]   Executing StatusCodeResult, setting HTTP status code 204
 2023-10-31T02:01:08Z   [Verbose]   Request successfully matched the route with name 'ResetDailyHighestScoreLeaderboard2' and template 'api/ResetDailyHighestScoreLeaderboard2'
 2023-10-31T02:01:08Z   [Information]   Executing 'ResetDailyHighestScoreLeaderboard2' (Reason='This function was programmatically called via the host APIs.', Id=7ecc9ee4-ce2b-4b69-b983-bc4f7c067fee)
 2023-10-31T02:01:08Z   [Information]   >> Start ResetDailyHighestScoreLeaderboard
 2023-10-31T02:01:09Z   [Information]   >> Reset Leaderboard: Daily Highest Score Classic 2, v125, DeactivationTime: (null)
 2023-10-31T02:01:09Z   [Information]   >> Reset Leaderboard: Daily Highest Score Expert 2, v125, DeactivationTime: (null)
 2023-10-31T02:01:09Z   [Information]   Executed 'ResetDailyHighestScoreLeaderboard2' (Succeeded, Id=7ecc9ee4-ce2b-4b69-b983-bc4f7c067fee, Duration=734ms)

Is there a way to see logs from previous days, when the error occurred?

In addition, if you just want to reset the leaderboards, you can refer to Using resettable statistics and leaderboards - PlayFab | Microsoft Learn.

Unfortunately as far as I can tell I cannot choose at what time of the day I want my leaderboards reset. My game is a daily puzzle and I need it to start at a time different from 00:00 UTC. Let me know if I missed anything.

In summary, I am still looking for a definitive answer to this problem. Any other pointers?

Here is my function, FYI:

 using System;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Http;
 using Microsoft.Azure.WebJobs;
 using Microsoft.Azure.WebJobs.Extensions.Http;
 using Microsoft.Extensions.Logging;
 using Newtonsoft.Json;
 using PlayFab;
 using PlayFab.Samples;
    
 namespace NewYorkShowsOff.WordLace
 {
     public static class NewBaseType2
     {
         [FunctionName("ResetDailyHighestScoreLeaderboard2")]
         public static async Task<uint> Run(
             [HttpTrigger(AuthorizationLevel.Function, "post", Route = null)]
             HttpRequest req, ILogger log)
         {
             log.LogInformation(">> Start ResetDailyHighestScoreLeaderboard");
             ScheduledTaskFunctionExecutionContext context =
                 JsonConvert.DeserializeObject<ScheduledTaskFunctionExecutionContext>(
                     await req.ReadAsStringAsync()
                 );
    
             string developerSecretKey = Environment.GetEnvironmentVariable("PLAYFAB_DEV_SECRET_KEY", EnvironmentVariableTarget.Process);
    
             var adminApi = new PlayFabAdminInstanceAPI(
                 new PlayFabApiSettings
                 {
                     TitleId = context.TitleAuthenticationContext.Id,
                     DeveloperSecretKey = developerSecretKey
                 },
                 new PlayFabAuthenticationContext
                 {
                     EntityToken = context.TitleAuthenticationContext.EntityToken
                 }
             );
    
             PlayFabSettings.staticSettings.DeveloperSecretKey = developerSecretKey;
             PlayFabSettings.staticSettings.TitleId = "XXXXX";   // hidden
    
             // reset classic leaderboard
             var newRequest = new PlayFab.AdminModels.IncrementPlayerStatisticVersionRequest
             {
                 StatisticName = "Daily Highest Score Classic 2"
             };
    
             var newResult = await adminApi.IncrementPlayerStatisticVersionAsync(newRequest);
    
             log.LogInformation(">> Reset Leaderboard: {0}, v{1}, DeactivationTime: {2}",
                 newResult.Result.StatisticVersion.StatisticName,
                 newResult.Result.StatisticVersion.Version,
                 newResult.Result.StatisticVersion.DeactivationTime
             );
    
             // reset expert leaderboard
             newRequest = new PlayFab.AdminModels.IncrementPlayerStatisticVersionRequest
             {
                 StatisticName = "Daily Highest Score Expert 2"
             };
    
             newResult = await adminApi.IncrementPlayerStatisticVersionAsync(newRequest);
    
             log.LogInformation(">> Reset Leaderboard: {0}, v{1}, DeactivationTime: {2}",
                 newResult.Result.StatisticVersion.StatisticName,
                 newResult.Result.StatisticVersion.Version,
                 newResult.Result.StatisticVersion.DeactivationTime
             );
    
             //return new { newResult.Result };
             //return new { newResult.Result.StatisticVersion };
             return newResult.Result.StatisticVersion.Version;
         }
     }
 }

2

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

Neils Shi commented · Nov 02, 2023 at 09:57 AM

If you want to view the previous logs, you can refer to Monitoring Azure Functions with Azure Monitor Logs | Microsoft Learn.

0 ·

Fausto Bernardini Neils Shi commented · Nov 05, 2023 at 05:40 PM

i do see some historical logs but could not find the failing one. I'll keep watching for them. In the meantime, is there anything wrong with my script? why would it run ok most times but fail sometimes?

0 ·

Answer 3 · 2023-11-06T03:15:52Z

Fausto Bernardini answered Nov 6, '23

Today the script failed again, after 10 successful executions.

This is the playfab response:

 {
     "TaskInstanceId": "DD11FE5A615B4ADF-132",
     "TaskIdentifier": {
         "Name": "Reset Daily Highest Score 2",
         "Id": "DD11FE5A615B4ADF"
     },
     "StartedAt": "2023-11-06T02:01:14.7774958Z",
     "CompletedAt": "2023-11-06T02:01:49.1380842Z",
     "Status": "Failed",
     "Error": "The function Reset Daily Highest Score Leaderboard 2 was terminated after the maximum execution time limit: 4500ms"
 }

I was watching the logstream on Azure, but all I got was this. It seems like the function just did not execute

 Connected!
 2023-11-06T02:59:58Z   [Verbose]   Initiating background SyncTriggers operation
 2023-11-06T03:00:07Z   [Information]   Executing StatusCodeResult, setting HTTP status code 204

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

Answer 4 · 2023-11-06T03:43:57Z

Fausto Bernardini answered Nov 6, '23

28 minutes later I got this:

 2023-11-06T03:28:13Z   [Verbose]   Initiating background SyncTriggers operation
 2023-11-06T03:29:21Z   [Information]   Host Status: {
   "id": "resetdailyhighestscoreleaderboar",
   "state": "Running",
   "version": "4.27.5.21549",
   "versionDetails": "4.27.5+096e48198ef4cc3259d9ad0f45891a74992825a6",
   "platformVersion": "100.0.7.517",
   "instanceId": "4dd8e98f154af9bddba1c3c11f33cd46040b2baa6b9b058b1ce9a8580076f5a2",
   "computerName": "10-30-12-0",
   "processUptime": 452338,
   "functionAppContentEditingState": "Unknown"
 }
 2023-11-06T03:29:21Z   [Information]   Host Status: {
   "id": "resetdailyhighestscoreleaderboar",
   "state": "Running",
   "version": "4.27.5.21549",
   "versionDetails": "4.27.5+096e48198ef4cc3259d9ad0f45891a74992825a6",
   "platformVersion": "100.0.7.517",
   "instanceId": "4dd8e98f154af9bddba1c3c11f33cd46040b2baa6b9b058b1ce9a8580076f5a2",
   "computerName": "10-30-12-0",
   "processUptime": 452426,
   "functionAppContentEditingState": "Unknown"
 }

Any ideas?

5

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

Neils Shi commented · Nov 07, 2023 at 07:34 AM

The code you provided looks fine. And as mentioned before, if the scheduled task failing with a timeout, it just means that PlayFab did not get a response to the current request within the time limit, and the function is still running. According to the log you provided, it looks like the error is related to Azure side. Since we are not experts in Azure Function, you may ask Azure Team for further assistance.

0 ·

Fausto Bernardini Neils Shi commented · Nov 23, 2023 at 05:39 PM

I opened a ticket with Azure tech support and below is their answer. It seems the problem is that PlayFab automation is not firing the HTTP request at the scheduled time.

Troubleshooting:

Thank you for bringing this issue to our attention. I kindly request your assistance with the following items to ensure the accuracy and completeness of our records:

We have observed the phenomenon you mentioned. On the 20th UTC in the morning, this operation was not executed. Therefore, we compared the execution of other HTTP triggers during different time periods. We noticed that each time you execute, there is a significant delay. As a result, we are now investigating the function logs and frontend information from the 20th to the 22nd. We found that the function on your side did not execute on the 20th mainly because your app did not receive the corresponding API request. You can pass the information we provide below to the PlayFab team. After comparison, we observed that every function that received an API request was successfully executed. Therefore, it might be that PlayFab failed to send a request, or the request was sent but not correctly received on our side.

0 ·

Neils Shi Fausto Bernardini commented · Nov 24, 2023 at 06:51 AM

Based on the information you provided on November 6 about PlayFab response and Azure logstream, PlayFab sent the request at 2:01 but the Azure side initiated at 02:59, so this is inconsistent with what Azure's reply "PlayFab failed to send a request, or the request was sent but not correctly received on our side". The issue may be related to the cold start of Azure Function. The cold start will increase the function's startup time and increase the time that user waits for the function to respond. You can continue to communicate with Azure side to see if the problem is caused by the cold start. If so, you may need to switch your Azure Function Plan from Consumption to Premium to alleviate the issue. For more info, you can refer to Azure Functions scale and hosting | Microsoft Learn.

0 ·

Show more comments

Answer 5 · 2023-12-15T16:44:10Z

Fausto Bernardini answered Dec 15, '23

After working with an Azure support engineer we seem to have found a solution. I was using the free Azure tier, which apparently can cause your function to start with a delay from time to time. After switching my plan to "Function Premium" the cloud script seems to be running correctly.

In your Azure account, navigate to 'Function app>App Service plan>Change App Service plan>Choose 'Function Premium' as your new Plan type'.

Unfortunately you will incur a cost, oh well.

10 |1200

Attachments: Up to 2 attachments (including images) can be used with a maximum of 512.0 KiB each and 1.0 MiB total.

question