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: