How to get information from the Access Log?

Question

noamtk OP

Created Nov ’18

Replies 3

Boosts 0

Views 1.6k

Participants 2

I need to get the following data during playback:

Number of dropped video frames (numberOfDroppedVideoFrames)
Number of bytes downloaded (numberOfBytesTransferred)

In theory I should be able to get those as they "happen" from AVPlayerItem's access log.

However, the logic for digging them out of the access log is not clear to me. When my observer handles a AVPlayerItemNewAccessLogEntry notification, it typically only looks at the last event. But it seems that by looking only at the last event on each invocation, I will miss more events that were added to the log since the last one - yet I don't know how many events from the end I should look at.

Moreover, the events don't cary a timestamp, so for the numberOfDroppedVideoFrames event I can't tell the period on which they occured, which is important for analytics purposes.

In my notification handler I've added code that prints all events on the log to the console. I only look at the above two metrics, and log them as DROPS and BYTES. This is what was printed after playing for ~30 seconds:

EVENTS: [<DROPS: 0 BYTES: 141752>]

EVENTS: [<DROPS: 0 BYTES: 1694552>, <DROPS: 0 BYTES: 911800>]

EVENTS: [<DROPS: 0 BYTES: 1694552>, <DROPS: 0 BYTES: 911800>, <DROPS: 0 BYTES: 821560>]

Why was the event that appears in the first handler invocation removed from the log?

Why wasn't the handler called when the event that has "BYTES: 1694552" was added to the log, so that I can catch it the the last event?

Please help.

Noam.

Boost

Answer 1

Technology Evangelist OP

Apple

Nov ’18

Hi Noam,

The last entry in the array is the entry being currently updated. The second last entry in the array is the one that has just been "freeze dried" since it will no longer be updated.

This freeze happens when a significant event, such as a transition between bitrates, occurs. The number of bytes transferred is an accumulator that runs until the next bitrate change. Thus, you can see for a given period of a given bitrate, how many bytes were transferred. The counter is reset for each bitrate transition.

Through the full collection of entries, you are able to map out most details of a given playback session.

You should receive one notification each time an event is marked as frozen.

I hope that helps to clarify what you are seeing.

Thanks,

Josh

0

Answer 2

noamtk OP

Nov ’18

Thanks Josh, it does make it clearer (assuming that by "index 0" you actually mean the last event in the events array and by "index 1" you mean the one-before-last). However:

The first line in my log (the first notification handled) contains a single event. Is that the freeze-dried event or the current event?
What about the dropped frames? When should I treat it as "complete" (as in, the frames were dropped and now playback is ok), and what is the period over which they were dropped?

Thanks again,

Noam.

0

Answer 3

Technology Evangelist OP

Apple

Nov ’18

Hi Noam,

I've updated my answer to be more clear in terms of the indexes - thank you for pointing that out.

To be even clearer, you will receive a notification each time a new access log entry is appended to the array. The first notification means that one has been added and is currently being updated. Each subsequent notification means a new entry has been appended and is now being updated, while the prior entry is now in a freeze-dried state.

The dropped frame count is an accumulator for each given bitrate tier, so those frames could have been dropped at any point during that tier. Note that a dropped frame is not considered as significant an event as when playback stalls, which triggers an AVPlayerItemPlaybackStalled notification.

I hope that helps.

Josh

0