question

Jimmie Tyrrell avatar image
Jimmie Tyrrell asked

Duplicate PlayStream events from CloudScript call

I am executing a CloudScript request called StartRound. I've set `GeneratePlayStreamEvent` to true on my requests, for debugging purposes.

A single call to ExecuteCloudScript seems to be generating TWO of the exact same PlayStream events. Here are the two events I see in the Data tab of PlayFab's web ui:

First one:

{
  "FunctionName": "StartRound",
  "PlayFabEnvironment": {
    "Application": "logicserver",
    "Vertical": "master",
    "Commit": "176b41f",
    "Cloud": "main"
  },
  "CloudScriptExecutionResult": {
    "FunctionName": "StartRound",
    "ExecutionTimeSeconds": 0.0938777,
    "ProcessorTimeSeconds": 0.0,
    "MemoryConsumedBytes": 12472,
    "HttpRequestsIssued": 0,
    "APIRequestsIssued": 1,
    "FunctionResult": {
      "RoundId": "ef148303"
    },
    "Revision": 184,
    "Logs": []
  },
  "EventNamespace": "com.playfab",
  "EntityType": "player",
  "SourceType": "BackEnd",
  "EventName": "player_executed_cloudscript",
  "Timestamp": "2020-10-27T02:26:10.6218461Z",
  "EntityId": "51D005C65A98499C",
  "TitleId": "6D4B7",
  "EventId": "519d14c6571744ac9115bdb16acede5e",
  "Source": "CloudScript"
}

Second one:

{
  "FunctionName": "StartRound",
  "PlayFabEnvironment": {
    "Application": "logicserver",
    "Vertical": "master",
    "Commit": "176b41f",
    "Cloud": "main"
  },
  "CloudScriptExecutionResult": {
    "FunctionName": "StartRound",
    "ExecutionTimeSeconds": 0.0938777,
    "ProcessorTimeSeconds": 0.0,
    "MemoryConsumedBytes": 12472,
    "HttpRequestsIssued": 0,
    "APIRequestsIssued": 1,
    "FunctionResult": {
      "RoundId": "ef148303"
    },
    "Revision": 184,
    "Logs": []
  },
  "EventNamespace": "com.playfab",
  "EntityType": "player",
  "SourceType": "BackEnd",
  "EventName": "player_executed_cloudscript",
  "Timestamp": "2020-10-27T02:26:10.6218461Z",
  "EntityId": "51D005C65A98499C",
  "TitleId": "6D4B7",
  "EventId": "519d14c6571744ac9115bdb16acede5e",
  "Source": "CloudScript"
}

This is not a copy/paste error - these two PlaySteam entries are exactly the same. The EventId, the timestamp. Here's a screenshot of what I'm seeing: https://i.imgur.com/yqqdAlZ.png

So, if this is a double-logging bug, no biggie.

But, what's weird about this particular request is that it failed for me (at least from my client's perspective). In C# terms, I executed `PlayFabClientAPI.PlayFabClientAPI.ExecuteCloudScript`, and the error callback got executed.

I'm still trying to track down more information about the error my client received. My question is, is the double-logging possibly related to the error? Or is this just a completely independent bug?

Any help would be greatly appreciated. Thanks

1 comment
10 |1200
Toggle Comment visibility. Current Visibility: Viewable by all users

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

Jimmie Tyrrell avatar image Jimmie Tyrrell commented ·

One follow up - I just checked my client logs and saw the following:

/Client/ExecuteCloudScript: Request timeout

Again, curious if the double-logging thing is somehow related to a request timeout.

Also, just surprised to see a request timeout. Clearly the request made it to the server, and processed in .1s. Obviously could've been a network blip, but the double logging just has me thinking it's something else.

0 Likes 0 ·

1 Answer

·
Seth Du avatar image
Seth Du answered

This can be a temporary display issue on Game Manager. I have checked the “player_executed_cloudscript” event within the latest 1000 events in your title, and there are only 2 and no duplicated events. You may also confirm it in PlayFab Explorer.

6 comments
10 |1200
Toggle Comment visibility. Current Visibility: Viewable by all users

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

Jimmie Tyrrell avatar image Jimmie Tyrrell commented ·

Thanks for the follow up! We are seeing a lot of request timeouts that seem like they shouldn't be happening. Me and my co-developer both have very stable internet connections, and they happen sporadically.

For example this one - I see an entry in the PlayStream Event History UI. But the user's client raised the same error:

/Client/ExecuteCloudScript: Request timeout

There's also a log error with this message:

curl error 28 connection timed out after 3000 milliseconds with 0 bytes received

But the request executed successfully according to PlayStream (EventId 7990c3d806d54051a95f624fd3250490 fyi). The result output is as expected

Any ideas why this might be happening? The request is a bit expensive, could that be the reason?

"FunctionName": "UnlockCrate",
"ExecutionTimeSeconds": 0.1210364,
"ProcessorTimeSeconds": 0.0,
"MemoryConsumedBytes": 96880,
"HttpRequestsIssued": 0,
"APIRequestsIssued": 4,

^ Do you think these metrics might be getting us throttled?

0 Likes 0 ·
Seth Du avatar image Seth Du ♦ Jimmie Tyrrell commented ·

This can be a platform-specfic issue. May I ask which platform you are using to implement your project? Can you reproduced this issue via Restful Api testing tools like Postman?

0 Likes 0 ·
Jimmie Tyrrell avatar image Jimmie Tyrrell Seth Du ♦ commented ·

We're using Unity. I've tried all 3 different web request types - Unity, Http, and Custom - they all seem to have this issue. I will test with Postman to see if we can reproduce it.

Have you heard of anyone else having this issue with Unity?

One theory I have is that I'm making too many web requests, they're not running in parallel for some reason, and so they get queued up. The delay from queueing ends up going over the timeout of 3000 milliseconds. Though I'm not sure where I could even configure this 3000. My PlayFabSharedSettings object is configured for 2000 milliseconds.

0 Likes 0 ·
Show more comments

Write an Answer

Hint: Notify or tag a user in this post by typing @username.

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