Autotuning warrnings/errors on RK3399 Mali using RPC

JoeyChou · January 6, 2020, 10:32pm

Hi,

I met a lot of warning/errors messages while I was autotuing my model. I enclosed the Gist below which includes

autotune_rpc_mali_error.py

An autotuning script with a downscale model having only one Conv2D layer built from Keras.
device_clinfo_mali.log

clinfo report from the targeted RK3399 Mali(MP4) device.
host_error.log

Host a small portion of warning/error messages during tuning.

The autotuning still finished at the end with a tune log. However, when I used the tune log to cross compile the model and run on RK3399 Mali directly, I found the inference time is slower than using ARM CPU. I am not sure if its caused by the warnings/errors.

gist.github.com

https://gist.github.com/JoeyTPChou/5c1859cfe15e34690f2334402cfe6042#file-device_clinfo_mali-log

autotune_rpc_mali_error.py

#! /usr/bin/env python3

import tvm
import tvm.relay as relay
import tvm.contrib.graph_runtime as runtime
from tvm import autotvm
from tvm.autotvm.tuner import XGBTuner, GATuner, RandomTuner, GridSearchTuner
from tvm.contrib.util import tempdir

import os

This file has been truncated. show original

device_clinfo_mali.log

Number of platforms                               1
  Platform Name                                   ARM Platform
  Platform Vendor                                 ARM
  Platform Version                                OpenCL 1.2 v1.r14p0-01rel0-git(966ed26).f44c85cb3d2ceb87e8be88e7592755c3
  Platform Profile                                FULL_PROFILE
  Platform Extensions                             cl_khr_global_int32_base_atomics cl_khr_global_int32_extended_atomics cl_khr_local_int32_base_atomics cl_khr_local_int32_extended_atomics cl_khr_byte_addressable_store cl_khr_3d_image_writes cl_khr_fp64 cl_khr_int64_base_atomics cl_khr_int64_extended_atomics cl_khr_fp16 cl_khr_gl_sharing cl_khr_icd cl_khr_egl_event cl_khr_egl_image cl_khr_image2d_from_buffer cl_arm_core_id cl_arm_printf cl_arm_thread_limit_hint cl_arm_non_uniform_work_group_size cl_arm_import_memory
  Platform Extensions function suffix             ARM

  Platform Name                                   ARM Platform
Number of devices                                 1

This file has been truncated. show original

host_error.log

Extract tasks...
Total 1 layers to be tuned ...
[Task(func_name=topi_nn_conv2d, args=(('TENSOR', (1, 32, 8, 8), 'float32'), ('TENSOR', (32, 32, 1, 1), 'float32'), (1, 1), (0, 0), (1, 1), 'NCHW', 'float32'), kwargs={}, workload=('conv2d', (1, 32, 8, 8, 'float32'), (32, 32, 1, 1, 'float32'), (1, 1), (0, 0), (1, 1), 'NCHW', 'float32'))]
[Task  1/ 1]  Current/Best:    0.00/   0.00 GFLOPS | Progress: (160/1000) | 58.22 s

WARNING:autotvm:Too many errors happen in the tuning. Now is in debug mode

DEBUG:autotvm:No: 161	GFLOPS: 0.00/0.00	result: MeasureResult(costs=(RuntimeError('Traceback (most recent call last):\n  [bt] (8) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::ServerLoop()+0xe4) [0x7f81fa763c]\n  [bt] (7) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::HandleUntilReturnEvent(tvm::runtime::TVMRetValue*, bool, tvm::runtime::PackedFunc const*)+0x180) [0x7f81fa7368]\n  [bt] (6) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandleNextEvent(tvm::runtime::TVMRetValue*, bool, tvm::runtime::PackedFunc const*)+0x240) [0x7f81fadf78]\n  [bt] (5) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandleRecvPackedSeqArg()+0x318) [0x7f81fad8b8]\n  [bt] (4) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::SwitchToState(tvm::runtime::RPCSession::EventHandler::State)+0x32c) [0x7f81fac44c]\n  [bt] (3) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandlePackedCall()+0x6c8) [0x7f81fa6',),), error_no=4, all_cost=1.460705280303955, timestamp=1578348078.2993999)	[('tile_co', [-1, 2, 1]), ('tile_oh', [-1, 4, 1]), ('tile_ow', [-1, 1, 8]), ('reorder_0', [0, 1, 2, 3, 4, 5, 6, 7, 8, 9]), ('ann_reduce', ['none', 'none']), ('ann_spatial', ['unroll', 'unroll', 'vec'])],direct,None,220333
DEBUG:autotvm:No: 162	GFLOPS: 0.00/0.00	result: MeasureResult(costs=(RuntimeError('Traceback (most recent call last):\n  [bt] (8) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::ServerLoop()+0xe4) [0x7f81fa763c]\n  [bt] (7) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::HandleUntilReturnEvent(tvm::runtime::TVMRetValue*, bool, tvm::runtime::PackedFunc const*)+0x180) [0x7f81fa7368]\n  [bt] (6) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandleNextEvent(tvm::runtime::TVMRetValue*, bool, tvm::runtime::PackedFunc const*)+0x240) [0x7f81fadf78]\n  [bt] (5) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandleRecvPackedSeqArg()+0x318) [0x7f81fad8b8]\n  [bt] (4) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::SwitchToState(tvm::runtime::RPCSession::EventHandler::State)+0x32c) [0x7f81fac44c]\n  [bt] (3) /root/data/jchou/TVM/tvm/build/libtvm_runtime.so(tvm::runtime::RPCSession::EventHandler::HandlePackedCall()+0x6c8) [0x7f81fa6',),), error_no=4, all_cost=3.148015260696411, timestamp=1578348078.9530125)	[('tile_co', [-1, 16, 1]), ('tile_oh', [-1, 1, 4]), ('tile_ow', [-1, 1, 4]), ('reorder_0', [0, 1, 2, 3, 4, 5, 6, 9, 7, 8]), ('ann_reduce', ['unroll', 'none']), ('ann_spatial', ['none', 'unroll', 'vec'])],direct,None,96121
DEBUG:autotvm:No: 163	GFLOPS: 0.00/0.00	result: MeasureResult(costs=(InstantiationError(['Too large factor for unrolling'],),), error_no=1, all_cost=0.03780198097229004, timestamp=1578348075.7359238)	[('tile_co', [-1, 1, 32]), ('tile_oh', [-1, 1, 4]), ('tile_ow', [-1, 4, 1]), ('reorder_0', [0, 1, 2, 3, 4, 5, 6, 7, 8, 9]), ('ann_reduce', ['unroll', 'unroll']), ('ann_spatial', ['vec', 'unroll', 'unroll'])],direct,None,332387

This file has been truncated. show original

comaniac · January 6, 2020, 11:19pm

Your error log includes debug info of 4 configs. Two of them encountered Runtime error, one of them was schedule error, and the last one was out of host memory error. While I have no idea about the runtime error by looking at the message, the schedule error looks like a bug, and the out of host memory error could be possibly expected.

@merrymercy would you take a look at this case as well? Thanks.

JoeyChou · January 14, 2020, 9:04pm

HI @merrymercy,

Just want to follow up to see if you have some suggestion on this.

Thanks, Joey

merrymercy · January 14, 2020, 9:37pm

Your log tells that all tuning trials failed. So the tuning actually did not have any effect. The error message shows something wrong on the device. But you said you can run opencl model on your device, so your runtime should be ok.

I suspect the timeout for measurement is too small. Could you try a larger value for timeout in L112 of your script?

For @comaniac, the scheduler error is not a bug. The too large unroll factor is detected and this config is successfully dropped.

JoeyChou · January 14, 2020, 9:50pm

HI @merrymercy,

Thanks for your suggestion! However, I’ve change the timeout to 20/50/100/1000 and still got the same messages.

Joey

comaniac · January 14, 2020, 9:51pm

You’re right. I missed the error message in that config.