Number of frames in .bag file does not correspond to expected number of frames

[pasandal]

• Before opening a new issue, we wanted to provide you with some useful suggestions (Click "Preview" above for a better view):

  • Consider checking out SDK examples.
  • Have you looked in our documentations?
  • Is you question a frequently asked one?
  • Try searching our GitHub Issues (open and closed) for a similar issue.

• All users are welcomed to report bugs, ask questions, suggest or request enhancements and generally feel free to open new issue, even if they haven't followed any of the suggestions above :)

---

Required Info
Camera Model	D435I
Firmware Version	05.12.12.100
Operating System & Version	Win 10
Platform	PC
SDK Version	2.44.0.3073
Language	python
Segment	others

Issue Description

After upgrading from pyrealsense2==2.35.0.1791 to pyrealsense2==2.44.0.3073, the number of frames in the recorded bag file does not correspond the the expected number of frames in the bag file.

Here is an example code to illustrate the issue:

import time
import pyrealsense2 as rs2

camera_framerate = 30
row = 480
col = 848

def enable_all_streams(config):
    config.enable_stream(
        stream_type=rs2.stream.depth,
        width=col,
        height=row,
        format=rs2.format.z16,
        framerate=camera_framerate,
    )
    config.enable_stream(
        stream_type=rs2.stream.color,
        width=col,
        height=row,
        format=rs2.format.bgr8,
        framerate=camera_framerate,
    )

#Make recording
duration = 5
bag_path = r"c:\temp\recording.bag"
config = rs2.config()
pipeline = rs2.pipeline()
ctx = rs2.context()
devices = ctx.query_devices()
serial_number = devices[0].get_info(rs2.camera_info.serial_number)
config.enable_device(serial_number)
enable_all_streams(config)
config.enable_record_to_file(bag_path)

pipeline.start(config)
#Wait for 5 seconds
time.sleep(duration)
pipeline.stop()

#Read bag file
config = rs2.config()
pipeline = rs2.pipeline()
config.enable_device_from_file(bag_path, repeat_playback=False)
enable_all_streams(config)
pipeline_profile = pipeline.start(config)
playback = pipeline_profile.get_device().as_playback()
playback.set_real_time(False)

success = True
frame_number = 0
while success:
    success, frameSet = pipeline.try_wait_for_frames(1000)
    frame_number += 1

print(f"Numbers of frames read from the bag file: {frame_number} | Expected number of frames: {camera_framerate*duration}")

When using pyrealsense2==2.35.0.1791 the result is:
Numbers of frames read from the bag file: 136 | Expected number of frames: 150
with pyrealsense2==2.44.0.3073 the result is:
Numbers of frames read from the bag file: 270 | Expected number of frames: 150

The number of frames read from the bag file is doubled when using the 2.44.0.3073 version.
Have you changed something in the SDK that I should be aware of, or is this a bug?

Regards, Paul

[MartyG-RealSense]

Hi @pasandal I am not aware of a change between these SDK versions that would radically alter your results.

I would not recommend placing confidence in calculating an expected number of frames by multiplying framerate by duration. This may provide an 'ideal' figure to use as a guideline. In practice though there are real-world factors that will affect the actual total number of frames in the bag, such as dropped frames during recording.

The code of your frame-counter frame_number looks okay to me, and you are correctly preventing bag looping and setting set_real_time to false.

It looks as though the script uses a sleep period to set a 5 second duration from the start of the script before the pipeline is stopped. I wonder if it may work better to put a timer check into the frame count mechanism, so if the value of frame_number is greater than camera_framerate*duration (your expected maximum bag length) then the pipeline is stopped.

I also note that you are recording depth and color together. It may therefore be worth enforcing a constant frame rate when recording to prevent a frame-rate dip. The link below provides details of Python code for how to do so when auto-exposure is enabled by disabling a setting called Auto-Exposure Priority.

#8205 (comment)

[pasandal]

Thanks for feedback @MartyG-RealSense .

Yes, replacing camera_framerate*duration with int(camera_framerate*playback.get_duration().total_seconds()) will provide a more accurate result. The actual duration turns out to be 4.898734 seconds
This means that I received 270 frames from a bag file with duration of 4.898734 seconds which gives a fps value of 270.0 / 4.898734 = 55 fps As seen in the code above, I enabled the stream using 30 fps on both depth and color.

If I run the same code with pyrealsense2==2.35.0.1791 I get in total 135 frames within 4.83415 seconds which results in 135 / 4.83415 = 27.9 fps

If I remove either color or depth stream I get the expected FPS (around 30) with both SDK versions.

Why does the frame rate of the two SDK versions deviate so much when recording both depth and color?
Paul

[MartyG-RealSense]

The amount of time that has passed between 2.35.0 and 2.44.0 would make it very difficult to identify a specific cause for a change in performance. In these situations, it is easier to try older versions in small steps (e.g 2.37.0, 2.39.0, 2.41.0 etc) to narrow down the point in the SDK's history at which the behavior of the script changes. It may not be worth doing so though unless you are curious, as you will still likely need to return to using the modern SDK version afterwards.

A notable historical change was when there were internal changes in the firmware from firmware version 5.12.8.200 onwards so that a minimum of SDK version 2.39.0 was required

A way to validate the FPS of the bag's depth and color streams would be to launch the RealSense Viewer tool without a camera plugged in and then import the bag into the Viewer, either by using the Add Source option at the top of the options side-panel or by drag-and-dropping the bag into the center panel of the Viewer. The bag will begin automatically playing, and if you left-click on the 'i' option at the top of each stream panel so that the 'i' is colored blue (On) then the FPS of each stream will be displayed.

[pasandal]

@MartyG-RealSense this is not a performance issue. The issue is that the python SDK reads 270 frames in a file where there only exists 135 frames.

If i change the frame_number += 1 counter with the built-in frameSet.get_frame_number() method, like this:

while success:
    success, frameSet = pipeline.try_wait_for_frames(1000)
    if success:
        frame_number = frameSet.get_frame_number()
        print(frame_number)

the printed result is:

....
....
128
128
129
129
130
130
131
131
132
132
133
133
134
134
135
135

This indicates that pipeline.try_wait_for_frames(1000) method reads each frames two times before proceeding to next frame.
I tried to add a time.sleep(0.1) between each frame read to check if I was reading the frame too fast, but the result was the same.
When using the pyrealsense2==2.35.0.1791 version however, the printed result is:

....
....
128
129
130
131
132
133
134
135

Realsense.Viewer is showing the correct values: 135 frames / around 30 fps

The change of behavior happens when going from ver 2.40.0.2483 to ver 2.41.0.2666. In 2.40.0.2483 the frameSet.get_frame_number() increases between each frame and in 2.41.0.2666 the frameSet.get_frame_number() increases every second frame.

[MartyG-RealSense]

The first pipeline open-close section handles the bag recording part of the program and then the second pipeline open is for the playback, yes?

My next question would be the method that you use to build librealsense on Windows. Do you use the automated installer file on the Releases page or build it with CMake?

If the frame count is reported consistently as 2x the correct total every time, a hacky workaround til a permanent solution is found may be to increment frame_number by 0.5 instead of 1.

[pasandal]

@MartyG-RealSense, you are correct about the pipeline start/stop logic.

I installed pyrealsense2 via pip with the following command: pip install pyrealsense2==2.44.0.3073, and downloaded the stand alone Intel.RealSense.Viewer.exe from you release page.

An incorrect frame number is not the main issue here. The biggest burden is that we are reading duplicate frames which leads to a 2x post-processing time and a wrong fps when storing the frames in a mp4 file after the video processing.

Yes, a workaround could be to discard every second frame, but then I prefer to use the old SDK version until it is fixed.

Are you able to replicate the duplicate frame behavior when using the 2.44.0.3073 version @MartyG-RealSense?

[MartyG-RealSense]

My computer is not set up to run pyrealsense2 and so I cannot perform a validation test of the duplicate frame behavior.

Duplication of frames can occur during recording of a bag, if the stream has a 'hiccup' and returns to the last known good frame before continuing onwards. I have not seen a case before where every single frame is duplicated though. If you are using the same bag file on 2.35.0 and 2.44.0 then that would suggest that the source of the problem is not within the bag-file.

Given that the row of dots at the top of the frame number list is printed twice, this makes me wonder whether the frames are actually being duplicated in reality or whether the on-screen information is just being printed twice.

[pasandal]

Sorry for the confusion. I typed in the dots manually to illustrate that there are in addition 127 frame numbers printed out.

I ran a test to identify the source of the problem and this is the result:

1. Make bag file with 2.44.0 and read it with 2.35.0 results in none duplicated frames
2. Make bag file with 2.35.0 and read it with 2.44.0 results in duplicated frames
3. Make bag file with 2.35.0 and read it with 2.35.0 results in none duplicated frames
4. Make bag file with 2.44.0 and read it with 2.44.0 results in duplicated frames
5. Make bag file with 2.44.0 and read it with RealSense Viewer 2.43.0 results in none duplicated frames

