XiaoMi / mace

MACE is a deep learning inference framework optimized for mobile heterogeneous computing platforms.
Apache License 2.0
4.94k stars 819 forks source link

How to use hexagon_nn with unsigned PD? #581

Open apivovarov opened 4 years ago

apivovarov commented 4 years ago

I apologies for posting my question as an issue.

I'm trying to run Qualcomm/Hexagon_SDK/3.4.3/examples/hexagon_nn/tutorials on Xiaomi Mi9 phone SM8150 (SDM855).

Example: 001-nop.c (using libs/hexagon_nn/2.6)

I added #pragma weak remote_session_control and hexnn_controller_request_unsigned_pd() to 001-nop.c.

Tutorial execution in examples/hexagon_nn/tutorials shows:

python tutorials_walkthrough.py -T sm8150 -N
...
---- Run Examples on cDSP ----
---- Runing 001-nop     ----
adb wait-for-device push /root/3.4.3/libs/hexagon_nn/2.6/hexagon_Debug_dynamic_toolv83_v66/ship/libhexagon_nn_skel.so /data/local/tmp/vendor/lib/rfsa/adsp/
/root/3.4.3/libs/hexagon_nn/2.6/hexagon_Debug_dynamic_toolv83_v66/ship/libhexagon_nn_skel.so: 1 file pushed. 1.4 MB/s (5007704 bytes in 3.443s)
adb wait-for-device push /root/3.4.3/examples/hexagon_nn/tutorials/android_Debug_aarch64/ship/001-nop /data/local/tmp/vendor/bin
/root/3.4.3/examples/hexagon_nn/tutorials/android_Debug_aarch64/ship/001-nop: 1 file pushed. 0.6 MB/s (118624 bytes in 0.176s)
adb wait-for-device shell chmod 777 /data/local/tmp/vendor/bin/001-nop
adb wait-for-device shell ADSP_LIBRARY_PATH="/data/local/tmp/vendor/lib/rfsa/adsp" /data/local/tmp/vendor/bin/001-nop
***************** remote_session_control is TRUE ****************
***************** remote_session_control returned 0 ****************
fastrpc_setup Done
Trying to hexagon_nn_config
hexagon_nn_config Done
hexagon_nn_init Done
hexagon_nn_append_node Done
hexagon_nn_prepare Done
Trying hexagon_nn_execute
Whoops... run failed: -1
Test Failed, err=-1

logcat shows that remote_handle_open for libhexagon_nn_skel.so was successfull, but remote_handle_invoke failed

12-21 23:50:18.501  3565  3565 V /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:1724: Successfully opened fastrpc_shell_unsigned_3
12-21 23:50:18.521  3565  3565 V /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:1870: Successfully created user PD on domain 3 (attrs 0x8)
12-21 23:50:18.545  3565  3565 V /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:1006: remote_handle_open: Successfully opened handle 0xed2620 for hexagon_nn on domain 3
12-21 23:50:18.557  3565  3565 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:925: Error 0xffffffff: remote_handle_invoke failed for handle 0xed2620, method 12 on domain 3 (sc 0xc020200)
12-21 23:50:18.557  3565  3566 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:925: Error 0xffffffff: remote_handle_invoke failed for handle 0x3, method 4 on domain 3 (sc 0x4020200)
12-21 23:50:18.558  3565  3566 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/listener_android.c:244:listener protocol failure ffffffff
12-21 23:50:18.558  3565  3565 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:925: Error 0x27: remote_handle_invoke failed for handle 0xed2620, method 13 on domain 3 (sc 0xd010000)
12-21 23:50:18.558  3565  3566 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/fastrpc_apps_user.c:925: Error 0x27: remote_handle_invoke failed for handle 0x3, method 4 on domain 3 (sc 0x4020200)
12-21 23:50:18.558  3565  3566 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/listener_android.c:251::error: 39: 0 == (nErr = __QAIC_HEADER(adsp_listener_next2)( ctx, nErr, 0, 0, &ctx, &handle, &sc, inBufs, inBufsLen, &inBufsLenReq))
12-21 23:50:18.558  3565  3566 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/listener_android.c:333:Error 0x27: listener2 thread exited

Full example code 001-nop.c:

#include "remote.h"

#pragma weak remote_session_control

