[MS]use SummaryCollector, print too much profiling failed to register error log.

| name       | about	                             | labels   |
| ---------- | ------------------------------------- | -------- |
| Bug Report | Use this template for reporting a bug | kind/bug |

<!--  Thanks for sending an issue!  Here are some tips for you:

1) If this is your first time, please read our contributor guidelines: https://gitee.com/mindspore/mindspore/blob/master/CONTRIBUTING.md

2) If you want to get the answer quickly, please add label `mindspore-assistant`
to the issue, we will find it and answer you as soon as possible.
-->

## Environment
- **Hardware Environment(`Ascend`/`GPU`/`CPU`)**: 
> Uncomment only one ` /device <>` line, hit enter to put that in a new line, and remove leading whitespaces from that line:
>
> /device ascend

- **Software Environment**:
-- MindSpore version (source or binary): r1.1 2020/12/28 commit_id = "[sha1]:65ba639d,[branch]:(HEAD->r1.1,origin/r1.1)"
-- Python version (e.g., Python 3.7.5): Python 3.7.5
-- OS platform and distribution (e.g., Linux Ubuntu 16.04): Euler 2.0(SP8)
-- GCC/Compiler version (if compiled from source):

## Related testcase
test_ms_run_psenet_ms_mi_davinci_distributed

## Steps to reproduce the issue
1. model_zoo psenet script
2. use SummaryCollector collect data.
3. execute train.

## Describe the current behavior
print too much profiling failed to register error log.

## Describe the expected behavior
control print times

## Related log / screenshot
[ERROR] DEVICE ... [mindspore/ccsrc/runtime/device/ascend/profiling/profiling_manager.cc:252] RegProfSetDeviceCallback] Pass MsprofSetDeviceCallback to runtime failed!
[ERROR] PROFILING ... [toolchain/profiler/collector/dvvp/msprofiler/src/msprof_callback_handler.cpp:131] >>> (tid:137613) Failed to register device state callback
[ERROR] RUNTIME ... runtime/feature/src/runtime.cc:582]137650 Init:halGetDeviceInfo(INFO_TYPE_VERSION) failed: drvRetCode=4
[ERROR] RUNTIME ... runtime/feature/inc/api.hpp:297]137650 Instance:Runtime::Instance == nullptr
[ERROR] RUNTIME ... runtime/feature/src/api_c.cc:1550]137650 rtRegDeviceStateCallback:api is NULL!
[ERROR] RUNTIME ... runtime/feature/src/api_c.cc:1550]137650 rtRegDeviceStateCallback:ErrCode=507000, desc=[null api pointer], InnerCode=0x70c0001
...

## Special notes for this issue
在model_zoo的psenet中加入summarycollector执行多P训练，打印太多ERROR日志, 但训练结果正常

