Skip to content

Commit 6d51024

Browse files
zzdanowiczCompute-Runtime-Automation
zzdanowicz
authored and
Compute-Runtime-Automation
committed
Improve ioctl statistics
Related-To: NEO-5845 Signed-off-by: Zbigniew Zdanowicz <[email protected]>
1 parent c6ee706 commit 6d51024

File tree

3 files changed

+101
-43
lines changed

3 files changed

+101
-43
lines changed

‎opencl/test/unit_test/linux/main_linux_dll.cpp‎

Lines changed: 71 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@
3030
#include "os_inc.h"
3131

3232
#include <string>
33+
#include <string_view>
3334

3435
namespace Os {
3536
extern const char *dxcoreDllName;
@@ -199,6 +200,9 @@ TEST_F(DrmSimpleTests, givenPrintIoctlTimesWhenCallIoctlThenStatisticsAreGathere
199200
};
200201
::testing::internal::CaptureStdout();
201202

203+
constexpr long long initialMin = std::numeric_limits<long long>::max();
204+
constexpr long long initialMax = 0;
205+
202206
auto executionEnvironment = std::make_unique<ExecutionEnvironment>();
203207
executionEnvironment->prepareRootDeviceEnvironments(1);
204208
auto drm = static_cast<DrmMock *>(DrmWrap::createDrm(*executionEnvironment->rootDeviceEnvironments[0]).release());
@@ -212,70 +216,109 @@ TEST_F(DrmSimpleTests, givenPrintIoctlTimesWhenCallIoctlThenStatisticsAreGathere
212216
uint32_t contextId = 1u;
213217

214218
drm->getEuTotal(euTotal);
215-
EXPECT_EQ(drm->ioctlStatistics.size(), 1u);
219+
EXPECT_EQ(1u, drm->ioctlStatistics.size());
216220

217221
drm->getEuTotal(euTotal);
218-
EXPECT_EQ(drm->ioctlStatistics.size(), 1u);
222+
EXPECT_EQ(1u, drm->ioctlStatistics.size());
219223

220224
drm->setLowPriorityContextParam(contextId);
221-
EXPECT_EQ(drm->ioctlStatistics.size(), 2u);
225+
EXPECT_EQ(2u, drm->ioctlStatistics.size());
222226

223227
auto euTotalData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GETPARAM);
224228
ASSERT_TRUE(euTotalData != drm->ioctlStatistics.end());
225-
EXPECT_EQ(euTotalData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM));
226-
EXPECT_EQ(euTotalData->second.second, 2u);
227-
EXPECT_NE(euTotalData->second.first, 0);
228-
auto firstTime = euTotalData->second.first;
229+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM), euTotalData->first);
230+
EXPECT_EQ(2u, euTotalData->second.count);
231+
EXPECT_NE(0, euTotalData->second.totalTime);
232+
EXPECT_NE(initialMin, euTotalData->second.minTime);
233+
EXPECT_NE(initialMax, euTotalData->second.minTime);
234+
EXPECT_NE(initialMin, euTotalData->second.maxTime);
235+
EXPECT_NE(initialMax, euTotalData->second.maxTime);
236+
auto firstTime = euTotalData->second.totalTime;
229237

230238
auto lowPriorityData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM);
231239
ASSERT_TRUE(lowPriorityData != drm->ioctlStatistics.end());
232-
EXPECT_EQ(lowPriorityData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM));
233-
EXPECT_EQ(lowPriorityData->second.second, 1u);
234-
EXPECT_NE(lowPriorityData->second.first, 0);
240+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM), lowPriorityData->first);
241+
EXPECT_EQ(1u, lowPriorityData->second.count);
242+
EXPECT_NE(0, lowPriorityData->second.totalTime);
243+
EXPECT_NE(initialMin, lowPriorityData->second.minTime);
244+
EXPECT_NE(initialMax, lowPriorityData->second.minTime);
245+
EXPECT_NE(initialMin, lowPriorityData->second.maxTime);
246+
EXPECT_NE(initialMax, lowPriorityData->second.maxTime);
235247

236248
drm->getEuTotal(euTotal);
237249
EXPECT_EQ(drm->ioctlStatistics.size(), 2u);
238250

239251
euTotalData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GETPARAM);
240252
ASSERT_TRUE(euTotalData != drm->ioctlStatistics.end());
241-
EXPECT_EQ(euTotalData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM));
242-
EXPECT_EQ(euTotalData->second.second, 3u);
243-
EXPECT_NE(euTotalData->second.first, 0);
253+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM), euTotalData->first);
254+
EXPECT_EQ(3u, euTotalData->second.count);
255+
EXPECT_NE(0u, euTotalData->second.totalTime);
244256

