dwSensorManager_acquireNextEvent does not return "oldest available event among all sensors"

Autonomous Vehicles DRIVE AGX Xavier DRIVE AGX Xavier General
1

Having a problem as described in topic.

Steps to reproduce:

  1. /usr/local/driveworks/tools/capture/recorder-tui 4cam.json
    (the 4cam.json file is for 4x sf3325 cameras)

  2. Use dwSensorManager_acquireNextEvent and dwSensorCamera_getImage in a loop with the recording in step 1. I used a simplified version of sample_sfm.

  3. Add dwImage_getTimestamp to get timestamp and display it for debugging, e.g.

    void processCamera(const dwSensorEvent& event)
    ...
        for (size_t k = 0; k < event.numCamFrames; k++)
        ...
            dwTime_t currentTimestamp;
            CHECK_DW_ERROR(dwImage_getTimestamp(&currentTimestamp, camera.frameCudaYuv));
            std::cout << k << " " << currentTimestamp << std::endl;
        ...
    ...
    }

Expected:

The timestamps should be in consecutive order because dwSensorManager_acquireNextEvent should return “oldest available event among all sensors”

Actual:

Timestamps not consecutive, e.g.:

0 1619516073418415
1 1619516073551740
2 1619516073651728
3 1619516073751751
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619516073451730
1 1619516073585055
2 1619516073685076
3 1619516073785099

Extra notes

When the same 4cam.json is used directly by the same application based on sample_sfm, timestamps are in order, e.g.

0 1619517985418409
1 1619517985418409
2 1619517985418409
3 1619517985418409
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517985451753
1 1619517985451753
2 1619517985451753
3 1619517985451753

However, there are hundreds (474) of lines worth of ICP DROP messages before processCamera is even reached, e.g.

[27-04-2021 20:06:12] CameraGMSL: Frame: 12 CaptureTimestamp: 1619517972618426 - ICP DROP in camera 2
[27-04-2021 20:06:12] CameraGMSL: Frame: 12 CaptureTimestamp: 1619517972618426 - ICP DROP in camera 0
[27-04-2021 20:06:12] CameraGMSL: Frame: 12 CaptureTimestamp: 1619517972618426 - ICP DROP in camera 1
[27-04-2021 20:06:12] CameraGMSL: Frame: 12 CaptureTimestamp: 1619517972618426 - ICP DROP in camera 3
[27-04-2021 20:06:12] CameraGMSL: Frame: 13 CaptureTimestamp: 1619517972651757 - ICP DROP in camera 2
[27-04-2021 20:06:12] CameraGMSL: Frame: 13 CaptureTimestamp: 1619517972651757 - ICP DROP in camera 1
[27-04-2021 20:06:12] CameraGMSL: Frame: 13 CaptureTimestamp: 1619517972651757 - ICP DROP in camera 3
[27-04-2021 20:06:12] CameraGMSL: Frame: 13 CaptureTimestamp: 1619517972651757 - ICP DROP in camera 0

But it settles down after a few seconds:

[27-04-2021 20:06:16] CameraGMSL: Frame: 128 CaptureTimestamp: 1619517976485100 - ICP DROP in camera 3
[27-04-2021 20:06:16] CameraGMSL: Frame: 129 CaptureTimestamp: 1619517976518435 - ICP DROP in camera 3
[27-04-2021 20:06:16] CameraGMSL: Frame: 129 CaptureTimestamp: 1619517976518435 - ICP DROP in camera 2
[27-04-2021 20:06:16] CameraGMSL: Frame: 129 CaptureTimestamp: 1619517976518435 - ICP DROP in camera 1
[27-04-2021 20:06:16] CameraGMSL: Frame: 129 CaptureTimestamp: 1619517976518435 - ICP DROP in camera 0
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517972518428
1 1619517972518428
2 1619517972518428
3 1619517972518428
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517972551750
1 1619517972551750
2 1619517972551750
3 1619517972551750
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517972585103
1 1619517972585103
2 1619517972585103
3 1619517972585103
[27-04-2021 20:06:16] CameraGMSL: Frame: 130 CaptureTimestamp: 1619517976551743 - ICP DROP in camera 0
[27-04-2021 20:06:16] CameraGMSL: Frame: 130 CaptureTimestamp: 1619517976551743 - ICP DROP in camera 3
[27-04-2021 20:06:16] CameraGMSL: Frame: 130 CaptureTimestamp: 1619517976551743 - ICP DROP in camera 2
[27-04-2021 20:06:16] CameraGMSL: Frame: 130 CaptureTimestamp: 1619517976551743 - ICP DROP in camera 1
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517976585086
1 1619517976585086
2 1619517976585086
3 1619517976585086

Please provide the following info (check/uncheck the boxes after clicking “+ Create Topic”):
Software Version
DRIVE OS Linux 5.2.0
DRIVE OS Linux 5.2.0 and DriveWorks 3.5
NVIDIA DRIVE™ Software 10.0 (Linux)
NVIDIA DRIVE™ Software 9.0 (Linux)
other DRIVE OS version
other

Target Operating System
Linux
QNX
other

Hardware Platform
NVIDIA DRIVE™ AGX Xavier DevKit (E3550)
NVIDIA DRIVE™ AGX Pegasus DevKit (E3550)
other

SDK Manager Version
1.5.0.7774
other

Host Machine Version
native Ubuntu 18.04
other

2

Hi @sleff ,

Doesn’t It look inex 0 has the oldiest timestamp? What did you mean consecutive? Could you explain the problem more? Thanks.

Please see if ICP DROP error in the log of recorder tool helps on this.

3

Hi @VickNV

Doesn’t It look inex 0 has the oldiest timestamp? What did you mean consecutive? Could you explain the problem more? Thanks.

I thought that “oldest available event among all sensors” means that timestamps should be in order from oldest to newest. Events are batched in numCamFrame, assumed to be synchronised.

However, in the example, which I have labelled 0, 1, 2, 3, 0, 1, 2, 3 according to numCamFrame, do you see that 1619516073751751 is older than 1619516073451730 by 300021? It makes no sense to order oldest only by index 0, because otherwise there is no reason to batch up the events in the first place.

0 1619516073418415
1 1619516073551740
2 1619516073651728
3 1619516073751751
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619516073451730
1 1619516073585055
2 1619516073685076
3 1619516073785099