It is quite clear that the source of the problem is not the bag-file, but the pipeline.try_wait_for_frames() method.

Do you have the opportunity to ask someone in your team to do a validation test @MartyG-RealSense?

[MartyG-RealSense]

For the moment, this particular phenomenon (a repeat of every frame instead of just some frames) seems to be an isolated case rather than a suspected bug to refer for deeper testing, as there have not been reports of the same effect from other RealSense users.

Now that librealsense 2.45.0 and Python wrapper 2.45.0.3217 are available, would it be possible to upgrade again and check whether the same effect is present in the latest SDK?

Also, does the problem still occur if you use wait_for_frames instead of try_wait_for_frames? The difference between the two instructions is that if there is a time-out when using try_wait_for_frames then it simply returns a 'False' result instead of throwing an exception.

#2422 (comment)

Thanks very much!

[pasandal]

@MartyG-RealSense , One user has to be the first. :)

To verify that this is a bug and not an isolated case, I did the following:

1. Downloaded outdoors.bag file from your github page Outdoors scene captured with D415 pre-production sample (Depth from Stereo)
2. Installed python 3.9 and 2.45.0.3217 SDK on a clean windows 10 computer
3. Ran the code below which resulted in count: 380
4. Downgraded SDK to 2.35.0.1791
5. Ran the code again which resulted in count: 194

import pyrealsense2 as rs2

path = r"C:\temp\outdoors.bag"
config = rs2.config()
pipeline = rs2.pipeline()
config.enable_stream(rs2.stream.depth, 1280, 720, rs2.format.z16, 30)
config.enable_stream(rs2.stream.color, 640, 480, rs2.format.rgb8, 30)

config.enable_device_from_file(path, repeat_playback=False)

pipeline_profile = pipeline.start(config)
playback = pipeline_profile.get_device().as_playback()
playback.set_real_time(False)
count = 0
success = True

while success:
    try:
        frames = pipeline.wait_for_frames(1000)
        print(frames.get_frame_number())
        count += 1

    except:
        success = False

print(count)

[MartyG-RealSense]

Thanks very much for your careful testing. I will seek further advice from Intel. Thank you for your patience!

[pasandal]

Thank you. I am glad you are looking into it.

[MartyG-RealSense]

After discussion with Intel, I set up a Python 3.9.5 installation on a Windows 10 computer with the latest pyrealsense2 wrapper and librealsense 2.45.0. I ran your script and confirmed the repeating frames. I have provided Intel with a log of the frame-counter output and will discuss it further with them.

[pasandal]

Ok. Thanks for update!

[MartyG-RealSense]

Hi @pasandal An official bug report about the duplicating frame-count when reading a bag file in pyrealsense2 on Windows 10 has been filed with Intel. This case should be left open whilst that bug report is active. Thanks again for reporting the issue! In the meantime, the best solution for you may be to continue using SDK 2.35.0 for your project.

[shivak7]

I can confirm this is definitely not an isolated case. I spent days trying to figure out what went wrong in my C++ code when I finally narrowed it down to differences between SDK versions 2.45 and 2.36. I examined the problem in more detail by looking at individual frame numbers and timestamps directly from the stream of the bag file, and this is what I found. It's not exactly duplicating framesets. However there are duplicate frames across different framesets. In other words, with the newer SDKs each frameset staggers color and depth alternatively.

For example the original sequence of frameset grabs during wait_for_frames() or poll_for_frames() is:
(c1,d1), (c2,d2), (c3,d3), ... (c_n, d_n) where, c and d stand for color and depth frames. They are best matched according to timestamps.

With the new SDK version this is the sequence I get: (c1,d1), (c1, d2), (c2,d2), (c2,d3), (c3,d3), (c3, d4)... etc.

As you can see duplicate frames across framesets are alternatively staggered almost like some bad interpolation instead of properly matching frames together. This leads to approximately doubling of the frames as reported by psandal. Hope this information helps. I will try to post actual stats from my bag file to illustrate this issue.

