1 /*---------------------------------------------------------------------------*
2   Project:  NintendoWare
3   File:     dev_Profile.cpp
4 
5   Copyright (C)2009-2010 Nintendo Co., Ltd./HAL Laboratory, Inc.  All rights reserved.
6 
7   These coded instructions, statements, and computer programs contain
8   proprietary information of Nintendo of America Inc. and/or Nintendo
9   Company Ltd., and are protected by Federal copyright law.  They may
10   not be disclosed to third parties or copied or duplicated in any form,
11   in whole or in part, without the prior written consent of Nintendo.
12 
13   $Revision: 22001 $
14  *---------------------------------------------------------------------------*/
15 
16 #include <nw/dev/dev_Profile.h>
17 #include <nw/ut/ut_Inlines.h>
18 #include <nw/dev/dev_Utility.h>
19 
20 #ifdef NW_PLATFORM_CTR
21 //#define PERFORMANCE_COUNTER_ENABLED
22 #endif
23 
24 #ifdef PERFORMANCE_COUNTER_ENABLED
25 #include <nn/os.h>
26 #include <nn/dbg/dbg_PerformanceCounterSelect.h>
27 #endif
28 
29 #ifndef NW_PLATFORM_CTR
30 #include <Windows.h>
31 #endif
32 
33 #ifdef NW_DEV_ENABLED
34 
35 namespace nw
36 {
37 namespace dev
38 {
39 
40 ProfileCenter* ProfileCenter::m_Instance = NULL;
41 
42 //----------------------------------------
43 ProfileManager*
CreateProfileManager(ProfileManager::Description & description,os::IAllocator * allocator)44 ProfileManager::CreateProfileManager(
45     ProfileManager::Description& description,
46     os::IAllocator* allocator)
47 {
48     ut::MoveArray<Report> reports(description.maxReport, allocator);
49     void* managerMemory = allocator->Alloc(sizeof(ProfileManager));
50 
51     ProfileManager* profileManager = new(managerMemory) ProfileManager(allocator, description, reports);
52 
53     return profileManager;
54 }
55 
56 //----------------------------------------
57 void
Destroy(os::IAllocator * allocator)58 ProfileManager::Destroy(os::IAllocator* allocator)
59 {
60     this->~ProfileManager();
61     allocator->Free( this );
62 }
63 
64 //----------------------------------------
ProfileManager(os::IAllocator * allocator,const ProfileManager::Description & description,ut::MoveArray<Report> reports)65 ProfileManager::ProfileManager(
66     os::IAllocator* allocator,
67     const ProfileManager::Description& description,
68     ut::MoveArray<Report> reports)
69     : m_Description(description),
70       m_Reports(reports)
71 {
72     NW_UNUSED_VARIABLE(allocator);
73 }
74 
75 //----------------------------------------
~ProfileManager()76 ProfileManager::~ProfileManager()
77 {
78 }
79 
80 //----------------------------------------
81 bool
AddReport(const Report & report)82 ProfileManager::AddReport(const Report& report)
83 {
84     return this->m_Reports.push_back(report);
85 }
86 
87 //----------------------------------------
88 bool
StoreReport(const Report & report)89 ProfileManager::StoreReport(const Report& report)
90 {
91     ReportRange range = this->GetReports();
92 
93     // 同一の名前が設定されたレポートを1つにまとめながら集計する。
94     for(ReportArray::iterator it = range.first; it != range.second; ++it)
95     {
96         if (::std::strcmp(it->name, report.name) == 0)
97         {
98             it->callCount += report.callCount;
99             it->elapsedTime += report.elapsedTime;
100 
101             it->iCacheMiss += report.iCacheMiss;
102             it->dCacheReadMiss += report.dCacheReadMiss;
103             it->dCacheWriteMiss += report.dCacheWriteMiss;
104 
105             if (it->maxElapsedTime < report.maxElapsedTime)
106             {
107                 it->maxElapsedTime = report.maxElapsedTime;
108             }
109 
110             if (it->minElapsedTime > report.minElapsedTime)
111             {
112                 it->minElapsedTime = report.minElapsedTime;
113             }
114 
115             return true;
116         }
117     }
118 
119     return this->m_Reports.push_back(report);
120 }
121 
122 //----------------------------------------
123 void
ClearReports()124 ProfileManager::ClearReports()
125 {
126     m_Reports.clear();
127 }
128 
129 //----------------------------------------
130 void
DumpReports()131 ProfileManager::DumpReports()
132 {
133     NW_DEV_LOG("\n");
134 
135     float accuracy = 0.0f;
136     const int MAX_LENGTH = 256;
137     switch (this->m_Description.accuracy)
138     {
139         case MILI_SECOND:
140         {
141             accuracy = 1000000.0f;
142             NW_DEV_LOG("Time: [ms]\n");
143         }
144         break;
145         case MICRO_SECOND:
146         {
147             accuracy = 1000.0f;
148             NW_DEV_LOG("Time: [us]\n");
149         }
150         break;
151         default:
152         {
153             NW_FATAL_ERROR("Unsupported accuracy.");
154         }
155         break;
156     }
157 
158     char caption[MAX_LENGTH];
159     caption[0] = '\0';
160     if (ut::CheckFlag(m_Description.mode, ProfileManager::TIMER))
161     {
162         char* str = "|    total| call|average|average%%|    max|    min|";
163         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
164     }
165 
166 #ifdef PERFORMANCE_COUNTER_ENABLED
167     if (ut::CheckFlag(m_Description.mode, ProfileManager::I_CACHE_MISS))
168     {
169         char* str = "IMiss|";
170         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
171     }
172 
173     if (ut::CheckFlag(m_Description.mode, ProfileManager::D_CACHE_READ_MISS))
174     {
175         char* str = "DRMiss|";
176         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
177     }
178 
179     if (ut::CheckFlag(m_Description.mode, ProfileManager::D_CACHE_WRITE_MISS))
180     {
181         char* str = "DWMiss|";
182         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
183     }
184 #endif
185 
186     if (this->m_Description.exportFormat == CSV)
187     {
188         std::replace(caption, caption + std::strlen(caption), '|', ',');
189         char* str = "name,\n";
190         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
191     }
192     else
193     {
194         char* str = "name|h\n";
195         ut::strncat(caption, MAX_LENGTH, str, std::strlen(str) + 1);
196     }
197 
198     // caption 出力
199     NW_DEV_LOG(caption);
200 
201     ProfileManager::ReportRange range = this->GetReports();
202     for(ReportArray::iterator it = range.first; it != range.second; ++it)
203     {
204         float elapsedTime = TickToTime(it->elapsedTime, accuracy);
205         float maxElapsedTime = TickToTime(it->maxElapsedTime, accuracy);
206         float minElapsedTime = TickToTime(it->minElapsedTime, accuracy);
207         float averageTime = elapsedTime / static_cast<float>(it->callCount);
208         float frame = 10.0f / 60.0f;
209         u64   iCacheMiss = (it->iCacheMiss / it->callCount);
210         u64   dCacheReadMiss = (it->dCacheReadMiss / it->callCount);
211         u64   dCacheWriteMiss = (it->dCacheWriteMiss / it->callCount);
212 
213         char formatString[MAX_LENGTH];
214         formatString[0] = '\0';
215         char output[256];
216         output[0] = '\0';
217         if (ut::CheckFlag(m_Description.mode, ProfileManager::TIMER))
218         {
219             char* format = "|%9.3f|%5d|%7.3f|   %5.2f|%7.3f|%7.3f|";
220             ut::snprintf(formatString, MAX_LENGTH, MAX_LENGTH - 1, format,
221                 elapsedTime,
222                 it->callCount,
223                 averageTime, averageTime / frame,
224                 maxElapsedTime,
225                 minElapsedTime);
226             ut::strncat(output, MAX_LENGTH, formatString, std::strlen(formatString) + 1);
227         }
228 
229 #ifdef PERFORMANCE_COUNTER_ENABLED
230         if (ut::CheckFlag(m_Description.mode, ProfileManager::I_CACHE_MISS))
231         {
232             char* format = "%5llu|";
233             ut::snprintf(formatString, MAX_LENGTH, MAX_LENGTH - 1, format, iCacheMiss);
234             ut::strncat(output, MAX_LENGTH, formatString, std::strlen(formatString) + 1);
235         }
236 
237         if (ut::CheckFlag(m_Description.mode, ProfileManager::D_CACHE_READ_MISS))
238         {
239             char* format = "%6llu|";
240             ut::snprintf(formatString, MAX_LENGTH, MAX_LENGTH - 1, format, dCacheReadMiss);
241             ut::strncat(output, MAX_LENGTH, formatString, std::strlen(formatString) + 1);
242         }
243 
244         if (ut::CheckFlag(m_Description.mode, ProfileManager::D_CACHE_WRITE_MISS))
245         {
246             char* format = "%6llu|";
247             ut::snprintf(formatString, MAX_LENGTH, MAX_LENGTH - 1, format, dCacheWriteMiss);
248             ut::strncat(output, MAX_LENGTH, formatString, std::strlen(formatString) + 1);
249         }
250 #endif
251 
252         ut::strncat(output, MAX_LENGTH, it->name, std::strlen(it->name) + 1);
253         char* str = "|\n";
254         ut::strncat(output, MAX_LENGTH, str, std::strlen(str) + 1);
255 
256         if (this->m_Description.exportFormat == CSV)
257         {
258             std::replace(output, output + std::strlen(output), '|', ',');
259         }
260 
261         NW_DEV_LOG(output);
262     }
263 }
264 
265 //----------------------------------------
AutoProfile(const char * name,ProfileManager * profileManager)266 AutoProfile::AutoProfile(const char* name, ProfileManager* profileManager)
267 : m_ProfileManager(profileManager),
268   m_Time(0),
269   m_ICacheMiss(0),
270   m_DCacheReadMiss(0),
271   m_DCacheWriteMiss(0)
272 {
273     m_Report.name = name;
274 
275 #ifdef PERFORMANCE_COUNTER_ENABLED
276     const nn::dbg::MPCore::PerformanceCounterName CORE_0 =
277         nn::dbg::MPCore::PERFORMANCE_COUNTER_NAME_CORE_0;
278     const nn::dbg::MPCore::PerformanceCounterName CORE_1 =
279         nn::dbg::MPCore::PERFORMANCE_COUNTER_NAME_CORE_1;
280     const nn::dbg::MPCore::PerformanceCounterEvent INST_CACHE_MISS =
281         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_INST_CACHE_MISS;
282     const nn::dbg::MPCore::PerformanceCounterEvent DATA_CACHE_READ_MISS =
283         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_DATA_CACHE_READ_MISS;
284     const nn::dbg::MPCore::PerformanceCounterEvent DATA_CACHE_WRITE_MISS =
285         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_DATA_CACHE_WRITE_MISS;
286 
287     if (ut::CheckFlag(profileManager->GetDescription().mode, ProfileManager::I_CACHE_MISS))
288     {
289         nn::dbg::MPCore::SetPMCEvent(CORE_0, INST_CACHE_MISS);
290         m_ICacheMiss = nn::dbg::MPCore::GetPMCValue(CORE_0);
291 
292         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_READ_MISS))
293         {
294             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_READ_MISS);
295             m_DCacheReadMiss = nn::dbg::MPCore::GetPMCValue(CORE_1);
296         }
297         else if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_WRITE_MISS))
298         {
299             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_WRITE_MISS);
300             m_DCacheWriteMiss = nn::dbg::MPCore::GetPMCValue(CORE_1);
301         }
302     }
303     else
304     {
305         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_READ_MISS))
306         {
307             nn::dbg::MPCore::SetPMCEvent(CORE_0, DATA_CACHE_READ_MISS);
308             m_DCacheReadMiss = nn::dbg::MPCore::GetPMCValue(CORE_0);
309         }
310 
311         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_WRITE_MISS))
312         {
313             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_WRITE_MISS);
314             m_DCacheWriteMiss = nn::dbg::MPCore::GetPMCValue(CORE_1);
315         }
316     }
317 #endif
318 
319     m_Time = this->GetTime();
320 }
321 
322 //----------------------------------------
~AutoProfile()323 AutoProfile::~AutoProfile()
324 {
325     m_Time = this->GetTime() - m_Time;
326 
327 #ifdef PERFORMANCE_COUNTER_ENABLED
328     const nn::dbg::MPCore::PerformanceCounterName CORE_0 =
329         nn::dbg::MPCore::PERFORMANCE_COUNTER_NAME_CORE_0;
330     const nn::dbg::MPCore::PerformanceCounterName CORE_1 =
331         nn::dbg::MPCore::PERFORMANCE_COUNTER_NAME_CORE_1;
332     const nn::dbg::MPCore::PerformanceCounterEvent INST_CACHE_MISS =
333         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_INST_CACHE_MISS;
334     const nn::dbg::MPCore::PerformanceCounterEvent DATA_CACHE_READ_MISS =
335         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_DATA_CACHE_READ_MISS;
336     const nn::dbg::MPCore::PerformanceCounterEvent DATA_CACHE_WRITE_MISS =
337         nn::dbg::MPCore::PERFORMANCE_COUNTER_EVENT_CORE_DATA_CACHE_WRITE_MISS;
338 
339     if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::I_CACHE_MISS))
340     {
341         nn::dbg::MPCore::SetPMCEvent(CORE_0, INST_CACHE_MISS);
342         m_ICacheMiss = nn::dbg::MPCore::GetPMCValue(CORE_0) - m_ICacheMiss;
343         m_Report.iCacheMiss = m_ICacheMiss;
344 
345         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_READ_MISS))
346         {
347             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_READ_MISS);
348             m_DCacheReadMiss = nn::dbg::MPCore::GetPMCValue(CORE_1) - m_DCacheReadMiss;
349             m_Report.dCacheReadMiss = m_DCacheReadMiss;
350         }
351         else if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_WRITE_MISS))
352         {
353             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_WRITE_MISS);
354             m_DCacheWriteMiss = nn::dbg::MPCore::GetPMCValue(CORE_1) - m_DCacheWriteMiss;
355             m_Report.dCacheWriteMiss = m_DCacheWriteMiss;
356         }
357     }
358     else
359     {
360         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_READ_MISS))
361         {
362             nn::dbg::MPCore::SetPMCEvent(CORE_0, DATA_CACHE_READ_MISS);
363             m_DCacheReadMiss = nn::dbg::MPCore::GetPMCValue(CORE_0) - m_DCacheReadMiss;
364             m_Report.dCacheReadMiss = m_DCacheReadMiss;
365         }
366 
367         if (ut::CheckFlag(this->m_ProfileManager->GetDescription().mode, ProfileManager::D_CACHE_WRITE_MISS))
368         {
369             nn::dbg::MPCore::SetPMCEvent(CORE_1, DATA_CACHE_WRITE_MISS);
370             m_DCacheWriteMiss = nn::dbg::MPCore::GetPMCValue(CORE_1) - m_DCacheWriteMiss;
371             m_Report.dCacheWriteMiss = m_DCacheWriteMiss;
372         }
373     }
374 #endif
375 
376     m_Report.elapsedTime = m_Time;
377     m_Report.callCount = 1;
378     m_Report.maxElapsedTime = m_Time;
379     m_Report.minElapsedTime = m_Time;
380 
381     m_ProfileManager->StoreReport(m_Report);
382 }
383 
384 //----------------------------------------
385 s64
GetTime()386 AutoProfile::GetTime()
387 {
388 #ifdef NW_PLATFORM_CTR
389     return static_cast<s64>(nn::os::Tick::GetSystemCurrent());
390 #else
391     timeBeginPeriod(1);
392     return timeGetTime() * 1000000;
393     timeEndPeriod(1);
394 #endif
395 }
396 
397 //----------------------------------------
398 void
Initialize(int maxReport,os::IAllocator * allocator)399 ProfileCenter::Initialize(int maxReport, os::IAllocator* allocator)
400 {
401     NW_ASSERT(m_Instance == NULL);
402 
403 #ifdef PERFORMANCE_COUNTER_ENABLED
404     // プログラムカウンタ初期化
405     nn::dbg::MPCore::AcquirePMCControl();
406 #endif
407 
408     ProfileManager::Description description;
409     description.maxReport = maxReport;
410     description.exportFormat = ProfileManager::CHART;
411     description.accuracy = ProfileManager::MILI_SECOND;
412     description.mode = ProfileManager::TIMER | ProfileManager::I_CACHE_MISS | ProfileManager::D_CACHE_READ_MISS;
413     ProfileManager* profileManager = ProfileManager::CreateProfileManager(description, (allocator));
414     void* memory = allocator->Alloc(sizeof(ProfileCenter));
415     NW_NULL_ASSERT(memory);
416     m_Instance = new(memory) ProfileCenter();
417     ProfileCenter::SetProfileManager(profileManager);
418 }
419 
420 //----------------------------------------
421 void
Finalize(os::IAllocator * allocator)422 ProfileCenter::Finalize(os::IAllocator* allocator)
423 {
424     ProfileManager* profileManager = ProfileCenter::GetProfileManager();
425     if (profileManager)
426     {
427         profileManager->Destroy(allocator);
428         ProfileCenter::SetProfileManager(NULL);
429     }
430 
431     os::SafeFree(m_Instance, allocator);
432 
433 #ifdef PERFORMANCE_COUNTER_ENABLED
434     // プログラムカウンタ解放
435     nn::dbg::MPCore::ReleasePMCControl();
436 #endif
437 }
438 
439 } // namespace nw::dev
440 } // namespace nw
441 #endif
442