diff --git a/CMakeLists.txt b/CMakeLists.txt index 3a20a7920..0ecb21c21 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -35,6 +35,9 @@ option(NVIDIA "Set to ON when building on NVIDIA" OFF) option(WITH_PROTOBUF_DEPENDENCY "Build with PROTOBUF dependency?" ON) option(USE_DEPTH_COMPUTE_OPENSOURCE "Use an open source implementation?" OFF) +##################### Development/Testing Options ############################# +option(TIME_PROFILING "Set to ON for displaying time execution for various core features" OFF) + ################################## Git ######################################## include(FindGit OPTIONAL) if (GIT_FOUND) @@ -96,6 +99,12 @@ if (WITH_NETWORK) add_definitions(-DHAS_NETWORK) endif() +if (TIME_PROFILING) + add_definitions(-DTIME_PROFILING) +else() + remove_definitions(-DTIME_PROFILING) +endif() + set(RESOURCES_DIR "${CMAKE_BINARY_DIR}/resources") make_directory(${RESOURCES_DIR}) diff --git a/sdk/src/cameras/itof-camera/camera_itof.cpp b/sdk/src/cameras/itof-camera/camera_itof.cpp index 74398607d..7b3702459 100644 --- a/sdk/src/cameras/itof-camera/camera_itof.cpp +++ b/sdk/src/cameras/itof-camera/camera_itof.cpp @@ -710,6 +710,12 @@ aditof::Status setAttributesByMode(aditof::Frame &frame, } aditof::Status CameraItof::requestFrame(aditof::Frame *frame) { +#ifdef TIME_PROFILING + using namespace std::chrono; + + steady_clock::time_point rf_t0 = steady_clock::now(); +#endif + using namespace aditof; Status status = Status::OK; ModeInfo::modeInfo aModeInfo; @@ -748,13 +754,21 @@ aditof::Status CameraItof::requestFrame(aditof::Frame *frame) { LOG(WARNING) << "getframe failed to allocated valid frame"; return status; } - +#ifdef TIME_PROFILING + steady_clock::time_point sgf_t0 = steady_clock::now(); +#endif status = m_depthSensor->getFrame(frameDataLocation); +#ifdef TIME_PROFILING + steady_clock::time_point sgf_t1 = steady_clock::now(); +#endif if (status != Status::OK) { LOG(WARNING) << "Failed to get frame from device"; return status; } +#ifdef TIME_PROFILING + steady_clock::time_point cxyz_t0 = steady_clock::now(); +#endif // The incoming sensor frames are already processed. Need to just create XYZ data if (m_xyzEnabled) { uint16_t *depthFrame; @@ -762,11 +776,13 @@ aditof::Status CameraItof::requestFrame(aditof::Frame *frame) { frame->getData("depth", &depthFrame); frame->getData("xyz", &xyzFrame); - Algorithms::ComputeXYZ((const uint16_t *)depthFrame, &m_xyzTable, (int16_t *)xyzFrame, m_details.frameType.height, m_details.frameType.width); } +#ifdef TIME_PROFILING + steady_clock::time_point cxyz_t1 = steady_clock::now(); +#endif Metadata metadata; status = frame->getMetadataStruct(metadata); @@ -807,6 +823,47 @@ aditof::Status CameraItof::requestFrame(aditof::Frame *frame) { memcpy(reinterpret_cast(metadataLocation), reinterpret_cast(&metadata), sizeof(metadata)); +#ifdef TIME_PROFILING + steady_clock::time_point rf_t1 = steady_clock::now(); +#endif + +#ifdef TIME_PROFILING + // Measure execution times, display statistics + auto request_frame_elapsed_time = + std::chrono::duration_cast(rf_t1 - rf_t0); + auto compute_xyz_elapsed_time = + std::chrono::duration_cast(cxyz_t1 - + cxyz_t0); + auto sensor_get_frame_elapsed_time = + std::chrono::duration_cast(sgf_t1 - sgf_t0); + + auto total_profiled_time = + compute_xyz_elapsed_time + sensor_get_frame_elapsed_time; + + std::cout << "CameraItof::requestFrame() took: " + << request_frame_elapsed_time.count() << "us" << std::endl; + std::cout << "|--> DepthSensorInterface::getFrame() took: " + << sensor_get_frame_elapsed_time.count() << "us" + << "(" + << ((double)sensor_get_frame_elapsed_time.count() / + request_frame_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << "|--> Algorithms::computeXYZ() took: " + << compute_xyz_elapsed_time.count() << "us" + << "(" + << ((double)compute_xyz_elapsed_time.count() / + request_frame_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << "Total profiled time: " << total_profiled_time.count() << "us" + << "(" + << ((double)total_profiled_time.count() / + request_frame_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; +#endif + return Status::OK; } diff --git a/sdk/src/connections/target/buffer_processor.cpp b/sdk/src/connections/target/buffer_processor.cpp index 7442f5113..a5fcfea6f 100644 --- a/sdk/src/connections/target/buffer_processor.cpp +++ b/sdk/src/connections/target/buffer_processor.cpp @@ -53,6 +53,10 @@ #include "buffer_processor.h" +#ifdef TIME_PROFILING +#include +#endif + #define CLEAR(x) memset(&(x), 0, sizeof(x)) static int xioctl(int fh, unsigned int request, void *arg) { @@ -208,6 +212,12 @@ aditof::Status BufferProcessor::setProcessorProperties( } aditof::Status BufferProcessor::processBuffer(uint16_t *buffer = nullptr) { +#ifdef TIME_PROFILING + using namespace std::chrono; + + steady_clock::time_point pb_t0 = steady_clock::now(); +#endif + using namespace aditof; struct v4l2_buffer buf[4]; struct VideoDev *dev; @@ -216,8 +226,13 @@ aditof::Status BufferProcessor::processBuffer(uint16_t *buffer = nullptr) { uint8_t *pdata; dev = m_inputVideoDev; uint8_t *pdata_user_space = nullptr; - +#ifdef TIME_PROFILING + steady_clock::time_point wfb_t0 = steady_clock::now(); +#endif status = waitForBufferPrivate(dev); +#ifdef TIME_PROFILING + steady_clock::time_point wfb_t1 = steady_clock::now(); +#endif if (status != Status::OK) { return status; } @@ -232,13 +247,22 @@ aditof::Status BufferProcessor::processBuffer(uint16_t *buffer = nullptr) { return status; } +#ifdef TIME_PROFILING + steady_clock::time_point mc_t0 = steady_clock::now(); +#endif pdata_user_space = (uint8_t *)malloc(sizeof(uint8_t) * buf_data_len); memcpy(pdata_user_space, pdata, buf_data_len); +#ifdef TIME_PROFILING + steady_clock::time_point mc_t1 = steady_clock::now(); +#endif uint16_t *tempDepthFrame = m_tofiComputeContext->p_depth_frame; uint16_t *tempAbFrame = m_tofiComputeContext->p_ab_frame; float *tempConfFrame = m_tofiComputeContext->p_conf_frame; +#ifdef TIME_PROFILING + steady_clock::time_point tc_t0 = steady_clock::now(); +#endif if (buffer != nullptr) { m_tofiComputeContext->p_depth_frame = buffer; m_tofiComputeContext->p_ab_frame = @@ -274,6 +298,9 @@ aditof::Status BufferProcessor::processBuffer(uint16_t *buffer = nullptr) { ::write(m_outputVideoDev->fd, m_processedBuffer, m_outputFrameWidth * m_outputFrameHeight); } +#ifdef TIME_PROFILING + steady_clock::time_point tc_t1 = steady_clock::now(); +#endif m_tofiComputeContext->p_depth_frame = tempDepthFrame; m_tofiComputeContext->p_ab_frame = tempAbFrame; @@ -287,6 +314,58 @@ aditof::Status BufferProcessor::processBuffer(uint16_t *buffer = nullptr) { return status; } +#ifdef TIME_PROFILING + steady_clock::time_point pb_t1 = steady_clock::now(); +#endif + +#ifdef TIME_PROFILING + // Measure execution times, display statistics + auto process_buffer_elapsed_time = + std::chrono::duration_cast(pb_t1 - pb_t0); + auto wait_for_buffer_elapsed_time = + std::chrono::duration_cast(wfb_t1 - wfb_t0); + auto tofi_compute_elapsed_time = + std::chrono::duration_cast(tc_t1 - tc_t0); + auto frame_memcpy_elapsed_time = + std::chrono::duration_cast(mc_t1 - mc_t0); + + auto total_profiled_time = wait_for_buffer_elapsed_time + + tofi_compute_elapsed_time + + frame_memcpy_elapsed_time; + + std::cout << std::endl; + std::cout << "BufferProcessor::processBuffer() took: " + << process_buffer_elapsed_time.count() << "us" << std::endl; + std::cout << "|--> WaitForBuffer() took: " + << wait_for_buffer_elapsed_time.count() << "us" + << "(" + << ((double)wait_for_buffer_elapsed_time.count() / + process_buffer_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << "|--> TofiCompute() took: " + << tofi_compute_elapsed_time.count() << "us" + << "(" + << ((double)tofi_compute_elapsed_time.count() / + process_buffer_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << "|--> Frame memcpy() took: " + << frame_memcpy_elapsed_time.count() << "us" + << "(" + << ((double)frame_memcpy_elapsed_time.count() / + process_buffer_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << "Total profiled time: " << total_profiled_time.count() << "us" + << "(" + << ((double)total_profiled_time.count() / + process_buffer_elapsed_time.count()) * + 100.0 + << "%)" << std::endl; + std::cout << std::endl; +#endif + return status; }