Curious Performance Characteristics

[iiSeymour]

Describe the bug

Running a converted recurrent network from PyTorch has some curious performance characteristics were running the .pb model directly in TensorFlow is ~2.5 times slower than the the onnx runtime.

$ ./benchmark model
> onnx runtime took 4.83842
> tensorflow took 12.63854

Looking at the trace information shows that work is only being done for about 3.5 seconds:

To Reproduce

#!/usr/bin/env python

"""
Benchmark ONNX model
"""

import os
os.environ['TF_CPP_MIN_LOG_LEVEL'] = '3'

import sys
import time
import warnings
from argparse import ArgumentParser

import numpy as np
import numpy.testing

import onnxruntime as runtime

import tensorflow as tf
from tensorflow.python.client import timeline

if not sys.warnoptions:
    warnings.filterwarnings("ignore")
    tf.compat.v1.logging.set_verbosity(tf.compat.v1.logging.ERROR)


def main(args):

    x = np.random.randn(args.chunksize, args.batchsize, 1).astype(np.float32)

    # == ONNX Runtime ==

    options = runtime.SessionOptions()
    session = runtime.InferenceSession(args.model + ".onnx", options)

    input_name = session.get_inputs()[0].name
    output_name = session.get_outputs()[0].name

    t0 = time.time()
    onnxrt_out = session.run([output_name], {input_name: x})
    onnxrt_out = np.array(onnxrt_out[0])
    t1 = time.time()
    print("> onnx runtime took %.5f" % (t1 - t0))
 
    # == TensorFlow ==

    with tf.compat.v1.Session() as session:
        with tf.io.gfile.GFile(args.model + ".pb", "rb") as graph:
            g = tf.compat.v1.GraphDef()
            g.ParseFromString(graph.read())
            tf.import_graph_def(g)

        graph = tf.get_default_graph()
        first = graph.get_tensor_by_name("import/input:0")
        last = graph.get_operations()[-1].outputs[0]

        run_options = tf.RunOptions(trace_level=tf.RunOptions.FULL_TRACE)
        run_metadata = tf.RunMetadata()

        t0 = time.time()
        tensorflow_out = session.run(
            last,
            feed_dict={first: x},
            options=run_options,
            run_metadata=run_metadata
        )
        t1 = time.time()

        tl = timeline.Timeline(run_metadata.step_stats)
        ctf = tl.generate_chrome_trace_format()
        with open('trace_file.json', 'w') as f:
            f.write(ctf)

    print("> tensorflow took %.5f" % (t1 - t0))

    numpy.testing.assert_allclose(
        onnxrt_out,
        tensorflow_out,
        atol=1e-4
    )


if __name__ == "__main__":
    parser = ArgumentParser()
    parser.add_argument("model")
    parser.add_argument('--batchsize', type=int, default=1000)
    parser.add_argument('--chunksize', type=int, default=1000)
    main(parser.parse_args())

ONNX model file

• ONNX https://www.dropbox.com/s/jv0hk9h62eymax2/model.onnx
• TensorFlow https://www.dropbox.com/s/t2n4ut7kwfjq8j2/model.pb

Python, ONNX, ONNX-TF, Tensorflow version

• Python version: 3.5.3
• ONNX version: 1.5.0
• ONNX-TF version: GRU support with linear_before_reset #452
• Tensorflow version: 1.14.0

Additional context

• Trace file https://www.dropbox.com/s/vhaq5ykt6vlu5ij/trace_file.json