// hexagon_nn.h includes most of the things you'll need to create and run graphs.
// Its most important includes are nn_graph.h, which includes nn_graph_if.h.
// Together, these provide the data-types for input/output tensors,
//   and the API you'll use for initializing, building, preparing and running
//   your graphs.
// NOTE: hexagon_nn.h redefines malloc(), alloc(), etc. so
//   they become a compile-error "OOPS MALLOC".  This is because you should
//   use rpcmem_alloc() instead.
#include <hexagon_nn.h>

// hexagon_nn_ops.h defines the various graph operations (e.g. "MatMul", "NOP"
//   and "Relu") which you can do.  Internally, it just expands
//   interface/ops.def into a usable format.  ops.def contains the list of
//   all implemented ops.
#include "hexagon_nn_ops.h"

// For printf, etc.
#include <stdio.h>

// If you're already familiar with SDK programming for the DSP,
//   you've probably used fastRPC.  There's already lots of examples
//   documenting its use, and the purpose of this tutorial is to
//   expose the hexagon_nn_* API, so we'll ignore the fastRPC details.
// For these tutorials, we create a couple functions
//   fastrpc_setup() and fastrpc_teardown(), and some required includes.
// FastRPC allows our code running on the ARM to call functions located
//   on the DSP, quite seamlessly.
// To enable this ARM/DSP communication, we need to open a channel.
//   We'll also need to be careful later how we call functions that cross
//   the ARM/DSP partition, e.g. sending pointers, to ensure the ARM and
//   DSP see the same data.
#include "sdk_fastrpc.h"

// The structure of our NOP network looks like this.
//   It's really just a NOP floating in space, with no inputs or outputs.
//
//
//                   ==============
//    ?????????      ||    NOP   ||      ?????????
//   ??nothing??     || id=0x1000||     ??nothing??
//    ?????????      ==============      ?????????
//

int hexnn_controller_request_unsigned_pd() {
  int ret = -1;
  if (remote_session_control) {
    printf("***************** remote_session_control is TRUE ****************\n");
    struct remote_rpc_control_unsigned_module data;
    data.enable = 1;
    data.domain = CDSP_DOMAIN_ID;
    ret = remote_session_control(DSPRPC_CONTROL_UNSIGNED_MODULE, (void *) &data, sizeof(data));
    printf("***************** remote_session_control returned %d ****************\n", ret);
  } else {
    printf("***************** remote_session_control is FALSE ****************\n");
  }
  return ret;
}

