Simple time measurement not sum up to total time

[twangnh]

Hi Xinlong, I have tried to simply measure the time cost inside the model, but found some confusing result:

I add time measure for the model and print it as:

        with torch.no_grad():
            s = time.time()

            seg_result = model(return_loss=False, rescale=not show, **data)

            torch.cuda.synchronize()
            total_time = time.time() - s
            print('total_time time {}'.format(total_time))

And add two measure for extract feature + box head, and get seg function as

        s = time.time()

        x = self.extract_feat(img)
        outs = self.bbox_head(x, eval=True)
        seg_inputs = outs + (img_meta, self.test_cfg, rescale)

        torch.cuda.synchronize()
        feat_head_time = time.time() - s
        print('feat_head_time time {}'.format(feat_head_time))

        s = time.time()

        seg_result = self.bbox_head.get_seg(*seg_inputs)

        torch.cuda.synchronize()
        get_seg_time = time.time() - s
        print('get_seg_time time {}'.format(get_seg_time))

Bold font are added code, the feat_head_time+ get_seg_time should be close to total_time, however, I found feat_head_time+ get_seg_time is about 10ms less than total_time, e.g.,

feat_head_time time 0.08217620849609375s
get_seg_time time 0.05288219451904297s
total_time time 0.14599919319152832s

I could not figure out where could the 10 ms be spent, if we measure feat_head_time+ get_seg_time as inference time, then the model should be faster. Any idea on this problem ?

[WXinlong]

@twangnh It's weird. Do you figure it out?