Edit: Posting actual numbers from my tests:
First with the 2.36 SDK. Frames are optimally matched. There are rare duplicates but over all things add up. Each frameset grab results in unique color and depth frames as you can see from the relative timestamps. (relative timestamps are calculated by subtracting the first frame's timestamp from the current timestamp and dividing by 1000 to convert into seconds).

Frameset Depth_Frame Color_Frame Time_difference
Frame: 0 Time1:0.01666 Time2:0.009694 Difference:0.006966
Frame: 1 Time1:0.033321 Time2:0.026494 Difference:0.006827
Frame: 2 Time1:0.049982 Time2:0.043294 Difference:0.006688
Frame: 3 Time1:0.066642 Time2:0.060094 Difference:0.006548
Frame: 4 Time1:0.083303 Time2:0.076894 Difference:0.006409
Frame: 5 Time1:0.099964 Time2:0.093694 Difference:0.00627
Frame: 6 Time1:0.116624 Time2:0.110494 Difference:0.00613
Frame: 7 Time1:0.133285 Time2:0.127294 Difference:0.005991
Frame: 8 Time1:0.149946 Time2:0.144094 Difference:0.005852
Frame: 9 Time1:0.166606 Time2:0.160894 Difference:0.005712
Frame: 10 Time1:0.183267 Time2:0.177694 Difference:0.005573

Now with the 2,45 SDK this is what I get:

Frameset Depth_Frame Color_Frame Time_difference
Frame: 0 Time1:0.016661 Time2:0.009555 Difference:0.007106
Frame: 1 Time1:0.016661 Time2:0.026355 Difference:-0.009694
Frame: 2 Time1:0.016661 Time2:0.043155 Difference:-0.026494
Frame: 3 Time1:0.033321 Time2:0.043155 Difference:-0.009834
Frame: 4 Time1:0.033321 Time2:0.059955 Difference:-0.026634
Frame: 5 Time1:0.049982 Time2:0.059955 Difference:-0.009973
Frame: 6 Time1:0.049982 Time2:0.076755 Difference:-0.026773
Frame: 7 Time1:0.066643 Time2:0.076755 Difference:-0.010112
Frame: 8 Time1:0.066643 Time2:0.093555 Difference:-0.026912
Frame: 9 Time1:0.083303 Time2:0.093555 Difference:-0.010252
Frame: 10 Time1:0.083303 Time2:0.110355 Difference:-0.027052

Here you can see that going by frame timestamp as an ID, that each frameset is different but frames are usually staggered alternatively. Additionally, the color frame timestamps are not the same for some reason across the two different SDKs!

[MartyG-RealSense]

Thanks very much @shivak7 for the detailed feedback about your own experiences with this issue!

[shivak7]

Thanks very much @shivak7 for the detailed feedback about your own experiences with this issue!

Glad to help. I too would like this fixed ASAP. If @pasandal is correct in his claim that 2.43 does not result in duplicate frames when reading from a bag file, then I think I've possibly narrowed down the issue to the file: concurrency.h or a related file which might have been affected during the Mar 21st update.

[shivak7]

Actually further investigation into 2.43 suggests that this fix might be the potential cause of this bug: #8378

[MartyG-RealSense]

@shivak7 I cannot provide a time estimate for when the bug report related to the repeating frames issue will be actioned upon, and so cannot guarantee an ASAP fix. Your feedback about possible causes will be able to read by Intel RealSense team members though when handling the bug report.

[shivak7]

@MartyG-RealSense That's OK. I've reverted to SDK version 2.36 and am using a custom workaround to handle another bug which was the reason I upgraded to 2.45 in the first place. I'm good for now.

[MartyG-RealSense]

Thanks very much @shivak7 for the update!

As mentioned earlier, this case will remain open whilst there is an active bug report relating to this issue.

[pasandal]

@MartyG-RealSense Would it be possible to get an estimate on when this bug will be looked at? I noticed that the issue is not included in the Release Note - Known issues list. Is it because you have placed the issue in a kind of backlog? I consider it as a pretty critical bug which should have been given more attention...

[MartyG-RealSense]

The bug has been officially logged with Intel but there is no further information to provide or a time estimate regarding when a fix might be delivered if it is confirmed to be a bug. I suggest trying 2.49.0 to see whether the problem has been corrected as a side-effect of changes to other systems in the SDK.

[Nir-Az]

Hi @pasandal ,
I ran the python script attached on latest LibRealSense version 2.49 and the result is as expected (136 frames)
I am not sure what was the version that the fix was introduce but I am glad to say the issue is no longer exist.
Please update if you find it fixed on latest release.

Thanks for notifying on the issue.

[MartyG-RealSense]

@Nir-Az Thanks very much for your help! The Intel bug report DSO-17075 associated with this case has now been closed.

[MartyG-RealSense]

Case closed due to the associated Intel bug report DSO-17075 having been closed.