报错：
```
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.383.567 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is SparseApplyAdagrad, outindex is 1, in_index is 1
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.407.002 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedMulApplyMomentumExtern, outindex is 0, in_index is 0
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.407.027 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedMulApplyMomentumExtern, outindex is 1, in_index is 6
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.407.039 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedMulApplyMomentumExtern, outindex is 2, in_index is 1
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.418.141 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is ScatterMax, outindex is 0, in_index is 0
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.418.823 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is ScatterMin, outindex is 0, in_index is 0
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.419.540 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is ScatterSub, outindex is 0, in_index is 0
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.420.300 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is ScatterMul, outindex is 0, in_index is 0
[INFO] KERNEL(142760,python):2020-12-29-18:59:23.421.027 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is ScatterDiv, outindex is 0, in_index is 0
[EVENT] TDT(138984,None):2020-12-29-18:59:23.486.694 [../../../../../../tdt/common/src/log.cpp:148]CurrentMemoryStatus: session=1 TX{Num=0 Size=0 SendNum=58 RecvNum=58} RX{Num=58 Size=1035468800 SendNum=58 RecvNum=0},[../../../../../../tdt/common/common_inc/memory_usage.h:183:ReportToLog]139150
[EVENT] TDT(138984,None):2020-12-29-18:59:23.486.743 [../../../../../../tdt/common/src/log.cpp:148]"HostSendPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 57, freeNum: 6}, {blockSize: 20480K, totalNum: 34, freeNum: 9}, {blockSize: 38912K, totalNum: 34, freeNum: 8}" "HostRecvPool: {blockSize: 3072K, totalNum: 1, freeNum: 1}" "DeviceRecvPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 37, freeNum: 8}, {blockSize: 20480K, totalNum: 15, freeNum: 0}, {blockSize: 38912K, totalNum: 14, freeNum: 0}" "HostCtrlPool: {SendPool: 128, FreePool: 128}, {RecvPool: 1, FreePool: 1}",[../../../../../../tdt/common/src/memory_pool.cpp:689:GetHostPoolStatus]139150
[INFO] COMMON(138984,python):2020-12-29-18:59:23.731.454 [mindspore/ccsrc/common/duplex_pipe.cc:65] Open] [DuplexPipe] Local process, id: 138984, 21/20
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.911.874 [../../../../../../runtime/feature/src/runtime.cc:582]142891 Init:halGetDeviceInfo(INFO_TYPE_VERSION) failed: drvRetCode=4
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.911.984 [../../../../../../runtime/feature/inc/api.hpp:297]142891 Instance:Runtime::Instance == nullptr
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.911.997 [../../../../../../runtime/feature/src/api_c.cc:108]142891 rtDevBinaryRegister:api is NULL!
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.912.017 [../../../../../../runtime/feature/src/api_c.cc:108]142891 rtDevBinaryRegister:ErrCode=507000, desc=[null api pointer], InnerCode=0x70c0001
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.912.090 [../../../../../../runtime/feature/src/runtime.cc:582]142891 Init:halGetDeviceInfo(INFO_TYPE_VERSION) failed: drvRetCode=4
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.912.102 [../../../../../../runtime/feature/inc/api.hpp:297]142891 Instance:Runtime::Instance == nullptr
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.912.110 [../../../../../../runtime/feature/src/api_c.cc:163]142891 rtFunctionRegister:api is NULL!
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.912.131 [../../../../../../runtime/feature/src/api_c.cc:163]142891 rtFunctionRegister:ErrCode=507000, desc=[null api pointer], InnerCode=0x70c0001
[EVENT] PROFILING(142891,None):2020-12-29-18:59:23.937.613 [../../../../../../../../toolchain/profiler/collector/dvvp/msprofiler/src/msprof_callback_handler.cpp:121] >>> (tid:142891) Started to register profiling callbacks to ge
[INFO] DEVICE(142891,python):2020-12-29-18:59:23.953.406 [mindspore/ccsrc/runtime/device/ascend/profiling/profiling_manager.cc:301] DoRegiste] VM profiling register start
[EVENT] PROFILING(142891,None):2020-12-29-18:59:23.953.441 [../../../../../../../../toolchain/profiler/collector/dvvp/msprofiler/src/msprof_callback_handler.cpp:121] >>> (tid:142891) Started to register profiling callbacks to ge
[INFO] DEVICE(142891,python):2020-12-29-18:59:23.953.470 [mindspore/ccsrc/runtime/device/ascend/profiling/profiling_manager.cc:236] RegProfCtrlCallback] GE register Msprof ctrl callback.
[INFO] DEVICE(142891,python):2020-12-29-18:59:23.953.482 [mindspore/ccsrc/runtime/device/ascend/profiling/profiling_manager.cc:249] RegProfSetDeviceCallback] GE pass setdevice callback to runtime.
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.955.957 [../../../../../../runtime/feature/src/runtime.cc:582]142891 Init:halGetDeviceInfo(INFO_TYPE_VERSION) failed: drvRetCode=4
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.955.981 [../../../../../../runtime/feature/inc/api.hpp:297]142891 Instance:Runtime::Instance == nullptr
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.955.991 [../../../../../../runtime/feature/src/api_c.cc:1550]142891 rtRegDeviceStateCallback:api is NULL!
[ERROR] RUNTIME(142891,None):2020-12-29-18:59:23.956.007 [../../../../../../runtime/feature/src/api_c.cc:1550]142891 rtRegDeviceStateCallback:ErrCode=507000, desc=[null api pointer], InnerCode=0x70c0001
[ERROR] DEVICE(142891,python):2020-12-29-18:59:23.956.024 [mindspore/ccsrc/runtime/device/ascend/profiling/profiling_manager.cc:252] RegProfSetDeviceCallback] Pass MsprofSetDeviceCallback to runtime failed!
[ERROR] PROFILING(142891,None):2020-12-29-18:59:23.956.033 [../../../../../../../../toolchain/profiler/collector/dvvp/msprofiler/src/msprof_callback_handler.cpp:131] >>> (tid:142891) Failed to register device state callback
[EVENT] TDT(138984,None):2020-12-29-18:59:24.486.864 [../../../../../../tdt/common/src/log.cpp:148]CurrentMemoryStatus: session=1 TX{Num=0 Size=0 SendNum=58 RecvNum=58} RX{Num=58 Size=1035468800 SendNum=58 RecvNum=0},[../../../../../../tdt/common/common_inc/memory_usage.h:183:ReportToLog]139150
[EVENT] TDT(138984,None):2020-12-29-18:59:24.486.950 [../../../../../../tdt/common/src/log.cpp:148]"HostSendPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 57, freeNum: 6}, {blockSize: 20480K, totalNum: 34, freeNum: 9}, {blockSize: 38912K, totalNum: 34, freeNum: 8}" "HostRecvPool: {blockSize: 3072K, totalNum: 1, freeNum: 1}" "DeviceRecvPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 37, freeNum: 8}, {blockSize: 20480K, totalNum: 15, freeNum: 0}, {blockSize: 38912K, totalNum: 14, freeNum: 0}" "HostCtrlPool: {SendPool: 128, FreePool: 128}, {RecvPool: 1, FreePool: 1}",[../../../../../../tdt/common/src/memory_pool.cpp:689:GetHostPoolStatus]139150
[EVENT] TDT(138984,None):2020-12-29-18:59:25.487.069 [../../../../../../tdt/common/src/log.cpp:148]CurrentMemoryStatus: session=1 TX{Num=0 Size=0 SendNum=58 RecvNum=58} RX{Num=58 Size=1035468800 SendNum=58 RecvNum=0},[../../../../../../tdt/common/common_inc/memory_usage.h:183:ReportToLog]139150
[EVENT] TDT(138984,None):2020-12-29-18:59:25.487.141 [../../../../../../tdt/common/src/log.cpp:148]"HostSendPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 57, freeNum: 6}, {blockSize: 20480K, totalNum: 34, freeNum: 9}, {blockSize: 38912K, totalNum: 34, freeNum: 8}" "HostRecvPool: {blockSize: 3072K, totalNum: 1, freeNum: 1}" "DeviceRecvPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 37, freeNum: 8}, {blockSize: 20480K, totalNum: 15, freeNum: 0}, {blockSize: 38912K, totalNum: 14, freeNum: 0}" "HostCtrlPool: {SendPool: 128, FreePool: 128}, {RecvPool: 1, FreePool: 1}",[../../../../../../tdt/common/src/memory_pool.cpp:689:GetHostPoolStatus]139150
[WARNING] ME(142891:281472881575376,MainProcess):2020-12-29-18:59:25.954.411 [mindspore/_check_version.py:207] call drvMngGetConsoleLogLevel failed , g_conLogLevel = 3
[INFO] PARALLEL(142891,python):2020-12-29-18:59:25.991.313 [mindspore/ccsrc/frontend/parallel/costmodel_context.cc:30] GetInstance] Create costmodel_context
[INFO] CORE(142891,python):2020-12-29-18:59:26.061.851 [mindspore/core/utils/ms_context.h:193] set_param<std::basic_string<char> >] ms set context device target:Ascend
[INFO] CORE(142891,python):2020-12-29-18:59:26.437.724 [mindspore/core/utils/ms_context.cc:95] set_backend_policy] ms set context backend policy:ms
[EVENT] TDT(138984,None):2020-12-29-18:59:26.487.248 [../../../../../../tdt/common/src/log.cpp:148]CurrentMemoryStatus: session=1 TX{Num=0 Size=0 SendNum=58 RecvNum=58} RX{Num=58 Size=1035468800 SendNum=58 RecvNum=0},[../../../../../../tdt/common/common_inc/memory_usage.h:183:ReportToLog]139150
[EVENT] TDT(138984,None):2020-12-29-18:59:26.487.298 [../../../../../../tdt/common/src/log.cpp:148]"HostSendPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 57, freeNum: 6}, {blockSize: 20480K, totalNum: 34, freeNum: 9}, {blockSize: 38912K, totalNum: 34, freeNum: 8}" "HostRecvPool: {blockSize: 3072K, totalNum: 1, freeNum: 1}" "DeviceRecvPool: {blockSize: 3072K, totalNum: 3, freeNum: 3}, {blockSize: 8192K, totalNum: 37, freeNum: 8}, {blockSize: 20480K, totalNum: 15, freeNum: 0}, {blockSize: 38912K, totalNum: 14, freeNum: 0}" "HostCtrlPool: {SendPool: 128, FreePool: 128}, {RecvPool: 1, FreePool: 1}",[../../../../../../tdt/common/src/memory_pool.cpp:689:GetHostPoolStatus]139150
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.749.827 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseAdam, outindex is 0, in_index is 0
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.749.870 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseAdam, outindex is 1, in_index is 1
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.749.883 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseAdam, outindex is 2, in_index is 2
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.750.645 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseLazyAdam, outindex is 0, in_index is 0
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.750.666 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseLazyAdam, outindex is 1, in_index is 1
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.750.678 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseLazyAdam, outindex is 2, in_index is 2
[INFO] KERNEL(142891,python):2020-12-29-18:59:26.751.365 [mindspore/ccsrc/backend/kernel_compiler/oplib/oplib.cc:379] GetRefInfo] add ref info, op name is FusedSparseFtrl, outindex is 0, in_index is 0

```

当前的128进程分析结论未复现：

```
(base) root@:alexnet# ps -ef|grep train_ogc | grep -v grep | awk '{print $2}' | xargs pstree
python─┬─python
       ├─python───python─┬─python
       │                 ├─python───128*[python───2*[{python}]]
       │                 └─5*[{python}]
       ├─python─┬─24*[python]
       │        └─5*[{python}]
       └─90*[{python}]
(base) root@:alexnet# tail -f mylog
epoch: 904 step: 1, loss is 1.5014355
epoch: 904 step: 2, loss is 1.5478022
epoch: 904 step: 3, loss is 1.785194
epoch time: 145.843 ms, per step time: 48.614 ms
epoch: 905 step: 1, loss is 1.5883512
epoch: 905 step: 2, loss is 1.7525071
epoch: 905 step: 3, loss is 1.6275258
epoch time: 108.552 ms, per step time: 36.184 ms
epoch: 906 step: 1, loss is 1.4160761
epoch: 906 step: 2, loss is 1.6879337
epoch: 906 step: 3, loss is 1.6158795
epoch time: 124.474 ms, per step time: 41.491 ms
epoch: 907 step: 1, loss is 1.4601058
epoch: 907 step: 2, loss is 1.7791272
epoch: 907 step: 3, loss is 1.3602922
epoch time: 124.928 ms, per step time: 41.643 ms
epoch: 908 step: 1, loss is 1.4701203
epoch: 908 step: 2, loss is 1.5954804
epoch: 908 step: 3, loss is 1.7635355
epoch time: 105.127 ms, per step time: 35.042 ms
epoch: 909 step: 1, loss is 1.7355163
epoch: 909 step: 2, loss is 1.7351396
epoch: 909 step: 3, loss is 1.8397739
epoch time: 138.650 ms, per step time: 46.217 ms
epoch: 910 step: 1, loss is 1.4778489
epoch: 910 step: 2, loss is 1.4933219
epoch: 910 step: 3, loss is 1.6927963
epoch time: 109.852 ms, per step time: 36.617 ms
epoch: 911 step: 1, loss is 1.9412262
epoch: 911 step: 2, loss is 1.6837018
epoch: 911 step: 3, loss is 1.7390918
epoch time: 117.101 ms, per step time: 39.034 ms
epoch: 912 step: 1, loss is 1.6386685
epoch: 912 step: 2, loss is 1.3268372
epoch: 912 step: 3, loss is 1.7714311
epoch time: 132.841 ms, per step time: 44.280 ms
epoch: 913 step: 1, loss is 1.6427679
epoch: 913 step: 2, loss is 1.880758
^C
(base) root@:alexnet# grep ERRROR mylog
(base) root@:alexnet# tail -f /var/log/message | grep "current manager_context_num"
tail: cannot open '/var/log/message' for reading: No such file or directory
tail: no files remaining
(base) root@:alexnet# lsof /dev/davinci_manager | wc -l
767

```
使用repo地址：https://repo.mindspore.cn/mindspore/mindspore/version/202012/20201230/r1.1_20201230174118_ec987fb4229f6e5e994b77657cb788736970ac72/
对应hisi run包地址：http://10.90.67.50/productrepo/HiAI/HISI_C76/20201229

当前128个进程限制的定位结论未复现。强行设置summary的进程数为128后，device总的进程达到767，但未出现ERROR

GVP MindSpore/mindspore

内容风险标识

评论 (11)

GVPMindSpore/mindspore

内容风险标识