LoL - onHighlightsCaptured missing highlights near end of match missing for multikills (quadra in this case)

Colorfulstan · March 11, 2021, 2:02pm

Issue Description:
If a user gets a multikill, highlights recording waits for a pottential penta kill (I assume).
Since that has a very long time, I think the highlight is never produced.
I did not do a detailed investigation on this though, so it is possible that there is

some maybe informative lines from highlights.log:

2021-01-22 20:20:38,065 (INFO) Notify replay to consumer [dmpfhbhjknfmncjinjaikncjjnklcplnodamiimn] is ready.
2021-01-22 20:20:38,066 (INFO) copy replay to consumer folder: C:\Users\\Videos\Overwolf\Ekko\League of Legends\League of Legends_01-22-2021_19-52-29-772\League of Legends 01-22-2021 20-19-43-387.mp4 - C:\Users\\Videos\Overwolf\Ekko\League of Legends\League of Legends_01-22-2021_19-52-29-772\Thumbnails\League of Legends 01-22-2021 20-19-43-387.jpg
2021-01-22 20:22:55,819 (INFO) On Game highlight (5426): feature [kill] data [kill] 
2021-01-22 20:22:55,820 (INFO) Start New replay
2021-01-22 20:22:55,821 (INFO) Start capture replay. trigger data [name: kill, past: 12000, future: 8000, pending: 12000 data:kill]
2021-01-22 20:22:55,823 (INFO) start stop time. internal: 20000 stop time: 01/22/2021 20:23:15
2021-01-22 20:22:57,500 (INFO) On Game highlight (5426): feature [kill] data [double_kill] 
2021-01-22 20:22:57,502 (INFO) Adding event to active replay. trigger data [name: kill, past: 13680, data:double_kill reset:True]. estimate replay length: 21680 (21680). estimate stop time: 01/22/2021 20:23:17
2021-01-22 20:22:57,503 (INFO) start stop time. internal: 20000 stop time: 01/22/2021 20:23:17
2021-01-22 20:23:03,436 (INFO) On Game highlight (5426): feature [kill] data [triple_kill] 
2021-01-22 20:23:03,437 (INFO) Adding event to active replay. trigger data [name: kill, past: 19616, data:triple_kill reset:True]. estimate replay length: 29616 (29616). estimate stop time: 01/22/2021 20:23:25
2021-01-22 20:23:03,438 (INFO) start stop time. internal: 22000 stop time: 01/22/2021 20:23:25
2021-01-22 20:23:07,818 (INFO) On Game highlight (5426): feature [kill] data [quadra_kill] 
2021-01-22 20:23:07,820 (INFO) Adding event to active replay. trigger data [name: kill, past: 23998, data:quadra_kill reset:True]. estimate replay length: 33998 (33998). estimate stop time: 01/22/2021 20:23:39
2021-01-22 20:23:07,821 (INFO) start stop time. internal: 32000 stop time: 01/22/2021 20:23:39
2021-01-22 20:23:29,282 (INFO) On Game highlight (5426): feature [assist] data [assist] 
2021-01-22 20:23:29,283 (INFO) Adding event to active replay. trigger data [name: assist, past: 45462, data:assist reset:False]. estimate replay length: 53462 (53462). estimate stop time: 01/22/2021 20:23:49
2021-01-22 20:23:29,284 (INFO) start stop time. internal: 20000 stop time: 01/22/2021 20:23:49
2021-01-22 20:23:36,464 (INFO) On Game highlight (5426): feature [victory] data [victory] 
2021-01-22 20:23:36,466 (INFO) Adding event to active replay. trigger data [name: victory, past: 52644, data:victory reset:False]. estimate replay length: 62644 (62644). estimate stop time: 01/22/2021 20:23:56
2021-01-22 20:23:36,467 (INFO) start stop time. internal: 20000 stop time: 01/22/2021 20:23:56
2021-01-22 20:23:41,162 (WARN) ending replay! (game terminated?)
2021-01-22 20:23:41,208 (ERROR) Fail to capture replay: Cannot stop replay
2021-01-22 20:23:41,211 (ERROR) Fail to capture highlight's replay: Cannot stop replay
2021-01-22 20:23:41,213 (INFO) Stop capture replay

As you can see, there were single kill events, but no highlight produced before - what I think is - the game close killing the recorder.
Right before that a highlight for kill,assist,death came in.
Can you reproduce it (exact steps to reproduce):
Impact for my app: non-blocking, but it’s super frustrating for users to lose their game winning tripple/quadra kill highlights

Do you currently have a workaround?
No

Please reproduce and attach a zip package of your OW client logs
Please mention the time of the event so we can find it easily in the logs

tom.wolf · January 26, 2021, 8:18pm

We do have a mechanism to gracefully stop a replay when the game ends while the recording is still on.
There might have been something else problematic here, so if you could send us the entire log dir that would help.

Colorfulstan · January 27, 2021, 7:35pm

Edit: please see comment after this first

I think in this specific case that graceful mechanism didn’t work.

I’m mostly focused on these last lines where it says (highlights.log) :
2021-01-22 20:23:41,162 (WARN) ending replay! (game terminated?)
2021-01-22 20:23:41,208 (ERROR) Fail to capture replay: Cannot stop replay

Which tells me that overwolf tried to end the replay, but something went wrong with finishing the replay.

Can you confirm that this is a meaningless log, or look into the reasoning behind it?
You can follow it along there from the kill->double_kill->triple_kill->quadra_kill → game end → recording failed.

I don’t believe that sequence of events is influenced by the onHighlightsCaptured listener, is it?

Colorfulstan · January 27, 2021, 7:34pm

I see that (despite me being convinced we removed it) we use overwolf.media.replays.turnOff call right at the end of a match.
So that might have caused the error maybe?

I will add a delay to set cleanup, so we get the last item emitted by overwolf.
Do you have a suggestion on the timing there?

eransharv · January 28, 2021, 9:19am

@Colorfulstan, I guess that the best way is to give your new setting and timing a try and keep an eye on it. If the issue is reproduced, please attach the FULL log package, and we will keep investigating it.

For now, I’m keeping the ticket open for your updates.