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