int main(int argc, char **argv) {
        int err = 0;
        hexnn_controller_request_unsigned_pd();
        // Start the ARM/DSP communications channel so we can call
        //   library functions that execute on the dsp.
        if (fastrpc_setup() != 0) return 1;
        printf("fastrpc_setup Done\n");
        // The nnlib API consists of functions that begin "hexagon_nn_*"
        // This prefix indicates that the function will actually run on the DSP.
        // To run a neural network we'll use this basic API:
        //   1) hexagon_nn_config            - Start nnlib, preparing globals
        //   2) hexagon_nn_init              - Initialize a new graph
        //   3) hexagon_nn_set_debug_level   - Enable debug
        //   4) hexagon_nn_append_node       - Add nodes to the graph
        //   5) hexagon_nn_append_const_node - Add constants (pure data, not ops)
        //                                     (we won't need any for now)
        //   6) hexagon_nn_prepare           - Allocate memory, strategize,
        //                                     and optimize the graph for speed
        //   7) hexagon_nn_execute           - Run an inference
        //   8) hexagon_nn_teardown          - Destroy the graph, free resources

        // Ensures that nnlib is ready to start working.
        printf("Trying to hexagon_nn_config\n");
        hexagon_nn_config();
        printf("hexagon_nn_config Done\n");

        // Initialize a fresh, empty graph.  Return a graph-handle by reference.
        hexagon_nn_nn_id graph_id;
        if (hexagon_nn_init(&graph_id)) {
                printf("Whoops... Cannot init\n");
                return 2;
        }
        printf("hexagon_nn_init Done\n");

        // Set power level (to max/turbo)
        if ((err = hexagon_nn_set_powersave_level(0)) != 0) {
                printf("Whoops... Cannot set power level: %d\n", err);
                goto TEARDOWN;
        }

        // Select our debug level.  0=none, >4=max
        // When creating new graphs, it's nice to have max debug
        //   even if you don't think you need it.
        //hexagon_nn_set_debug_level(graph_id, 100);

        // Append a node to the graph.
        // We need to provide a unique-id so other nodes can connect.
        // The operation can be any of the ops found in interface/ops.def,
        //   prefixed with "OP_" (e.g. OP_MatMul_f, OP_Relu_f, OP_MaxPool_f)
        // Our NOP node doesn't need any padding, because it won't do anything.
        // Our input/output lists will be NULL in this example,
        //   but for real graphs we'll need to connect nodes using these lists.
        hexagon_nn_append_node(
                graph_id,           // Graph handle we're appending into
                0x1000,             // Node identifier (any unique uint32)
                OP_Nop,             // Operation of this node (e.g. Concat, Relu)
                NN_PAD_NA,          // Padding type for this node
                NULL,               // The list of inputs to this node
                0,                  //   How many elements in input list?
                NULL,               // The list of outputs from this node
                0                   //   How many elements in output list?
                );
        printf("hexagon_nn_append_node Done\n");
        // Prepare the graph for execution by optimizing it, allocating storage,
        //   connecting all the input/output pointers between nodes, and
        //   doing some basic checks, like number of input/output tensors and
        //   sizing for each node.
        if (hexagon_nn_prepare(graph_id)) {
                printf("Whoops... Cannot prepare\n");
        }
        printf("hexagon_nn_prepare Done\n");

        // Execute an inference on our input data.
        // Real graphs require input and output buffers, but we'll
        //   just use zero-size NULL pointers for this NOP example.
        uint32_t out_batches, out_height, out_width, out_depth, out_data_size;
        printf("Trying hexagon_nn_execute\n");
        if ((err = hexagon_nn_execute(
                     graph_id,
                     0, 0, 0, 0,             // Our input has 0-dimension
                     NULL,                   // Pointer to input data
                     0,                      // How many total bytes of input?
                     (unsigned int *) &out_batches,
                     (unsigned int *) &out_height,
                     (unsigned int *) &out_width,
                     (unsigned int *) &out_depth,
                     (uint8_t *)NULL,        // Pointer to output buffer
                     0,                      // Max size of output buffer
                     (unsigned int*) &out_data_size)         // Actual size used for output
                    ) != 0) {

                printf("Whoops... run failed: %d\n",err);
        }

TEARDOWN:
    // Free the memory, especially if we want to build subsequent graphs
    hexagon_nn_teardown(graph_id);

    // Stop fastRPC
    fastrpc_teardown();

    if (!err) printf("Test Passed!\n");
    else printf ("Test Failed, err=%d\n", err);

    return err;
}
lee-bin commented 4 years ago

Hi @apivovarov.

This is due to the wrong limitations on the unsigned PD of hexagon firmware on SM8150. hexagon_nn_execute calls some APIs that unsigned PD is (wrongly) prohibited to access. I heard that Qualcomm has resolved the issue, but many existing devices may have not synced with the patch. BTW, SM8250/SM7250 works just fine.

apivovarov commented 4 years ago

@lee-bin, Thank you for your reply! I just tried the latest Xiaomi image for Mi 9 (cepheus) phone cepheus_global_images_V11.0.3.0.QFAMIXM_20191115.0000.00_10.0_global

Test program 001-nop.c just hangs now. Other examples such as calculator, rpcperf and cornerApp are working fine (and worked before).

001-nop logcat:

cepheus:/ $ logcat W:* | grep 001-nop                                                                                                                                               
12-22 22:06:02.974 29154 29154 W 001-nop : type=1400 audit(0.0:4588): avc: denied { search } for name="nativetest" dev="sda31" ino=56 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:06:02.974 29154 29154 W 001-nop : type=1400 audit(0.0:4589): avc: denied { search } for name="nativetest64" dev="sda31" ino=59 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:06:02.974 29154 29154 W 001-nop : type=1400 audit(0.0:4590): avc: denied { search } for name="nativetest" dev="sda31" ino=56 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:06:02.974 29154 29154 W 001-nop : type=1400 audit(0.0:4591): avc: denied { search } for name="nativetest64" dev="sda31" ino=59 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:06:02.988 29154 29154 W /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/apps_std_imp.c:749: Warning: fopen returned 0xd for file fastrpc_shell_unsigned_3. (Permission denied)
12-22 22:06:02.988 29154 29154 E /data/local/tmp/vendor/bin/001-nop: Error 0xd: open_shell failed for domain 3
12-22 22:06:03.019 29154 29154 I /data/local/tmp/vendor/bin/001-nop: Successfully created user PD on domain 3 (attrs 0x8, debug_trace 0x0)
12-22 22:06:03.020 29154 29154 I /data/local/tmp/vendor/bin/001-nop: fastrpc_perf_init: enabled RPC traces (kernel 0, dsp 0) with frequency 1000
12-22 22:06:03.043 29154 29154 I /data/local/tmp/vendor/bin/001-nop: remote_handle_open: Successfully opened handle 0xed5760 for hexagon_nn on domain 3