245-
auto secondTime = euTotalData->second.first;
257+
auto secondTime = euTotalData->second.totalTime;
246258
EXPECT_GT(secondTime, firstTime);
247259

248260
lowPriorityData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM);
249261
ASSERT_TRUE(lowPriorityData != drm->ioctlStatistics.end());
250-
EXPECT_EQ(lowPriorityData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM));
251-
EXPECT_EQ(lowPriorityData->second.second, 1u);
252-
EXPECT_NE(lowPriorityData->second.first, 0);
262+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM), lowPriorityData->first);
263+
EXPECT_EQ(1u, lowPriorityData->second.count);
264+
EXPECT_NE(0, lowPriorityData->second.totalTime);
253265

254266
drm->destroyDrmContext(contextId);
255-
EXPECT_EQ(drm->ioctlStatistics.size(), 3u);
267+
EXPECT_EQ(3u, drm->ioctlStatistics.size());
256268

257269
euTotalData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GETPARAM);
258270
ASSERT_TRUE(euTotalData != drm->ioctlStatistics.end());
259-
EXPECT_EQ(euTotalData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM));
260-
EXPECT_EQ(euTotalData->second.second, 3u);
261-
EXPECT_NE(euTotalData->second.first, 0);
271+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GETPARAM), euTotalData->first);
272+
EXPECT_EQ(3u, euTotalData->second.count);
273+
EXPECT_NE(0, euTotalData->second.totalTime);
262274

263275
lowPriorityData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM);
264276
ASSERT_TRUE(lowPriorityData != drm->ioctlStatistics.end());
265-
EXPECT_EQ(lowPriorityData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM));
266-
EXPECT_EQ(lowPriorityData->second.second, 1u);
267-
EXPECT_NE(lowPriorityData->second.first, 0);
277+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_SETPARAM), lowPriorityData->first);
278+
EXPECT_EQ(1u, lowPriorityData->second.count);
279+
EXPECT_NE(0, lowPriorityData->second.totalTime);
268280

269281
auto destroyData = drm->ioctlStatistics.find(DRM_IOCTL_I915_GEM_CONTEXT_DESTROY);
270282
ASSERT_TRUE(destroyData != drm->ioctlStatistics.end());
271-
EXPECT_EQ(destroyData->first, static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_DESTROY));
272-
EXPECT_EQ(destroyData->second.second, 1u);
273-
EXPECT_NE(destroyData->second.first, 0);
283+
EXPECT_EQ(static_cast<unsigned long>(DRM_IOCTL_I915_GEM_CONTEXT_DESTROY), destroyData->first);
284+
EXPECT_EQ(1u, destroyData->second.count);
285+
EXPECT_NE(0, destroyData->second.totalTime);
274286

275287
delete drm;
276288

277289
std::string output = ::testing::internal::GetCapturedStdout();
278-
EXPECT_STRNE(output.c_str(), "");
290+
EXPECT_STRNE("", output.c_str());
291+
292+
std::string_view requestString("Request");
293+
std::string_view totalTimeString("Total time(ns)");
294+
std::string_view countString("Count");
295+
std::string_view avgTimeString("Avg time per ioctl");
296+
std::string_view minString("Min");
297+
std::string_view maxString("Max");
298+
299+
std::size_t position = output.find(requestString);
300+
EXPECT_NE(std::string::npos, position);
301+
position += requestString.size();
302+
303+
position = output.find(totalTimeString, position);
304+
EXPECT_NE(std::string::npos, position);
305+
position += totalTimeString.size();
306+
307+
position = output.find(countString, position);
308+
EXPECT_NE(std::string::npos, position);
309+
position += countString.size();
310+
311+
position = output.find(avgTimeString, position);
312+
EXPECT_NE(std::string::npos, position);
313+
position += avgTimeString.size();
314+
315+
position = output.find(minString, position);
316+
EXPECT_NE(std::string::npos, position);
317+
position += minString.size();
318+
319+
position = output.find(maxString, position);
320+
EXPECT_NE(std::string::npos, position);
321+
position += maxString.size();
279322
}
280323

