Skip to content

Commit 3e15460

Browse files
atobiszeiatobiszei
authoredNov 29, 2023
Ad OpenVINO calls tracing (#2175)
Tracing show with --log_level TRACE and build with -c dbg. * renaming createSharedTensor - naming was not changed earlier on but implementation changed * minor refactoring
·
v2025.0v2023.3
1 parent 1bf04db commit 3e15460

17 files changed

+157
-45
lines changed
 

‎ci/cppclean.sh

+1-1
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,7 @@ fi
5454
if [ ${NO_WARNINGS_TEST_NOTUSED} -gt 0 ]; then
5555
errors+="Failed probably due to unnecessary forward includes: ${NO_WARNINGS_TEST_NOTUSED}"$'\n'
5656
fi
57-
if [ ${NO_WARNINGS} -gt 157 ]; then
57+
if [ ${NO_WARNINGS} -gt 159 ]; then
5858
errors+="Failed due to higher than allowed number of issues in code: ${NO_WARNINGS}"$'\n'
5959
fi
6060
if [ ${NO_WARNINGS_TEST} -gt 57 ]; then

‎src/dags/entry_node.cpp

+1-1
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,7 @@ Status EntryNode<RequestType>::createShardedTensor(ov::Tensor& dividedTensor, Pr
104104
(precision == Precision::I8) ||
105105
(precision == Precision::U8) ||
106106
(precision == Precision::I16)) {
107-
dividedTensor = createSharedTensor(ovmsPrecisionToIE2Precision(precision), shape, (void*)((char*)(tensor.data()) + i * step));
107+
dividedTensor = createTensorWithNoDataOwnership(ovmsPrecisionToIE2Precision(precision), shape, (void*)((char*)(tensor.data()) + i * step));
108108
} else {
109109
return Node::createShardedTensor(dividedTensor, precision, shape, tensor, i, step, metadata, tensorName);
110110
}

‎src/dags/node.cpp

+1-1
Original file line numberDiff line numberDiff line change
@@ -269,7 +269,7 @@ Status Node::demultiplyOutputs(SessionResults& nodeSessionOutputs) {
269269
}
270270

271271
Status Node::createShardedTensor(ov::Tensor& dividedTensor, Precision precision, const shape_t& shape, const ov::Tensor& tensor, size_t i, size_t step, const NodeSessionMetadata& metadata, const std::string tensorName) {
272-
dividedTensor = createSharedTensor(tensor.get_element_type(), shape, (char*)(tensor.data()) + i * step);
272+
dividedTensor = createTensorWithNoDataOwnership(tensor.get_element_type(), shape, (char*)(tensor.data()) + i * step);
273273
return StatusCode::OK;
274274
}
275275
} // namespace ovms

‎src/deserialization.cpp

+17-1
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616
#include "deserialization.hpp"
1717

1818
#include "capi_frontend/buffer.hpp"
19+
#include "logging.hpp"
1920