It doesn’t seem that “oldest timestamp” is supposed to be ordered by index 0 only, because in live (not recorded by /usr/local/driveworks/tools/capture/recorder-tui, it seems that timestamps in each batch should have the same.

0 1619517985418409
1 1619517985418409
2 1619517985418409
3 1619517985418409
dwSensorManager_acquireNextEvent DW_SUCCESS
0 1619517985451753
1 1619517985451753
2 1619517985451753
3 1619517985451753
4

I didn’t compare timestamps of events from different dwSensorManager_acquireNextEvent() calls. Now I got your point.

So, you observed the issue by running sample_sfm with virtual cameras (recorded by recorder-tui 4cam.json) but didn’t with live cameras. Am I right?

5

Hi @VickNV

So, you observed the issue by running sample_sfm with virtual cameras (recorded by recorder-tui 4cam.json) but didn’t with live cameras. Am I right?

Yes. To make it reproducible for this issue, I also made some modifications to sample_sfm to remove CAN dependency, but the relevant parts should be the same.

6

Could you share your patch file for sample_sfm and the virtual camera rig file for reproducing the issue on my side? Thanks.

8

Attached:

changes.patch (2.4 KB)
4cam-virtual.json (3.6 KB)
timestamps.zip (38.6 KB)

I also shared the *.timestamps files, which may be useful for you to reproduce.

9

@VickNV any update on this? Thanks

10

It looks the four cameras have different timestamp counts.

$ tail *\.timestamps
==> C0.h264.timestamps <==
1618 1619587666371789
1619 1619587666405123
1620 1619587666438447
1621 1619587666471782
1622 1619587666505096
1623 1619587666538449
1624 1619587666571778
1625 1619587666605124
1626 1619587666638421
1627 1619587666671783

==> C1.h264.timestamps <==
1621 1619587666471782
1622 1619587666505096
1623 1619587666538449
1624 1619587666571778
1625 1619587666605124
1626 1619587666638421
1627 1619587666671783
1628 1619587666705101
1629 1619587666738451
1630 1619587666771785

==> C2.h264.timestamps <==
1622 1619587666605124
1623 1619587666638421
1624 1619587666671783
1625 1619587666705101
1626 1619587666738451
1627 1619587666771785
1628 1619587666805120
1629 1619587666838455
1630 1619587666871786
1631 1619587666905139

==> C3.h264.timestamps <==
1627 1619587666705101
1628 1619587666738451
1629 1619587666771785
1630 1619587666805120
1631 1619587666838455
1632 1619587666871786
1633 1619587666905139
1634 1619587666938437
1635 1619587666971794
1636 1619587667005111

The same timestamp is at different positions of different timestamps files.

$ grep 1619587666471782 *\.timestamps
C0.h264.timestamps:1621 1619587666471782
C1.h264.timestamps:1621 1619587666471782
C2.h264.timestamps:1618 1619587666471782
C3.h264.timestamps:1620 1619587666471782

Do you think it has something to do with " - ICP DROP in camera " messages during recording? You may need to solve that first.

11

Yes, that is why I attached the timestamps files.

Did you try to reproduce the issue with recorder-tui? Were your timestamps files the same across all cameras?

I assumed it could be normal for timestamps to begin at different times because cameras are started one after another. Does DriveWorks not handle synchronisation?

12

I observed a async issues with our timestamps files (under /usr/local/driveworks-2.2/data/tools/preFlightChecker/pfc_vsensors) but all the files have the same timestamp count.
For the async issue, I guess it may be due to lack of time sensor setup mentioned in DriveWorks SDK Reference: Time which is supported from DRIVE OS 5.2.0.

13

@VickNV do you have any other suggestions?

The system is not behaving as expected doing basic operations. Simply using recorder-tui to record using the rig file I attached previously results in timestamps files that are out of sync.

14

Are you sure this is related? It seems to add more confusion. Time module does not seem to be available in DRIVE SOFTWARE 10.0 with DriveWorks 2.2. Also, it seems Time module is for time sync across different types of sensors (e.g. lidar and radar). For GMSL camera, they are already synchronised: DRIVE OS Linux

15

I’ll discuss with internal team and get back to you. Thanks.

16

Please also share 4cam.json you used to run recorder-tui and how the four cameras was connected to the DRIVE system. In the mean time, please try to solve " - ICP DROP in camera " and see if helps.

17

4cam.json attached. The cameras are just connected on the quad cable.

4cam.json (3.8 KB)

Regarding " - ICP DROP in camera ", I will check file:///usr/local/driveworks-2.2/doc/nvsdk_html/dwx_recording_devguide_high_throughput_recording.html. I’m using Samsung T7 SSD so it is fast enough for 4 cameras. However, the " - ICP DROP in camera " messages happen even when not recording, e.g. immediately after starting sample_sfm.

18

@VickNV any news from the internal team, and have you been able to use my 4cam.json file?

Btw, my USB write speed is 427 MB/s.

20

I read your post again. " - ICP DROP in camera " weren’t from recorder-tui during recording.
I think it should be nothing to do with the timestamps files.

Did you see any suspicious messages during recording with recorder-tui?

The timestamps unalignment issue between timestamps files is also seen on our internal branch.
That means applications need to handle them.
We are discussing SensorManager aligns the frames and returns aligned frames.
Anyhow, it won’t be available in current release verions.