Is there a way to update hexagon firmware on SM8150? My phone is unlocked. Currently SM8250/SM7250 devices are not available on the market yet. Looks like the only way to run hexagon_nnlib is to use Qualcomm dev kits. Any other options?

BTW, cornerApp is working fine - its logcat is

cepheus:/ $ logcat W:* | grep corne                                                                                                                                                 
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:980): avc: denied { search } for name="nativetest" dev="sda31" ino=56 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:981): avc: denied { search } for name="nativetest64" dev="sda31" ino=59 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:982): avc: denied { search } for name="nativetest" dev="sda31" ino=56 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:983): avc: denied { search } for name="nativetest64" dev="sda31" ino=59 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:984): avc: denied { search } for name="nativetest" dev="sda31" ino=56 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.604  3995  3995 W cornerApp: type=1400 audit(0.0:985): avc: denied { search } for name="nativetest64" dev="sda31" ino=59 scontext=u:r:shell:s0 tcontext=u:object_r:nativetest_data_file:s0 tclass=dir permissive=0
12-22 22:40:57.614  3995  3995 W cornerApp: type=1400 audit(0.0:986): avc: denied { search } for name="/" dev="sde48" ino=2 scontext=u:r:shell:s0 tcontext=u:object_r:adsprpcd_file:s0 tclass=dir permissive=0
12-22 22:40:57.624  3995  3995 W /data/local/tmp/vendor/bin/cornerApp: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/apps_std_imp.c:749: Warning: fopen returned 0xd for file fastrpc_shell_unsigned_3. (Permission denied)
12-22 22:40:57.624  3995  3995 E /data/local/tmp/vendor/bin/cornerApp: Error 0xd: open_shell failed for domain 3
12-22 22:40:57.654  3995  3995 I /data/local/tmp/vendor/bin/cornerApp: Successfully created user PD on domain 3 (attrs 0x8, debug_trace 0x0)
12-22 22:40:57.655  3995  3995 I /data/local/tmp/vendor/bin/cornerApp: fastrpc_perf_init: enabled RPC traces (kernel 0, dsp 0) with frequency 1000
12-22 22:40:57.672  3995  3995 I /data/local/tmp/vendor/bin/cornerApp: remote_handle_open: Successfully opened handle 0xed5750 for dspCV on domain 3
12-22 22:40:57.699  3995  3995 I /data/local/tmp/vendor/bin/cornerApp: remote_handle_open: Successfully opened handle 0xf06930 for cornerApp on domain 3
---- Run CornerApp Example on CDSP ----
adb wait-for-device shell ADSP_LIBRARY_PATH="/data/local/tmp/vendor/lib/rfsa/adsp" LD_LIBRARY_PATH=/data/local/tmp/vendor/lib64/ /data/local/tmp/vendor/bin/cornerApp
***************** remote_session_control is TRUE ****************
***************** remote_session_control returned 0 ****************
initq6 done...
Num corners detected: 60. Expected: 60 
run time of corner detection: 243808 microseconds for 100 iterations
deinit done...
cornerApp SUCCESS
Done

Ok, dspCV lib works but hexagon_nnlib does not, interesting...

lee-bin commented 4 years ago

Well, hexagon_nn may use some APIs that unsigned PD happens to reject to access... Redmi K30 5G is expected to be released next month...

DavinFun commented 4 years ago

@apivovarov i found two apis run error: in function "hexagon_nn_config_with_options", the function"qurt_sysenv_get_max_hw_threads" get "num_threads"=0, you can set it like this Total_Threads =4 Num_Vector_Threads =4.

Another, in function "nn_os_update_main_thread_priority", the function"nn_os_set_current_thread_priority" run error, you can comment it.

suggestion, in function "hexagon_nn_config_with_options", the function"HAP_mem_set_grow_size" can set more large, like 0x3000000

rebuild nnlib, update the "libhexagon_nn_skel.so"

apivovarov commented 4 years ago

@DavinFun I did all the changes in SDK code as you mentioned above. But examples/hexagon_nn/tutorials/001-nop.c still hangs on Xiaomi Mi9

Chengjian-Tang commented 4 years ago

@apivovarov I notice there's some "avc denied" message in your log, Did you disable the selinux? If not, can you try "setenforce 0"?

apivovarov commented 4 years ago

I tried it on unlocked but non-rooted device before.

To run setenforce 0 I need to root the device. Ok, I rooted it and run setenforce 0. Now getenforce shows Permissive

cepheus:/ # whoami
root
cepheus:/ # getenforce                                                                                                                                                              
Permissive

001-nop still hangs on hexagon_nn_execute

ADSP_LIBRARY_PATH="/data/local/tmp/vendor/lib/rfsa/adsp" /data/local/tmp/vendor/bin/001-nop
***************** remote_session_control is TRUE ****************
***************** remote_session_control returned 0 ****************
fastrpc_setup Done
hexagon_nn_version: 132608, ruturn: 0
Trying to hexagon_nn_config
hexagon_nn_config Done 0
hexagon_nn_init Done 0
hexagon_nn_set_powersave_level Done 0
hexagon_nn_append_node Done 0
hexagon_nn_prepare Done 0
Trying hexagon_nn_execute

logcat

01-12 22:33:13.104 10523 10523 I /data/local/tmp/vendor/bin/001-nop: Successfully opened fastrpc_shell_unsigned_3
01-12 22:33:13.127 10523 10523 I /data/local/tmp/vendor/bin/001-nop: Successfully created user PD on domain 3 (attrs 0x8, debug_trace 0x0)
01-12 22:33:13.128 10523 10523 I /data/local/tmp/vendor/bin/001-nop: fastrpc_perf_init: enabled RPC traces (kernel 0, dsp 0) with frequency 1000
01-12 22:33:13.150 10523 10523 I /data/local/tmp/vendor/bin/001-nop: remote_handle_open: Successfully opened handle 0xed5760 for hexagon_nn on domain 3
Chengjian-Tang commented 4 years ago

Did you enable diagnostic messages from the DSP side by creating a farf file in the ADSP_LIBRARY_PATH? It can log the DSP side log in the logcat.

apivovarov commented 4 years ago

I guess the file name should be hexagon_nn.farf. I just created it.

$ cat /data/local/tmp/vendor/lib/rfsa/adsp/hexagon_nn.farf
0x1f

I tried to run 001-nop again. logcat * shows the same log lines as before

Chengjian-Tang commented 4 years ago

No, the file name should be your process name, from the Hexagon SDK:

In order to reference a particular FastRPC process, the config file can be named in any one of the following formats:

<rpc_hlos_process_name>.farf

<rpc_hlos_pid>.farf

<rpc_adsp_asid>.farf

You can use the 'ps' or top to get the process name.

apivovarov commented 4 years ago

Ok, I added /data/local/tmp/vendor/lib/rfsa/adsp/001-nop.farf - adspmsgd enabled now

01-12 23:22:52.788 13125 13125 E /data/local/tmp/vendor/bin/001-nop: Error 0xd: open_shell failed for domain 3
01-12 23:22:52.821 13125 13125 I /data/local/tmp/vendor/bin/001-nop: Successfully created user PD on domain 3 (attrs 0x8, debug_trace 0x0)
01-12 23:22:52.822 13125 13125 I /data/local/tmp/vendor/bin/001-nop: fastrpc_perf_init: enabled RPC traces (kernel 0, dsp 0) with frequency 1000
01-12 23:22:52.833 13125 13127 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/log_config.c:178:Found 001-nop.farf. adspmsgd enabled 
01-12 23:22:52.834 13125 13128 V adsprpc : HAP_utils.c:303:0x30d6:11: Logging mask set to 31
01-12 23:22:52.853 13125 13128 V adsprpc : mod_table.c:540:0x30d7:11: open_mod_table_open_dynamic: Module hexagon_nn_skel_invoke opened successfully with handle 0xed58e0
01-12 23:22:52.853 13125 13125 I /data/local/tmp/vendor/bin/001-nop: remote_handle_open: Successfully opened handle 0xed58e0 for hexagon_nn on domain 3
01-12 23:22:52.896 13125 13128 V adsprpc : log.c:95:0x30d7:11: Arch_Version: 00000000
01-12 23:22:52.896 13125 13128 V adsprpc : log.c:107:0x30d7:11: WARN: ARCH-MISMATCH (compiled for v60 != actual v0)
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 2
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 2
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: deleted 0 dead nodes out of 1 in 1 iterations
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 3
01-12 23:22:52.897 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 2
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: deleted 0 dead nodes out of 1 in 1 iterations
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 2
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: deleted 0 dead nodes out of 1 in 1 iterations
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: deleted 0 dead nodes out of 1 in 1 iterations
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: hash ok; 1 of 1 nodes are in hash
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: graph check ok, options 7
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: freelist node @ f0df90: base=80 size=60000100
01-12 23:22:52.898 13125 13128 V adsprpc : log.c:95:0x30d7:11: Watermark says: we used 256 bytes
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: freelist node @ f0df90: base=80 size=60000100
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: Watermark says: we used 256 bytes
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: Allocated 256 bytes @ f0dff0.  Hope that's enough!
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: Checking nop node f0db20
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: nop node f0db20 check OK
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: in hexagon_nn_execute_new, 1 in 1 out
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: couldn't acquire VTCM
01-12 23:22:52.899 13125 13128 V adsprpc : log.c:95:0x30d7:11: acquire
01-12 23:22:52.900 13125 13128 V adsprpc : log.c:95:0x30d7:11: acquire done
01-12 23:22:52.900 13125 13128 V adsprpc : log.c:95:0x30d7:11: do_execute(): node=f0db20 id=1000, next at 0
01-12 23:22:52.900 13125 13128 V adsprpc : log.c:95:0x30d7:11: nop execute. self=f0db20 
01-12 23:22:52.900 13125 13128 V adsprpc : log.c:95:0x30d7:11: release
01-12 23:22:52.900 13125 13128 V adsprpc : log.c:95:0x30d7:11: release done
apivovarov commented 4 years ago

I also tried 001-nop on sdm660 dev kit (without unsigned PD) - 001-nop works. Find its logcat below:

01-13 07:31:52.687 28513 28513 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/fastrpc_apps_user.c:930: /dsp/fastrpc_shell_3 load failed 69, searching...
01-13 07:31:52.687 28513 28513 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/fastrpc_apps_user.c:933: fastrpc_shell_3 loaded successfully 
01-13 07:31:52.728 28513 28515 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/fastrpc_apps_user.c:1113: Error 4b: get adsp msgd handle failed. domain 3
01-13 07:31:52.733 28513 28514 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/apps_std_imp.c:540:Error 45: fopen failed for oemconfig.so. (No such file or directory)
01-13 07:31:52.738 28513 28514 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/apps_std_imp.c:540:Error 45: fopen failed for libadspmsgd_adsp_skel.so. (No such file or directory)
01-13 07:31:52.746 28513 28515 E /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/log_config.c:173:Found 001-nop.farf. adspmsgd enabled 
01-13 07:31:52.746 28513 28515 D /data/local/tmp/vendor/bin/001-nop: vendor/qcom/proprietary/adsprpc/src/fastrpc_apps_user.c:1095: Error 4b: adsp current process handle failed. domain 3
01-13 07:31:52.751 28513 28514 D adsprpc : HAP_utils.c:253:0x9068: CDSP: Logging mask set to 31
01-13 07:31:52.918 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: Arch_Version: 000f4060
01-13 07:31:52.919 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: hash ok; 1 of 1 nodes are in hash
01-13 07:31:52.920 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: graph check ok, options 2
01-13 07:31:52.920 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: hash ok; 1 of 1 nodes are in hash
01-13 07:31:52.921 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: graph check ok, options 2
01-13 07:31:52.921 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: deleted 0 dead nodes out of 1 in 1 iterations
01-13 07:31:52.921 28513 28514 W adsprpc : log.c:95:0x306c: CDSP: hash ok; 1 of 1 nodes are in hash
Chengjian-Tang commented 4 years ago

The suspected message is ,

01-12 23:22:52.896 13125 13128 V adsprpc : log.c:95:0x30d7:11: Arch_Version: 00000000
01-12 23:22:52.896 13125 13128 V adsprpc : log.c:107:0x30d7:11: WARN: ARCH-MISMATCH (compiled for v60 != actual v0)

I met the same issue on another Android 9 855 phone but not in Android 10. I am working on it and will post feedback.

Chengjian-Tang commented 4 years ago

I have tried serials times, only find the resolution is to flash the phone to Android 10. I am not sure if it can help you.

apivovarov commented 4 years ago

I'm using Android 10 already (MIUI Global 11.0.3) cepheus_global_images_V11.0.3.0.QFAMIXM_20191115.0000.00_10.0_global

The message ARCH-MISMATCH (compiled for v60 != actual v0) has 2 strange things

  1. compiled for v60 - it should be compiled for v66 instead
  2. actual v0 - for some reason qurt_sysenv_get_arch_version gives 00000000

Another tests which hangs on Xiaomi Mi 9 is queuetest from examples/common/asyncdspq_sample.

Console output

python asyncdspq_queuetest_walkthrough.py  -T sm8150 -N
...
---- Run asyncdspq_queuetest Example on CDSP ----
adb wait-for-device shell ADSP_LIBRARY_PATH="/data/local/tmp/vendor/lib/rfsa/adsp" /data/local/tmp/vendor/bin/queuetest
1 test loops

------------
0

asyncdspq: One message apps-DSP
Queue created; attach handle 0x00f07200

asyncdspq: One message apps-DSP
Queue created; attach handle 0x00f07200
Writing
Calling DSP
asyncdspq: One message DSP-apps
Queue created; attach handle 0x00f07200
Reading
Destroy queue

asyncdspq: Ten messages DSP-apps
Queue created; attach handle 0x00f07200
Reading

asyncdspq: Two queues - adder on DSP
Queues created. Handles 0x00f07200, 0x00f072a0. Starting adder on DSP

logcat with farf

01-13 13:13:24.256  5018  5018 I /data/local/tmp/vendor/bin/queuetest: Successfully created user PD on domain 3 (attrs 0x8, debug_trace 0x0)
01-13 13:13:24.257  5018  5018 I /data/local/tmp/vendor/bin/queuetest: fastrpc_perf_init: enabled RPC traces (kernel 0, dsp 0) with frequency 1000
01-13 13:13:24.265  5018  5020 E /data/local/tmp/vendor/bin/queuetest: vendor/qcom/proprietary/commonsys-intf/adsprpc/src/log_config.c:178:Found queuetest.farf. adspmsgd enabled 
01-13 13:13:24.293  5018  5022 V adsprpc : mod_table.c:540:0xf0be:9: open_mod_table_open_dynamic: Module queuetest_skel_invoke opened successfully with handle 0xed5900
01-13 13:13:24.293  5018  5018 I /data/local/tmp/vendor/bin/queuetest: remote_handle_open: Successfully opened handle 0xed5900 for queuetest on domain 3
01-13 13:13:24.295  5018  5018 I /data/local/tmp/vendor/bin/queuetest: remote_handle_open: Successfully opened handle 0xf07180 for asyncdspq on domain 3
01-13 13:13:24.298  5018  5022 V adsprpc : queuetest_imp.c:32:0xf0be:9: queuetest_asyncdspq_test_reads: attach_handle 15757824; nummsgs: 1
01-13 13:13:24.299  5018  5022 V adsprpc : queuetest_imp.c:55:0xf0be:9: queuetest_asyncdspq_test_reads: Done
01-13 13:13:24.302  5018  5022 V adsprpc : queuetest_imp.c:32:0xf0be:9: queuetest_asyncdspq_test_reads: attach_handle 15757824; nummsgs: 1
01-13 13:13:24.302  5018  5022 V adsprpc : queuetest_imp.c:55:0xf0be:9: queuetest_asyncdspq_test_reads: Done
01-13 13:13:24.305  5018  5022 V adsprpc : queuetest_imp.c:71:0xf0be:9: queuetest_asyncdspq_test_writes: attach_handle 15757824; nummsgs: 1
01-13 13:13:24.306  5018  5022 V adsprpc : queuetest_imp.c:89:0xf0be:9: queuetest_asyncdspq_test_reads: Done
01-13 13:13:24.309  5018  5022 V adsprpc : queuetest_imp.c:71:0xf0be:9: queuetest_asyncdspq_test_writes: attach_handle 15757824; nummsgs: 10
01-13 13:13:24.309  5018  5022 V adsprpc : queuetest_imp.c:89:0xf0be:9: queuetest_asyncdspq_test_reads: Done
01-13 13:13:24.315  5018  5022 V adsprpc : queuetest_imp.c:105:0xf0be:9: queuetest_asyncdspq_adder_spin: req_queue_attach_handle 15757824; resp_queue_attach_handle: 15757984
Chengjian-Tang commented 4 years ago

@apivovarov Besides @DavinFun's comment, I found it needs to comment other thread functions in

nn_os_restore_main_thread_priority
apivovarov commented 4 years ago

Thank you! It helped! nn_os_restore_main_thread_priority calls nn_os_set_current_thread_priority.

nn_os_set_current_thread_priority calls qurt_thread_set_priority.

I decided to fix nn_os_set_current_thread_priority by commenting out qurt_thread_set_priority inside libs/hexagon_nn/2.6/hexagon/src/nn_os_qurt.c.

Just this fix alone helped me to run hexagon_nn tutorials on prod Xiaomi Mi 9 device (non-rooted)

examples/hexagon_nn/tutorials# python tutorials_walkthrough.py -T sm8150 -N

The fix:

diff --git a/libs/hexagon_nn/2.6/hexagon/src/nn_os_qurt.c b/libs/hexagon_nn/2.6/hexagon/src/nn_os_qurt.c
index 2004cd5..fdc4b65 100755
--- a/libs/hexagon_nn/2.6/hexagon/src/nn_os_qurt.c
+++ b/libs/hexagon_nn/2.6/hexagon/src/nn_os_qurt.c
@@ -284,8 +284,9 @@ int nn_os_get_current_thread_priority(int *priority) {
        return 0;
 }
 int nn_os_set_current_thread_priority(int priority) {
-       qurt_thread_t id = qurt_thread_get_id();
-       return qurt_thread_set_priority(id, (unsigned short) priority);
+       //qurt_thread_t id = qurt_thread_get_id();^M
+       //return qurt_thread_set_priority(id, (unsigned short) priority);^M
+       return 0;^M
 }

 /* depending on config, get pcycles or PMU events */
Chengjian-Tang commented 4 years ago

Good to know it works. :)

apivovarov commented 4 years ago

BTW, I looked at Hexagon_SDK docs Hexagon_SDK/3.4.3/docs/Tools_Signing.html - it says:

Unsigned PD limitations

it explains why qurt_thread_set_priority fails/hangs

johnoakley2004 commented 4 years ago

Hi @apivovarov. I am trying to follow your work. I have a MI 9 phone which is rooted using TWRP and Magisk. My problem is getting the adb push commands to work. I can change ro.secure etc. but when I type "adb root" the link goes down and I have to restore the phone. I have tried every trick I can find but can find no clean approach that works. I would be very grateful for any suggestion. Thanks

apivovarov commented 4 years ago

Root is not needed. On non-rooted phone you can write files to /data/local/tmp/ folder. I changed the following path in ${HEXAGON_SDK}/scripts/Common_Walkthrough.py file

print_and_run_cmd('adb wait-for-device shell mount -o remount,rw,exec /data')
...
APPS_DST='/data/local/tmp/vendor/bin'
DSP_DST='/data/local/tmp/vendor/lib/rfsa/adsp/'
LIB_DST='/data/local/tmp/vendor/lib/'
ADSP_LIB_PATH="\"/data/local/tmp/vendor/lib/rfsa/adsp\""
johnoakley2004 commented 4 years ago

Its working now thanks. In case anyone else is following this the steps I took (for rooted device) are:

  1. In the scripts folder, edit device_configuration.py

def get_target_name_using_dev_num(dev_no): //# comment or delete existing code target = "sm8150" return target

def mount_device(device_number, Lparser): LocalParser = Lparser.parse_args() //# cmd1='adb -s '+device_number+' wait-for-device root' //# print_and_run_cmd(cmd1) //# cmd2='adb -s '+device_number+' wait-for-device remount' //# print_and_run_cmd(cmd2) //# if LocalParser.linux_env: cmd3='adb -s '+device_number+' wait-for-device shell su -c mount -o remount,rw,exec / ' print_and_run_cmd(cmd3)

  1. Edit common_walkthrough.py

    APPS_DST='/data/local/tmp/vendor/bin' DSP_DST='/data/local/tmp/vendor/lib/rfsa/adsp/' LIB_DST='/data/local/tmp/vendor/lib/' ADSP_LIB_PATH="\"/data/local/tmp/vendor/lib/rfsa/adsp\""

//# if LocalParser.thirty_two_bit: //# LIB_DST='/vendor/lib/' //# else: //# LIB_DST='/vendor/lib64/'

DSP_LIB_PATH='/data/local/tmp/vendor/lib/rfsa/adsp;'
  1. Edit the calculator_walkthrough.py to comment out the clean commands.

    if not options.no_rebuild: print "---- Build newcalc example for both Android and Hexagon ----" //# print_and_run_cmd(clean_variant) print_and_run_cmd(build_variant) //# print_and_run_cmd(clean_hexagon_variant) print_and_run_cmd(build_hexagon_variant)

  2. In the initial build a directory called androidDebug_aarch64 will be created but the script will fail. The stub file calculator_stub.c should then be edited to include the call for unsigned PD. On the next run of the script this modification should allow the example to run on the target device. There must be a way to tell the build system to inject the necessary code into the calculator_stub.c file but I could not work out how to do this. Any suggestions would be welcome.