2021
namespace ovms {
2122

@@ -24,6 +25,7 @@ Status InputSink<ov::InferRequest&>::give(const std::string& name, ov::Tensor& t
2425
OVMS_PROFILE_FUNCTION();
2526
Status status;
2627
try {
28+
OV_LOGGER("ov::InferRequest: {}, request.set_tensor({}, tensor)", reinterpret_cast<void*>(&requester), name, reinterpret_cast<void*>(&tensor));
2729
requester.set_tensor(name, tensor);
2830
// OV implementation the ov::Exception is not
2931
// a base class for all other exceptions thrown from OV.
@@ -43,56 +45,70 @@ Status InputSink<ov::InferRequest&>::give(const std::string& name, ov::Tensor& t
4345
ov::Tensor makeTensor(const InferenceTensor& requestInput,
4446
const std::shared_ptr<const TensorInfo>& tensorInfo) {
4547
OVMS_PROFILE_FUNCTION();
48+
OV_LOGGER("ov::Shape()");
4649
ov::Shape shape;
4750
for (const auto& dim : requestInput.getShape()) {
51+
OV_LOGGER("ov::Shape::push_back({})", dim);
4852
shape.push_back(dim);
4953
}
5054
ov::element::Type_t precision = tensorInfo->getOvPrecision();
5155
if (!requestInput.getBuffer()->getByteSize()) {
56+
OV_LOGGER("ov::Tensor({}, shape)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
5257
return ov::Tensor(precision, shape);
5358
}
59+
OV_LOGGER("ov::Tensor({}, shape, data)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
5460
return ov::Tensor(precision, shape, const_cast<void*>(reinterpret_cast<const void*>(requestInput.getBuffer()->data())));
5561
}
5662

5763
ov::Tensor makeTensor(const tensorflow::TensorProto& requestInput,
5864
const std::shared_ptr<const TensorInfo>& tensorInfo) {
5965
OVMS_PROFILE_FUNCTION();
66+
OV_LOGGER("ov::Shape()");
6067
ov::Shape shape;
6168
for (int i = 0; i < requestInput.tensor_shape().dim_size(); i++) {
69+
OV_LOGGER("ov::Shape::push_back(dim)");
6270
shape.push_back(requestInput.tensor_shape().dim(i).size());
6371
}
6472
ov::element::Type_t precision = tensorInfo->getOvPrecision();
6573
if (!requestInput.tensor_content().size()) {
74+
OV_LOGGER("ov::Tensor({}, shape)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
6675
return ov::Tensor(precision, shape);
6776
}
77+
OV_LOGGER("ov::Tensor({}, shape, data)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
6878
return ov::Tensor(precision, shape, const_cast<void*>(reinterpret_cast<const void*>(requestInput.tensor_content().data())));
6979
}
7080

7181
ov::Tensor makeTensor(const ::KFSRequest::InferInputTensor& requestInput,
7282
const std::shared_ptr<const TensorInfo>& tensorInfo,
7383
const std::string& buffer) {
7484
OVMS_PROFILE_FUNCTION();
85+
OV_LOGGER("ov::Shape()");
7586
ov::Shape shape;
7687
for (int i = 0; i < requestInput.shape_size(); i++) {
88+
OV_LOGGER("ov::Shape::push_back({})", requestInput.shape().at(i));
7789
shape.push_back(requestInput.shape().at(i));
7890
}
7991
ov::element::Type precision = tensorInfo->getOvPrecision();
8092
if (!buffer.size()) {
93+
OV_LOGGER("ov::Tensor({}, shape)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
8194
return ov::Tensor(precision, shape);
8295
}
96+
OV_LOGGER("ov::Tensor({}, shape, data)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
8397
return ov::Tensor(precision, shape, const_cast<void*>(reinterpret_cast<const void*>(buffer.data())));
8498
}
8599
ov::Tensor makeTensor(const ::KFSRequest::InferInputTensor& requestInput,
86100
const std::shared_ptr<const TensorInfo>& tensorInfo) {
87101
OVMS_PROFILE_FUNCTION();
102+
OV_LOGGER("ov::Shape()");
88103
ov::Shape shape;
89104
for (int i = 0; i < requestInput.shape_size(); i++) {
105+
OV_LOGGER("ov::Shape::push_back({})", requestInput.shape().at(i));
90106
shape.push_back(requestInput.shape().at(i));
91107
}
92108

93109
ov::element::Type precision = tensorInfo->getOvPrecision();
110+
OV_LOGGER("ov::Tensor({}, shape)", toString(ovms::ovElementTypeToOvmsPrecision(precision)));
94111
ov::Tensor tensor(precision, shape);
95112
return tensor;
96113
}
97-
98114
} // namespace ovms

‎src/deserialization.hpp

+5
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
#include "capi_frontend/inferencerequest.hpp"
3232
#include "capi_frontend/inferencetensor.hpp"
3333
#include "kfs_frontend/kfs_utils.hpp"
34+
#include "logging.hpp"
3435
#include "profiler.hpp"
3536
#include "status.hpp"
3637
#include "tensor_conversion.hpp"
@@ -218,6 +219,7 @@ class ConcreteTensorProtoDeserializator {
218219
case ovms::Precision::Q78:
219220
case ovms::Precision::BIN:
220221
default:
222+
OV_LOGGER("ov::Tensor()");
221223
return ov::Tensor();
222224
}
223225
}
@@ -250,6 +252,7 @@ class ConcreteTensorProtoDeserializator {
250252
case ovms::Precision::Q78:
251253
case ovms::Precision::BIN:
252254
default:
255+
OV_LOGGER("ov::Tensor()");
253256
return ov::Tensor();
254257
}
255258
}
@@ -268,8 +271,10 @@ class ConcreteTensorProtoDeserializator {
268271
return makeTensor(requestInput, tensorInfo);
269272
}
270273
case ovms::Precision::FP16: {
274+
OV_LOGGER("ov::Shape()");
271275
ov::Shape shape;
272276
for (std::int64_t i = 0; i < requestInput.tensor_shape().dim_size(); i++) {
277+
OV_LOGGER("ov::Shape::push_back({})", requestInput.tensor_shape().dim(i).size());
273278
shape.push_back(requestInput.tensor_shape().dim(i).size());
274279
}
275280
ov::Tensor tensor(ov::element::f16, shape);

‎src/logging.cpp

+12
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,9 @@ std::shared_ptr<spdlog::logger> capi_logger = std::make_shared<spdlog::logger>("
3232
#if (MEDIAPIPE_DISABLE == 0)
3333
std::shared_ptr<spdlog::logger> mediapipe_logger = std::make_shared<spdlog::logger>("mediapipe");
3434
#endif
35+
#if COMPILATION_MODE == dbg
36+
std::shared_ptr<spdlog::logger> ov_logger = std::make_shared<spdlog::logger>("openvino");
37+
#endif
3538
const std::string default_pattern = "[%Y-%m-%d %T.%e][%t][%n][%l][%s:%#] %v";
3639

3740
static void set_log_level(const std::string log_level, std::shared_ptr<spdlog::logger> logger) {
@@ -65,6 +68,9 @@ static void register_loggers(const std::string& log_level, std::vector<spdlog::s
6568
capi_logger->set_pattern(default_pattern);
6669
#if (MEDIAPIPE_DISABLE == 0)
6770
mediapipe_logger->set_pattern(default_pattern);
71+
#endif
72+
#if COMPILATION_MODE == dbg
73+
ov_logger->set_pattern(default_pattern);
6874
#endif
6975
for (auto& sink : sinks) {
7076
gcs_logger->sinks().push_back(sink);
@@ -76,6 +82,9 @@ static void register_loggers(const std::string& log_level, std::vector<spdlog::s
7682
capi_logger->sinks().push_back(sink);
7783
#if (MEDIAPIPE_DISABLE == 0)
7884
mediapipe_logger->sinks().push_back(sink);
85+
#endif
86+
#if COMPILATION_MODE == dbg
87+
ov_logger->sinks().push_back(sink);
7988
#endif
8089
}
8190
set_log_level(log_level, serving_logger);
@@ -88,6 +97,9 @@ static void register_loggers(const std::string& log_level, std::vector<spdlog::s
8897
set_log_level(log_level, capi_logger);
8998
#if (MEDIAPIPE_DISABLE == 0)
9099
set_log_level(log_level, mediapipe_logger);
100+
#endif
101+
#if COMPILATION_MODE == dbg
102+
set_log_level(log_level, ov_logger);
91103
#endif
92104
spdlog::set_default_logger(serving_logger);
93105
}

‎src/logging.hpp

+8-1
Original file line numberDiff line numberDiff line change
@@ -31,9 +31,16 @@ extern std::shared_ptr<spdlog::logger> modelmanager_logger;
3131
extern std::shared_ptr<spdlog::logger> dag_executor_logger;
3232
extern std::shared_ptr<spdlog::logger> sequence_manager_logger;
3333
extern std::shared_ptr<spdlog::logger> capi_logger;
34-
#if (MEDIAPIPE_DISABLE == 0)
34+
#if (MEDIAPIPE_DISABLE != 0)
3535
extern std::shared_ptr<spdlog::logger> mediapipe_logger;
3636
#endif
37+
#if COMPILATION_MODE == dbg
38+
extern std::shared_ptr<spdlog::logger> ov_logger;
39+
#define OV_LOGGER(...) SPDLOG_LOGGER_TRACE(ov_logger, __VA_ARGS__)
40+
#else
41+
#define OV_LOGGER(...)
42+
#endif
43+
3744
void configure_logger(const std::string& log_level, const std::string& log_path);
3845

3946
} // namespace ovms

0 commit comments

Comments
 (0)
Please sign in to comment.