ScanBatcher returning true before scan is done (Name updated)

iAmir97 commented 1 year ago

Describe your question I have a problem when getting the timestamps when reading PCAP files. I have files that have been recorded with 2.4 FW, and files that have been recorded with FW3.0, and I am currently using the newest ouster-sdk. I calculate the timestamps the following way:

    auto status = scan.status();
    auto it = std::find_if(status.data(), status.data() + status.size(),[](const uint32_t s){return (s & 0x01);}); // find first valid status
    auto index = std::distance(status.data(), it);
    if (it != status.data() + status.size()) {
        std::cout <<"status: "<< status(it - status.data()) << std::endl;
        std::cout <<"ts: " <<std::chrono::nanoseconds(scan.timestamp()(it - status.data())).count() << std::endl;
        return std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::nanoseconds(scan.timestamp()(it - status.data()))).count();  // get corresponding timestamp
    }else{
        return 0;
    }

which is similar to what I have seen in your examples. when using pcaps recorded with FW3.0 (non-legacy profiles) I do not have any problems and the output of status is always 1, and a correct unix timestamp. but when I use pcaps recorded with FW2.4 ( or legacy profile FW3.0) I get these

------------FW2.4------------

status: 4294967295
ts: 1670570875461034496
status: 4294967295
ts: 1670570875461034496
status: 4294967295
ts: 1670570875461034496
status: 4294967295
ts: 1670570875461034496
status: 25851
ts: 113571820208470
status: 25851
ts: 113571820208470

------------FW3.0 legacy profile------------

status: 4294967295
ts: 1684172716100256000
status: 4294967295
ts: 1684172716100256000
status: 4294967295
ts: 1684172716200325632
status: 4294967295
ts: 1684172716200325632

in the FW3.0 legacy, I get no wrong timestamps, just unusual status, but for the FW2.4 I get the wrong status but it still prints the timestamp. I hope my explanation is clear, Thanks.

Screenshots If applicable, add screenshots to help explain your problem.

Platform (please complete the following information):

Ouster Sensor? [e.g. OS-0, OS-1, ..] OS2-128(FW2.4) OS1-128(FW3.0)
Ouster Firmware Version? [e.g. 2.3, 2.4, ..] OS2-128(FW2.4) OS1-128(FW3.0)
Programming Language? [e.g. C++, Python, ..] C++
- For Python include the targeted Python version
Operating System? [e.g. Linux, Windows, MacOS] Linux
Machine Architecture? [e.g. x64, arm] x64
git commit hash (if not the latest).

iAmir97 commented 1 year ago

Forgot to mention, the OS2-128 is Rev 6, the OS1-128 is Rev 7

Samahu commented 1 year ago

I don't know what's fully encoded in the status field across different udp profiles but for a measurement to be considered i.e. valid only the first bit (LSB) needs to be on. Please refer to the Column Header Block section in our Non-LEGACY Lidar Packet Format and also the Measurement Block Status section in the LEGACY Lidar Packet Format.

iAmir97 commented 1 year ago

Using the FW3.0, is there a way to access the Measurement block status? because in the code i posted access the first bit of status isn't always correct. so is there another way to access this in the legacy lidar packets?

iAmir97 commented 1 year ago

Upon closer inspection, I found out the problem is located in the ScanBatcher, it returns True prematurely.

ScanBatcher not done, packet num: 1 - frame id: 6116
ScanBatcher not done, packet num: 2 - frame id: 6116
ScanBatcher not done, packet num: 3 - frame id: 6116
ScanBatcher not done, packet num: 4 - frame id: 6116
ScanBatcher not done, packet num: 5 - frame id: 6116
ScanBatcher not done, packet num: 6 - frame id: 6116
ScanBatcher not done, packet num: 7 - frame id: 6116
ScanBatcher not done, packet num: 8 - frame id: 6116
ScanBatcher not done, packet num: 9 - frame id: 6116
ScanBatcher not done, packet num: 10 - frame id: 6116
ScanBatcher not done, packet num: 11 - frame id: 6116
ScanBatcher not done, packet num: 12 - frame id: 6116
NEW FRAME old id: 11660 new id: 6116
ScanBatcher is done
Timestamp[0]: 1.67057e+12 1
ScanBatcher not done, packet num: 0 - frame id: 6116
NEW FRAME old id: 6116 new id: 11660

When I looked closer at the difference between FW3.0 and FW2.4 Pcap packets, the FW2.4 Pcap has multiple fragments of IPv4 then a UDP packet, while FW3.0 have UDP packets only. Any suggestion as to where this might be going wrong or how to fix this?

Samahu commented 1 year ago

Upon closer inspection, I found out the problem is located in the ScanBatcher, it returns True prematurely.

I am trying to understand the log that you have produced .. it seems like you have a frame jump from 11660 -> 6116 and then there was a jump back again to 11660. Is that what you are described as that ScanBatcher is returning prematurely?

When I looked closer at the difference between FW3.0 and FW2.4 Pcap packets, the FW2.4 Pcap has multiple fragments of IPv4 then a UDP packet, while FW3.0 have UDP packets only. Any suggestion as to where this might be going wrong or how to fix this?

Did you record the two pcap files on the same machine and same network setup? It might be that you had different MTU size between the two which would result in a packet fragmentation. Also the udp lidar profile will affect how much fragmentation that you incur.

iAmir97 commented 1 year ago

. I am trying to understand the log that you have produced .. it seems like you have a frame jump from 11660 -> 6116 and then there was a jump back again to 11660. Is that what you are described as that ScanBatcher is returning prematurely?

yes, you can see it jumps from 6616 -> 11660, then 11660 -> 6616 which doesn't make sense so my guess is it could be a fragmented packet? or packet not read correctly?

. Did you record the two pcap files on the same machine and same network setup? It might be that you had different MTU size between the two which would result in a packet fragmentation. Also the udp lidar profile will affect how much fragmentation that you incur.

Two different machines and network, Same profile they are all using the Legacy profile. but yeah the FW3.0 produced by newest ouster studio only issues UDP packets, while the FW2.4 (where I face the issue) has segmented IPv4 packets and a UDP packet the reassembles them. Appreciate your help on this matter

iAmir97 commented 1 year ago

Oh yeah just for clarification, i am not running them both at the same time, just trying to support both pcaps at different runtimes

Samahu commented 1 year ago

yes, you can see it jumps from 6616 -> 11660, then 11660 -> 6616 which doesn't make sense so my guess is it could be a fragmented packet? or packet not read correctly?

This basically happens when a lost packet found its way very late and caused this disturbance. The ScanBatcher implementation does not handle this situation very well. The reason is on a good network setup it is very unlikely that this could happen. A LidarScan object consumes about 64 packets to build the frame, you may have an off by one packet from the previous frame or the next frame and the current ScanBatcher implementation does handle these this scenario sufficiently. However, in the case where you have packets that is off by more than one frame then this isn't currently handled and and will result in double jumps. In my experience I have only seen this happen when I connect to the sensor via WiFi or through a poor network adapter.

Samahu commented 1 year ago

Two different machines and network, Same profile they are all using the Legacy profile. but yeah the FW3.0 produced by newest ouster studio only issues UDP packets, while the FW2.4 (where I face the issue) has segmented IPv4 packets and a UDP packet the reassembles them. Appreciate your help on this matter

Since you mentioned it is two different machines and networks I don't think you can attribute the timestamp differences to differences in the FW. I don't think timestamp handling has changed between the two firmwares. The status flag though may had extra information encoding but I think that packet validity check remains the same.

iAmir97 commented 1 year ago

Yeah it could be the Wi-Fi or the network, sre there any temporary solutions to overcome this?

iAmir97 commented 1 year ago

so yeah currently the problem isn't the timestamps its just the ScanBatcher, I changed the name of the issue for your convinience

iAmir97 commented 1 year ago

. However, in the case where you have packets that is off by more than one frame then this isn't currently handled and and will result in double jumps. In my experience, I have only seen this happen when I connect to the sensor via WiFi or through a poor network adapter.

it's worth noting that this is across many pcap recordings, not just a single one, most of them on different machines and setups, but the only common thing among them is (IPv4 + FW2.4 + Rev 6)

iAmir97 commented 1 year ago

ScanBatcher not done, packet num: 11 - frame id: 6742
payload size: 24896
ScanBatcher not done, packet num: 12 - frame id: 6742
payload size: 48
NEW FRAME old id: 19815 new id: 6742

Capture

these small sized packets happen frequently

iAmir97 commented 1 year ago

so after reading more about it those are IMU packets I think, in newer firmware I think they are merged in the same UDP packets as lidar scans, but for old firmware it was not. Problem solved so Im closing this ticket, thanks @Samahu.

kairenw commented 1 year ago

How did you record your FW 2.4 pcaps? Are your lidar and imu packets being sent to the same port? Do you mind sending us one of your broken pcaps?

Your Ouster Studio FW 3.0 pcaps don't contain IMU packets because (for now) Ouster Studio doesn't record them.

ouster-lidar / ouster-sdk

ScanBatcher returning true before scan is done (Name updated) #516