281324
TEST_F(DrmSimpleTests, GivenSelectedNonExistingDeviceWhenOpenDirFailsThenRetryOpeningRenderDevicesAndNoDevicesAreCreated) {

‎shared/source/os_interface/linux/drm_neo.cpp‎

Lines changed: 22 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -202,39 +202,41 @@ int Drm::ioctl(unsigned long request, void *arg) {
202202
std::chrono::steady_clock::time_point start;
203203
std::chrono::steady_clock::time_point end;
204204

205-
if (measureTime) {
206-
start = std::chrono::steady_clock::now();
207-
}
208-
209205
auto printIoctl = DebugManager.flags.PrintIoctlEntries.get();
210206

211207
if (printIoctl) {
212208
printf("IOCTL %s called\n", IoctlHelper::getIoctlString(request).c_str());
213209
}
214210

211+
if (measureTime) {
212+
start = std::chrono::steady_clock::now();
213+
}
215214
ret = SysCalls::ioctl(getFileDescriptor(), request, arg);
216215

217216
returnedErrno = errno;
218217

219-
if (printIoctl) {
220-
printf("IOCTL %s returns %d, errno %d(%s)\n", IoctlHelper::getIoctlString(request).c_str(), ret, returnedErrno, strerror(returnedErrno));
221-
}
222-
223218
if (measureTime) {
224219
end = std::chrono::steady_clock::now();
225-
auto elapsedTime = std::chrono::duration_cast<std::chrono::nanoseconds>(end - start).count();
220+
long long elapsedTime = std::chrono::duration_cast<std::chrono::nanoseconds>(end - start).count();
226221

227-
std::pair<long long, uint64_t> ioctlData{};
222+
IoctlStatisticsEntry ioctlData{};
228223
auto ioctlDataIt = this->ioctlStatistics.find(request);
229224
if (ioctlDataIt != this->ioctlStatistics.end()) {
230225
ioctlData = ioctlDataIt->second;
231226
}
232227

233-
ioctlData.first += elapsedTime;
234-
ioctlData.second++;
228+
ioctlData.totalTime += elapsedTime;
229+
ioctlData.count++;
230+
ioctlData.minTime = std::min(ioctlData.minTime, elapsedTime);
231+
ioctlData.maxTime = std::max(ioctlData.maxTime, elapsedTime);
235232

236233
this->ioctlStatistics[request] = ioctlData;
237234
}
235+
236+
if (printIoctl) {
237+
printf("IOCTL %s returns %d, errno %d(%s)\n", IoctlHelper::getIoctlString(request).c_str(), ret, returnedErrno, strerror(returnedErrno));
238+
}
239+
238240
} while (ret == -1 && (returnedErrno == EINTR || returnedErrno == EAGAIN || returnedErrno == EBUSY));
239241
SYSTEM_LEAVE(request);
240242
return ret;
@@ -599,9 +601,15 @@ void Drm::printIoctlStatistics() {
599601
}
600602

601603
printf("\n--- Ioctls statistics ---\n");
602-
printf("%40s %15s %10s %20s", "Request", "Total time(ns)", "Count", "Avg time per ioctl\n");
604+
printf("%41s %15s %10s %20s %20s %20s", "Request", "Total time(ns)", "Count", "Avg time per ioctl", "Min", "Max\n");
603605
for (const auto &ioctlData : this->ioctlStatistics) {
604-
printf("%40s %15llu %10lu %20f\n", IoctlHelper::getIoctlString(ioctlData.first).c_str(), ioctlData.second.first, static_cast<unsigned long>(ioctlData.second.second), ioctlData.second.first / static_cast<double>(ioctlData.second.second));
606+
printf("%41s %15llu %10lu %20f %20lld %20lld\n",
607+
IoctlHelper::getIoctlString(ioctlData.first).c_str(),
608+
ioctlData.second.totalTime,
609+
static_cast<unsigned long>(ioctlData.second.count),
610+
ioctlData.second.totalTime / static_cast<double>(ioctlData.second.count),
611+
ioctlData.second.minTime,
612+
ioctlData.second.maxTime);
605613
}
606614
printf("\n");
607615
}

‎shared/source/os_interface/linux/drm_neo.h‎

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@
2626
#include <array>
2727
#include <cerrno>
2828
#include <fcntl.h>
29+
#include <limits>
2930
#include <memory>
3031
#include <mutex>
3132
#include <string>
@@ -275,7 +276,13 @@ class Drm : public DriverModel {
275276
ADAPTER_BDF adapterBDF{};
276277

277278
TopologyMap topologyMap;
278-
std::unordered_map<unsigned long, std::pair<long long, uint64_t>> ioctlStatistics;
279+
struct IoctlStatisticsEntry {
280+
long long totalTime = 0;
281+
uint64_t count = 0;
282+
long long minTime = std::numeric_limits<long long>::max();
283+
long long maxTime = 0;
284+
};
285+
std::unordered_map<unsigned long, IoctlStatisticsEntry> ioctlStatistics;
279286

280287
std::mutex bindFenceMutex;
281288
std::array<uint64_t, EngineLimits::maxHandleCount> pagingFence;

0 commit comments

Comments
 (0)