Closed Bug 596725 Opened 14 years ago Closed 10 years ago

Profiling tools for IPC messages

Categories

(Core :: IPC, defect)

defect
Not set
normal

Tracking

()

RESOLVED INVALID

People

(Reporter: azakai, Assigned: azakai)

Details

Attachments

(2 files, 3 obsolete files)

Attached file Python profiling script (obsolete) —
Some tools for profiling IPC messages can be useful. The attached python script lists messages by number and latency.
Example output: === By total messages === PContentChild|Msg_GetCharPref [SYNC/RPC] latency: 0.0006 total: 386.000000 PContentChild|Msg_GetIntPref [SYNC/RPC] latency: 0.0026 total: 254.000000 PContentChild|Msg_GetBoolPref [SYNC/RPC] latency: 0.0027 total: 245.000000 PBrowserChild|Msg_AsyncMessage latency: 0.0040 total: 77.000000 PBrowserChild|Msg_NotifyStateChange latency: 0.0032 total: 57.000000 PBrowserChild|Msg_NotifyStatusChange latency: 0.0017 total: 46.000000 PHttpChannelParent|Msg_OnStatus latency: 0.0730 total: 41.000000 PNeckoChild|Msg_HTMLDNSPrefetch latency: 0.0002 total: 39.000000 PContentChild|Msg_StartVisitedQuery latency: 0.0001 total: 33.000000 PContentChild|Msg_TestPermission [SYNC/RPC] latency: 0.0012 total: 32.000000 PHttpChannelParent|Msg_OnDataAvailable latency: 0.0830 total: 30.000000 PBrowserChild|Msg_NotifyProgressChange latency: 0.0021 total: 30.000000 PHttpChannelParent|Msg_OnProgress latency: 0.0799 total: 29.000000 PBrowserParent|Msg_AsyncMessage latency: 0.2114 total: 13.000000 PDocumentRendererNativeIDChild|Msg___delete__ latency: 0.0010 total: 9.000000 PBrowserParent|Msg_PDocumentRendererNativeIDConstructor latency: 0.0868 total: 9.000000 PBrowserParent|Msg_LoadRemoteScript latency: 0.2392 total: 7.000000 PCookieServiceChild|Msg_GetCookieString [SYNC/RPC] latency: 0.0006 total: 7.000000 PHttpChannelChild|Msg_AsyncOpen latency: 0.0005 total: 6.000000 PHttpChannelParent|Msg_OnStopRequest latency: 0.0507 total: 6.000000 PNeckoChild|Msg_PHttpChannelConstructor latency: 0.0005 total: 6.000000 PHttpChannelParent|Msg_OnStartRequest latency: 0.0411 total: 6.000000 PContentChild|Msg_GetPrefLocalizedString [SYNC/RPC] latency: 0.0004 total: 5.000000 PHttpChannelChild|Msg___delete__ latency: 0.0009 total: 5.000000 PContentParent|Msg_NotifyRemotePrefObserver latency: 0.5101 total: 4.000000 PBrowserParent|Msg_Move latency: 0.2080 total: 3.000000 PContentChild|Msg_GetChildList [SYNC/RPC] latency: 0.0008 total: 3.000000 PContentChild|Msg_VisitURI latency: 0.0002 total: 3.000000 PBrowserChild|Msg_NotifyLocationChange latency: 0.0094 total: 2.000000 PBrowserChild|Msg_NotifySecurityChange latency: 0.0009 total: 2.000000 PContentParent|Msg_NotifyVisited latency: 0.0279 total: 2.000000 PBrowserParent|Msg_LoadURL latency: 0.2865 total: 2.000000 PContentParent|Msg_SetOffline latency: 0.0260 total: 1.000000 PBrowserParent|Msg_CreateWidget latency: 0.0006 total: 1.000000 PNeckoParent|Msg_PHttpChannelConstructor latency: 0.0003 total: 1.000000 PHttpChannelParent|Msg_Redirect1Begin latency: 0.0003 total: 1.000000 PHttpChannelChild|Msg_DocumentChannelCleanup latency: 0.0114 total: 1.000000 PContentChild|Msg_PNeckoConstructor latency: 0.0005 total: 1.000000 PBrowserParent|Msg_Destroy latency: 0.0165 total: 1.000000 PContentChild|Msg_PrefHasUserValue [SYNC/RPC] latency: 0.0003 total: 1.000000 PContentParent|Msg_PBrowserConstructor latency: 0.0005 total: 1.000000 PNeckoChild|Msg_PCookieServiceConstructor latency: 0.0002 total: 1.000000 PHttpChannelChild|Msg_Redirect2Result latency: 0.0049 total: 1.000000 PBrowserChild|Msg___delete__ latency: 0.0000 total: 1.000000 PContentParent|Msg_RegisterChrome latency: 0.6041 total: 1.000000 PHttpChannelParent|Msg_Redirect3Complete latency: 0.0005 total: 1.000000 PHttpChannelParent|Msg___delete__ latency: 0.0343 total: 1.000000 === By latency === PContentParent|Msg_RegisterChrome latency: 0.6041 total: 1.000000 PContentParent|Msg_NotifyRemotePrefObserver latency: 0.5101 total: 4.000000 PBrowserParent|Msg_LoadURL latency: 0.2865 total: 2.000000 PBrowserParent|Msg_LoadRemoteScript latency: 0.2392 total: 7.000000 PBrowserParent|Msg_AsyncMessage latency: 0.2114 total: 13.000000 PBrowserParent|Msg_Move latency: 0.2080 total: 3.000000 PBrowserParent|Msg_PDocumentRendererNativeIDConstructor latency: 0.0868 total: 9.000000 PHttpChannelParent|Msg_OnDataAvailable latency: 0.0830 total: 30.000000 PHttpChannelParent|Msg_OnProgress latency: 0.0799 total: 29.000000 PHttpChannelParent|Msg_OnStatus latency: 0.0730 total: 41.000000 PHttpChannelParent|Msg_OnStopRequest latency: 0.0507 total: 6.000000 PHttpChannelParent|Msg_OnStartRequest latency: 0.0411 total: 6.000000 PHttpChannelParent|Msg___delete__ latency: 0.0343 total: 1.000000 PContentParent|Msg_NotifyVisited latency: 0.0279 total: 2.000000 PContentParent|Msg_SetOffline latency: 0.0260 total: 1.000000 PBrowserParent|Msg_Destroy latency: 0.0165 total: 1.000000 PHttpChannelChild|Msg_DocumentChannelCleanup latency: 0.0114 total: 1.000000 PBrowserChild|Msg_NotifyLocationChange latency: 0.0094 total: 2.000000 PHttpChannelChild|Msg_Redirect2Result latency: 0.0049 total: 1.000000 PBrowserChild|Msg_AsyncMessage latency: 0.0040 total: 77.000000 PBrowserChild|Msg_NotifyStateChange latency: 0.0032 total: 57.000000 PContentChild|Msg_GetBoolPref [SYNC/RPC] latency: 0.0027 total: 245.000000 PContentChild|Msg_GetIntPref [SYNC/RPC] latency: 0.0026 total: 254.000000 PBrowserChild|Msg_NotifyProgressChange latency: 0.0021 total: 30.000000 PBrowserChild|Msg_NotifyStatusChange latency: 0.0017 total: 46.000000 PContentChild|Msg_TestPermission [SYNC/RPC] latency: 0.0012 total: 32.000000 PDocumentRendererNativeIDChild|Msg___delete__ latency: 0.0010 total: 9.000000 PBrowserChild|Msg_NotifySecurityChange latency: 0.0009 total: 2.000000 PHttpChannelChild|Msg___delete__ latency: 0.0009 total: 5.000000 PContentChild|Msg_GetChildList [SYNC/RPC] latency: 0.0008 total: 3.000000 PContentChild|Msg_GetCharPref [SYNC/RPC] latency: 0.0006 total: 386.000000 PCookieServiceChild|Msg_GetCookieString [SYNC/RPC] latency: 0.0006 total: 7.000000 PBrowserParent|Msg_CreateWidget latency: 0.0006 total: 1.000000 PContentChild|Msg_PNeckoConstructor latency: 0.0005 total: 1.000000 PNeckoChild|Msg_PHttpChannelConstructor latency: 0.0005 total: 6.000000 PHttpChannelChild|Msg_AsyncOpen latency: 0.0005 total: 6.000000 PContentParent|Msg_PBrowserConstructor latency: 0.0005 total: 1.000000 PHttpChannelParent|Msg_Redirect3Complete latency: 0.0005 total: 1.000000 PContentChild|Msg_GetPrefLocalizedString [SYNC/RPC] latency: 0.0004 total: 5.000000 PHttpChannelParent|Msg_Redirect1Begin latency: 0.0003 total: 1.000000 PContentChild|Msg_PrefHasUserValue [SYNC/RPC] latency: 0.0003 total: 1.000000 PNeckoParent|Msg_PHttpChannelConstructor latency: 0.0003 total: 1.000000 PContentChild|Msg_VisitURI latency: 0.0002 total: 3.000000 PNeckoChild|Msg_PCookieServiceConstructor latency: 0.0002 total: 1.000000 PNeckoChild|Msg_HTMLDNSPrefetch latency: 0.0002 total: 39.000000 PContentChild|Msg_StartVisitedQuery latency: 0.0001 total: 33.000000 PBrowserChild|Msg___delete__ latency: 0.0000 total: 1.000000
Attached patch Python profiling script (obsolete) — Splinter Review
Attachment #475618 - Attachment is obsolete: true
Assignee: nobody → azakai
Attached patch Patch v2 (obsolete) — Splinter Review
Turns out that since the parent and child outputs go to the same place, they can overwrite each other, dropping or cutting lines in the middle. So, added an option to redirect the child stdout or stderr to a separate file. Example output (icanhascheezburger/fennec): http://pastebin.mozilla.org/790209
Attachment #475621 - Attachment is obsolete: true
Attached patch Patch v3Splinter Review
Now with visualization as well.
Attachment #475941 - Attachment is obsolete: true
Updated patch (see link in comment 6) now supports profiling on android devices. See comments in android_prettifier.py for details. Will post some profiling data in bug 629513 soon.
This is very obsolete.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: