Timing issues with Tango image frames

It appears that Tango is dropping image frames when I try to get depth data, image data, and pose data at the same time.

I am trying to capture depth and image frames and synchronize them with pose data. Using the C point-cloud-jni-example I added code to dump point cloud data to memory buffers and then to files. I added a callback for onFrameAvailable() and copied image data to buffers and then to files. Since the image data is at 30 Hz and the depth data is at ~5 Hz I naively expected the latest image to match fairly closely with the latest depth frame. The timestamps were not very close. In some cases they were different by more than 100 milliseconds. So I started to investigate the timing on the onXYZijAvailable(), onFrameAvailable(), and onPoseAvailable() callbacks and the corresponding data timestamps.

I added logcat dumps to each callback and printed out system time (std::chrono::system_clock::now()) and the TangoSystem timestamp of the returned data, whether depth, image, or pose. Some of this was described in exactly how do we compute timestamp differentials?.

Here is some pose timing. The sys time is the current clock time when the callback is executed. The pose timestamp is from the actual pose struct.

             sys time   pose timestamp
TM CLK Pose  10.008419  245.976464
TM CLK Pose  10.025983  246.009791
TM CLK Pose  10.124470  246.043119
TM CLK Pose  10.133542  246.076447
TM CLK Pose  10.147136  246.109774
TM CLK Pose  10.192470  246.143102
TM CLK Pose  10.200370  246.176430
TM CLK Pose  10.225367  246.209757
TM CLK Pose  10.300509  246.243085
TM CLK Pose  10.311827  246.276413
TM CLK Pose  10.335946  246.309740
TM CLK Pose  10.399209  246.343068
TM CLK Pose  10.407704  246.376396
TM CLK Pose  10.426889  246.409723
TM CLK Pose  10.504403  246.443051

The corresponding differences from pose to pose are shown here. The pose timing is rock solid at 33 msec based on the recorded timestamps. The callback times vary quite a bit, presumably due to the load of the application.

time:  0.017564   pose:  0.033327
time:  0.098487   pose:  0.033328
time:  0.009072   pose:  0.033328
time:  0.013594   pose:  0.033327
time:  0.045334   pose:  0.033328
time:  0.007900   pose:  0.033328
time:  0.024997   pose:  0.033327
time:  0.075142   pose:  0.033328
time:  0.011318   pose:  0.033328
time:  0.024119   pose:  0.033327
time:  0.063263   pose:  0.033328
time:  0.008495   pose:  0.033328
time:  0.019185   pose:  0.033327
time:  0.077514   pose:  0.033328
time:  0.011892   pose:  0.033328

Here is some depth timing and corresponding differences. The timestamps are very stable at about 0.2 seconds.

             sys time : xyz timestamp
TM CLK XYZ   10.161695  246.017013
TM CLK XYZ   10.363448  246.216639
TM CLK XYZ   10.595306  246.438693
TM CLK XYZ   10.828368  246.668223
TM CLK XYZ   11.025787  246.890277
TM CLK XYZ   11.233364  247.097379
TM CLK XYZ   11.433941  247.297005
TM CLK XYZ   11.633176  247.496631
TM CLK XYZ   11.830650  247.696257

time:  0.201753   depth:  0.199626
time:  0.231858   depth:  0.222054
time:  0.233062   depth:  0.229530
time:  0.197419   depth:  0.222054
time:  0.207577   depth:  0.207102
time:  0.200577   depth:  0.199626
time:  0.199235   depth:  0.199626
time:  0.197474   depth:  0.199626
time:  0.196935   depth:  0.199626

Here is some image timing. The lines marked "---" are problem frames.

             sys time : img timestamp
TM CLK Img   10.041056  246.005896
TM CLK Img   10.074105  246.105709   -----
TM CLK Img   10.106492  246.105709
TM CLK Img   10.142581  246.138980
TM CLK Img   10.176176  246.172251
TM CLK Img   10.241146  246.205522
TM CLK Img   10.274909  246.305335   -----
TM CLK Img   10.317819  246.305335
TM CLK Img   10.361682  246.345225
TM CLK Img   10.397533  246.390139
TM CLK Img   10.472859  246.430886
TM CLK Img   10.514923  246.538175   -----
TM CLK Img   10.551663  246.545651
TM CLK Img   10.585960  246.586398
TM CLK Img   10.626671  246.620526
TM CLK Img   10.705709  246.656249
TM CLK Img   10.734324  246.767705   -----
TM CLK Img   10.774233  246.768562
TM CLK Img   10.808848  246.804285
TM CLK Img   10.847230  246.842580
TM CLK Img   10.927872  246.878303
TM CLK Img   10.957309  246.989759   -----
TM CLK Img   10.991136  246.990616

Here is the corresponding time differences for the above list.

time:  0.033049   image:  0.099813
time:  0.032387   image:  0.000000
time:  0.036089   image:  0.033271
time:  0.033595   image:  0.033271
time:  0.064970   image:  0.033271
time:  0.033763   image:  0.099813
time:  0.042910   image:  0.000000
time:  0.043863   image:  0.039890
time:  0.035851   image:  0.044914
time:  0.075326   image:  0.040747
time:  0.042064   image:  0.107289
time:  0.036740   image:  0.007476
time:  0.034297   image:  0.040747
time:  0.040711   image:  0.034128
time:  0.079038   image:  0.035723
time:  0.028615   image:  0.111456
time:  0.039909   image:  0.000857
time:  0.034615   image:  0.035723
time:  0.038382   image:  0.038295
time:  0.080642   image:  0.035723
time:  0.029437   image:  0.111456
time:  0.033827   image:  0.000857

Notice that every 4 frames there is a big delay in the image time, roughly 100 msec. This is followed by two frames with the same or nearly the same timestamp. Even in cases where the timestamp on two successive images is identical the callback still fires to indicate a new frame. The result is that I am missing every fifth frame of video. That stinks for an application trying to match depth and image data.

I have stripped any extra processing out of the code. In the callbacks the only thing that happens is the data gets copied out to static buffers. The rendering of the point cloud is still being done in the normal rendering thread.

So, what gives? Can the Tango device not handle depth, image, and pose callbacks all running at the same time? Do I need to use UpdateTexture() instead of onFrameAvailable()?

In the current version of Project Tango Tablet RGB IR camera is used for both depth and color images and it can only do one or the other for each frame. So in the stream we get 4 RGB frames followed by 1 Depth frame resulting in the pattern you observed. This is more of a hardware limitation.