#include "InternalProfiler.h" #include #include #include #define ENABLE_DETAILED_GC_STATS 0 #if ENABLE_INTERNAL_PROFILER namespace { enum { GpuProfilerBlockEachNthFrame = 4 }; mach_timebase_info_data_t timebaseInfo; void ProfilerInit() { mach_timebase_info(&timebaseInfo); } static float MachToMillisecondsDelta(int64_t delta) { // Convert to nanoseconds delta *= timebaseInfo.numer; delta /= timebaseInfo.denom; float result = (float)delta / 1000000.0F; return result; } struct ProfilerBlock { int64_t maxV, minV, avgV; }; void ProfilerBlock_Update(struct ProfilerBlock* b, int64_t d, bool reset, bool avoidZero = false) { if (reset) { b->maxV = b->minV = b->avgV = d; } else { b->maxV = (d > b->maxV) ? d : b->maxV; if (avoidZero && (b->minV == 0 || d == 0)) b->minV = (d > b->minV) ? d : b->minV; else b->minV = (d < b->minV) ? d : b->minV; b->avgV += d; } } ProfilerBlock _framePB; ProfilerBlock _playerPB; ProfilerBlock _batchCountPB; ProfilerBlock _drawCallCountPB; ProfilerBlock _triCountPB; ProfilerBlock _vertCountPB; ProfilerBlock _dynamicBatchDtPB; ProfilerBlock _dynamicBatchCountPB; ProfilerBlock _dynamicBatchedDrawCallCountPB; ProfilerBlock _dynamicBatchedTriCountPB; ProfilerBlock _dynamicBatchedVertCountPB; ProfilerBlock _staticBatchCountPB; ProfilerBlock _staticBatchedDrawCallCountPB; ProfilerBlock _staticBatchedTriCountPB; ProfilerBlock _staticBatchedVertCountPB; ProfilerBlock _fixedBehaviourManagerPB; ProfilerBlock _fixedPhysicsManagerPB; ProfilerBlock _dynamicBehaviourManagerPB; ProfilerBlock _coroutinePB; ProfilerBlock _skinMeshUpdatePB; ProfilerBlock _animationUpdatePB; ProfilerBlock _unityRenderLoopPB; ProfilerBlock _unityCullingPB; ProfilerBlock _unityMSAAResolvePB; ProfilerBlock _fixedUpdateCountPB; ProfilerBlock _GCCountPB; ProfilerBlock _GCDurationPB; int _frameId = 0; // our rendering is dictated by ios display link // frametime will be time between two frame starts // unity player time will be time between frame start/end int64_t _lastFrameStart = -1; int64_t _frameStart = 0; int64_t _frameTime = 0; int64_t _playerTime = 0; int64_t _msaaResolveStart = 0; int64_t _msaaResolve = 0; void* _msaaResolveCounter = 0; UnityFrameStats _unityFrameStats; } extern "C" int64_t UnityScriptingGetUsedSize(); extern "C" int64_t UnityScriptingGetHeapSize(); static void Profiler_SetupScriptingProfile(); void Profiler_InitProfiler() { Profiler_SetupScriptingProfile(); ProfilerInit(); if (_msaaResolveCounter == 0) _msaaResolveCounter = UnityCreateProfilerCounter("iOS.MSAAResolve"); } void Profiler_UninitProfiler() { UnityDestroyProfilerCounter(_msaaResolveCounter); } void Profiler_FrameStart() { _frameStart = mach_absolute_time(); if (_lastFrameStart < 0) { _lastFrameStart = _frameStart; return; } _frameTime = _frameStart - _lastFrameStart; _lastFrameStart = _frameStart; } void Profiler_FrameEnd() { _playerTime = mach_absolute_time() - _frameStart; } void Profiler_FramePresent(const UnityFrameStats* unityFrameStats) { if (!unityFrameStats) return; _unityFrameStats = *unityFrameStats; const int EachNthFrame = 32; if (_frameId == EachNthFrame) { _frameId = 0; ::printf("iPhone Unity internal profiler stats\n"); ::printf("frametime> min: %4.1f max: %4.1f avg: %4.1f\n", MachToMillisecondsDelta(_framePB.minV), MachToMillisecondsDelta(_framePB.maxV), MachToMillisecondsDelta(_framePB.avgV / EachNthFrame)); ::printf("cpu-player> min: %4.1f max: %4.1f avg: %4.1f\n", MachToMillisecondsDelta(_playerPB.minV), MachToMillisecondsDelta(_playerPB.maxV), MachToMillisecondsDelta(_playerPB.avgV / EachNthFrame)); ::printf("batches> min: %3d max: %3d avg: %3d\n", (int)_batchCountPB.minV, (int)_batchCountPB.maxV, (int)(_batchCountPB.avgV / EachNthFrame)); ::printf("draw calls> min: %3d max: %3d avg: %3d\n", (int)_drawCallCountPB.minV, (int)_drawCallCountPB.maxV, (int)(_drawCallCountPB.avgV / EachNthFrame)); ::printf("tris> min: %5d max: %5d avg: %5d\n", (int)_triCountPB.minV, (int)_triCountPB.maxV, (int)(_triCountPB.avgV / EachNthFrame)); ::printf("verts> min: %5d max: %5d avg: %5d\n", (int)_vertCountPB.minV, (int)_vertCountPB.maxV, (int)(_vertCountPB.avgV / EachNthFrame)); ::printf("dynamic batching> batched draw calls: %3d batches: %3d tris: %5d verts: %5d\n", (int)(_dynamicBatchedDrawCallCountPB.avgV / EachNthFrame), (int)(_dynamicBatchCountPB.avgV / EachNthFrame), (int)(_dynamicBatchedTriCountPB.avgV / EachNthFrame), (int)(_dynamicBatchedVertCountPB.avgV / EachNthFrame)); ::printf("static batching> batched draw calls: %3d batches: %3d tris: %5d verts: %5d\n", (int)(_staticBatchedDrawCallCountPB.avgV / EachNthFrame), (int)(_staticBatchCountPB.avgV / EachNthFrame), (int)(_staticBatchedTriCountPB.avgV / EachNthFrame), (int)(_staticBatchedVertCountPB.avgV / EachNthFrame)); ::printf("player-detail> physx: %4.1f animation: %4.1f culling %4.1f skinning: %4.1f batching: %4.1f render: %4.1f fixed-update-count: %d .. %d\n", MachToMillisecondsDelta(_fixedPhysicsManagerPB.avgV / EachNthFrame), MachToMillisecondsDelta(_animationUpdatePB.avgV / EachNthFrame), MachToMillisecondsDelta(_unityCullingPB.avgV / EachNthFrame), MachToMillisecondsDelta(_skinMeshUpdatePB.avgV / EachNthFrame), MachToMillisecondsDelta(_dynamicBatchDtPB.avgV / EachNthFrame), MachToMillisecondsDelta((_unityRenderLoopPB.avgV - _dynamicBatchDtPB.avgV - _unityCullingPB.avgV) / EachNthFrame), (int)_fixedUpdateCountPB.minV, (int)_fixedUpdateCountPB.maxV); ::printf("scripting-scripts> update: %4.1f fixedUpdate: %4.1f coroutines: %4.1f \n", MachToMillisecondsDelta(_dynamicBehaviourManagerPB.avgV / EachNthFrame), MachToMillisecondsDelta(_fixedBehaviourManagerPB.avgV / EachNthFrame), MachToMillisecondsDelta(_coroutinePB.avgV / EachNthFrame)); #if UNITY_DEVELOPER_BUILD ::printf("scripting-memory> used heap: %lld allocated heap: %lld max number of collections: %d collection total duration: %4.1f\n", UnityScriptingGetUsedSize(), UnityScriptingGetHeapSize(), (int)_GCCountPB.avgV, MachToMillisecondsDelta(_GCDurationPB.avgV)); #else ::printf("scripting-memory> information not available on non-development player configuration\n"); #endif ::printf("----------------------------------------\n"); } ProfilerBlock_Update(&_framePB, _frameTime, (_frameId == 0)); ProfilerBlock_Update(&_playerPB, _playerTime, (_frameId == 0)); ProfilerBlock_Update(&_batchCountPB, _unityFrameStats.batchCount, (_frameId == 0)); ProfilerBlock_Update(&_drawCallCountPB, _unityFrameStats.drawCallCount, (_frameId == 0)); ProfilerBlock_Update(&_triCountPB, _unityFrameStats.triCount, (_frameId == 0)); ProfilerBlock_Update(&_vertCountPB, _unityFrameStats.vertCount, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBatchDtPB, _unityFrameStats.dynamicBatchDt, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBatchCountPB, _unityFrameStats.dynamicBatchCount, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBatchedDrawCallCountPB, _unityFrameStats.dynamicBatchedDrawCallCount, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBatchedTriCountPB, _unityFrameStats.dynamicBatchedTris, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBatchedVertCountPB, _unityFrameStats.dynamicBatchedVerts, (_frameId == 0)); ProfilerBlock_Update(&_staticBatchCountPB, _unityFrameStats.staticBatchCount, (_frameId == 0)); ProfilerBlock_Update(&_staticBatchedDrawCallCountPB, _unityFrameStats.staticBatchedDrawCallCount, (_frameId == 0)); ProfilerBlock_Update(&_staticBatchedTriCountPB, _unityFrameStats.staticBatchedTris, (_frameId == 0)); ProfilerBlock_Update(&_staticBatchedVertCountPB, _unityFrameStats.staticBatchedVerts, (_frameId == 0)); ProfilerBlock_Update(&_fixedBehaviourManagerPB, _unityFrameStats.fixedBehaviourManagerDt, (_frameId == 0)); ProfilerBlock_Update(&_fixedPhysicsManagerPB, _unityFrameStats.fixedPhysicsManagerDt, (_frameId == 0)); ProfilerBlock_Update(&_dynamicBehaviourManagerPB, _unityFrameStats.dynamicBehaviourManagerDt, (_frameId == 0)); ProfilerBlock_Update(&_coroutinePB, _unityFrameStats.coroutineDt, (_frameId == 0)); ProfilerBlock_Update(&_skinMeshUpdatePB, _unityFrameStats.skinMeshUpdateDt, (_frameId == 0)); ProfilerBlock_Update(&_animationUpdatePB, _unityFrameStats.animationUpdateDt, (_frameId == 0)); ProfilerBlock_Update(&_unityRenderLoopPB, _unityFrameStats.renderDt, (_frameId == 0)); ProfilerBlock_Update(&_unityCullingPB, _unityFrameStats.cullingDt, (_frameId == 0)); ProfilerBlock_Update(&_unityMSAAResolvePB, _msaaResolve, (_frameId == 0)); ProfilerBlock_Update(&_fixedUpdateCountPB, _unityFrameStats.fixedUpdateCount, (_frameId == 0)); ProfilerBlock_Update(&_GCCountPB, 0, (_frameId == 0)); ProfilerBlock_Update(&_GCDurationPB, 0, (_frameId == 0)); _msaaResolve = 0; ++_frameId; } void Profiler_StartMSAAResolve() { UnityStartProfilerCounter(_msaaResolveCounter); _msaaResolveStart = mach_absolute_time(); } void Profiler_EndMSAAResolve() { _msaaResolve += (mach_absolute_time() - _msaaResolveStart); UnityEndProfilerCounter(_msaaResolveCounter); } // // scriptint memory profiling // extern "C" { enum ScriptingGCEvent { SCRIPTING_GC_EVENT_START, SCRIPTING_GC_EVENT_MARK_START, SCRIPTING_GC_EVENT_MARK_END, SCRIPTING_GC_EVENT_RECLAIM_START, SCRIPTING_GC_EVENT_RECLAIM_END, SCRIPTING_GC_EVENT_END, SCRIPTING_GC_EVENT_PRE_STOP_WORLD, SCRIPTING_GC_EVENT_POST_STOP_WORLD, SCRIPTING_GC_EVENT_PRE_START_WORLD, SCRIPTING_GC_EVENT_POST_START_WORLD }; enum ScriptingProfileFlags { SCRIPTING_PROFILE_NONE = 0, SCRIPTING_PROFILE_APPDOMAIN_EVENTS = 1 << 0, SCRIPTING_PROFILE_ASSEMBLY_EVENTS = 1 << 1, SCRIPTING_PROFILE_MODULE_EVENTS = 1 << 2, SCRIPTING_PROFILE_CLASS_EVENTS = 1 << 3, SCRIPTING_PROFILE_JIT_COMPILATION = 1 << 4, SCRIPTING_PROFILE_INLINING = 1 << 5, SCRIPTING_PROFILE_EXCEPTIONS = 1 << 6, SCRIPTING_PROFILE_ALLOCATIONS = 1 << 7, SCRIPTING_PROFILE_GC = 1 << 8, SCRIPTING_PROFILE_THREADS = 1 << 9, SCRIPTING_PROFILE_REMOTING = 1 << 10, SCRIPTING_PROFILE_TRANSITIONS = 1 << 11, SCRIPTING_PROFILE_ENTER_LEAVE = 1 << 12, SCRIPTING_PROFILE_COVERAGE = 1 << 13, SCRIPTING_PROFILE_INS_COVERAGE = 1 << 14, SCRIPTING_PROFILE_STATISTICAL = 1 << 15, SCRIPTING_PROFILE_METHOD_EVENTS = 1 << 16, SCRIPTING_PROFILE_MONITOR_EVENTS = 1 << 17, SCRIPTING_PROFILE_IOMAP_EVENTS = 1 << 18, /* this should likely be removed, too */ SCRIPTING_PROFILE_GC_MOVES = 1 << 19, }; struct MemoryProfiler { int64_t gc_total_time; int64_t gc_mark_time; int64_t gc_reclaim_time; int64_t gc_stop_world_time; int64_t gc_start_world_time; }; typedef void (*UnityScriptingProfileFunc)(void* /*MemoryProfiler*/ prof); typedef void (*UnityScriptingProfileGCFunc)(void* /*MemoryProfiler*/ prof, int event, int generation); typedef void (*UnityScriptingProfileGCResizeFunc)(void* /*MemoryProfiler*/ prof, int64_t new_size); void UnityScriptingProfilerInstall(void* /*MemoryProfiler*/ prof, UnityScriptingProfileFunc shutdown_callback); void UnityScriptingProfilerInstallGC(UnityScriptingProfileGCFunc callback, UnityScriptingProfileGCResizeFunc heap_resize_callback); void UnityScriptingProfilerSetEvents(int /*ScriptingProfileFlags*/ events); } static MemoryProfiler _MemoryProfiler; static void gc_event(void* profiler_, int event, int generation) { MemoryProfiler* profiler = (MemoryProfiler*)profiler_; switch (event) { case SCRIPTING_GC_EVENT_START: profiler->gc_total_time = mach_absolute_time(); break; case SCRIPTING_GC_EVENT_END: { profiler->gc_total_time = mach_absolute_time() - profiler->gc_total_time; float delta = profiler->gc_total_time; ProfilerBlock_Update(&_GCDurationPB, delta, false); ProfilerBlock_Update(&_GCCountPB, 1, false); break; } case SCRIPTING_GC_EVENT_MARK_START: profiler->gc_mark_time = mach_absolute_time(); break; case SCRIPTING_GC_EVENT_MARK_END: profiler->gc_mark_time = mach_absolute_time() - profiler->gc_mark_time; break; case SCRIPTING_GC_EVENT_RECLAIM_START: profiler->gc_reclaim_time = mach_absolute_time(); break; case SCRIPTING_GC_EVENT_RECLAIM_END: profiler->gc_reclaim_time = mach_absolute_time() - profiler->gc_reclaim_time; break; case SCRIPTING_GC_EVENT_PRE_STOP_WORLD: profiler->gc_stop_world_time = mach_absolute_time(); break; case SCRIPTING_GC_EVENT_POST_STOP_WORLD: profiler->gc_stop_world_time = mach_absolute_time() - profiler->gc_stop_world_time; break; case SCRIPTING_GC_EVENT_PRE_START_WORLD: profiler->gc_start_world_time = mach_absolute_time(); break; case SCRIPTING_GC_EVENT_POST_START_WORLD: profiler->gc_start_world_time = mach_absolute_time() - profiler->gc_start_world_time; break; default: break; } #if ENABLE_DETAILED_GC_STATS if (event == SCRIPTING_GC_EVENT_END) { ::printf("scripting-gc> stop time: %4.1f mark time: %4.1f reclaim time: %4.1f start time: %4.1f total time: %4.1f \n", MachToMillisecondsDelta(profiler->gc_stop_world_time), MachToMillisecondsDelta(profiler->gc_mark_time), MachToMillisecondsDelta(profiler->gc_reclaim_time), MachToMillisecondsDelta(profiler->gc_start_world_time), MachToMillisecondsDelta(profiler->gc_total_time) ); } #endif } static void gc_resize(void* profiler, int64_t new_size) { } static void profiler_shutdown(void* profiler) { } static void Profiler_SetupScriptingProfile() { UnityScriptingProfilerInstall(&_MemoryProfiler, &profiler_shutdown); UnityScriptingProfilerInstallGC(&gc_event, &gc_resize); UnityScriptingProfilerSetEvents(SCRIPTING_PROFILE_GC); } #endif // ENABLE_INTERNAL_PROFILER