Bug 229664

Summary: add logging for IPC messages
Product: WebKit Reporter: Cameron McCormack (:heycam) <heycam>
Component: WebKit2Assignee: Cameron McCormack (:heycam) <heycam>
Status: RESOLVED FIXED    
Severity: Normal CC: achristensen, benjamin, cdumez, cmarcelo, ews-watchlist, Hironori.Fujii, kkinnunen, simon.fraser, thorton, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Local Build   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugs.webkit.org/show_bug.cgi?id=235562
Bug Depends on:    
Bug Blocks: 230064    
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Patch none

Description Cameron McCormack (:heycam) 2021-08-29 23:28:10 PDT
I have a patch.  Still wondering whether to have a single IPCMessages log channel that logs all messages, or have a separate channel per message receiver.
Comment 1 Radar WebKit Bug Importer 2021-08-29 23:28:26 PDT
<rdar://problem/82511640>
Comment 2 Cameron McCormack (:heycam) 2021-08-30 00:08:55 PDT
Created attachment 436758 [details]
Patch
Comment 3 Cameron McCormack (:heycam) 2021-08-30 00:10:15 PDT
This is what the logging looks like, right after starting MiniBrowser:

WebProcess_InitializeWebProcess (processCreationParameters ...)
WebProcessProxy_GetNetworkProcessConnection
NetworkProcess_InitializeNetworkProcess (processCreationParameters ...)
NetworkProcess_PreconnectTo (sessionID ...) (webPageProxyID 6) (webPageID 7) (url http://192.168.20.92:8000/) (userAgent Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko)) (storedCredentialsPolicy ...) (isNavigatingToAppBoundDomain ...
NetworkProcess_CreateNetworkConnectionToWebProcess (processIdentifier 8) (sessionID ...)
NetworkProcess_CreateNetworkConnectionToWebProcess Reply (connectionIdentifier ...) (cookieAcceptPolicy ...)
WebProcessProxy_GetNetworkProcessConnection Reply (connectionInfo ...)
NetworkConnectionToWebProcess_RegisterURLSchemesAsCORSEnabled (schemes [http, https])
AuxiliaryProcess_MainThreadPing
WebProcess_CreateWebPage (newPageID 7) (pageCreationParameters ...)
DrawingAreaProxy_EnterAcceleratedCompositingMode (backingStoreStateID 0) (context ...)
WebPageProxy_DidCreateMainFrame (frameID 3)
WebPageProxy_DidCreateWindow (frameID 3) (windowIdentifier ...)
WebPageProxy_DidChangeMainDocument (frameID 3)
WebProcessProxy_SetDisplayLinkPreferredFramesPerSecond (observerID 6) (displayID 0) (preferredFramesPerSecond 60)
WebProcessProxy_StartDisplayLink (observerID 6) (displayID 0) (preferredFramesPerSecond 60)
WebPageProxy_RegisterWebProcessAccessibilityToken (data ...)
WebPageProxy_FocusedFrameChanged (frameID 3)
WebProcessProxy_SetDisplayLinkPreferredFramesPerSecond (observerID 6) (displayID 0) (preferredFramesPerSecond 30)
WebProcessPool_ReportWebContentCPUTime (cpuTime 0.07s) (activityState 1)
WebPageProxy_DidChangeContentSize (newSize width=1311 height=964)
WebPageProxy_SetCanShortCircuitHorizontalWheelEvents (canShortCircuitHorizontalWheelEvents 1)
WebPageProxy_SetRenderTreeSize (treeSize 3)
WebPageProxy_SetRenderTreeSize (treeSize 3)
WebPageProxy_SampledPageTopColorChanged (sampledPageTopColor #00000000)
Comment 4 Cameron McCormack (:heycam) 2021-08-30 00:11:50 PDT
Not sure if it's useful to show PIDs and/or destination IDs.
Comment 5 Simon Fraser (smfr) 2021-08-30 14:44:36 PDT
Comment on attachment 436758 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=436758&action=review

> Source/WebKit/Platform/IPC/HandleMessage.h:51
> +#ifndef NDEBUG

LOG_DISABLED

> Source/WebKit/Platform/IPC/HandleMessage.h:74
> +#ifndef NDEBUG

LOG_DISABLED
Comment 6 Alex Christensen 2021-08-30 14:47:53 PDT
Source and destination pid would be quite useful.  On Darwin-based OSes, you can probably get the pid from xpc_connection_get_pid and Connection::xpcConnection(), but on other OSes you should probably leave it unimplemented.
Comment 7 Cameron McCormack (:heycam) 2021-08-30 14:54:45 PDT
(In reply to Alex Christensen from comment #6)
> Source and destination pid would be quite useful.  On Darwin-based OSes, you
> can probably get the pid from xpc_connection_get_pid and
> Connection::xpcConnection(), but on other OSes you should probably leave it
> unimplemented.

Maybe I can use getCurrentProcessID() from wtf/ProcessID.h.
Comment 8 Cameron McCormack (:heycam) 2021-08-30 14:55:13 PDT
(In reply to Cameron McCormack (:heycam) from comment #7)
> Maybe I can use getCurrentProcessID() from wtf/ProcessID.h.

(Oh but that doesn't get me the source PID.)
Comment 9 Cameron McCormack (:heycam) 2021-08-31 00:15:25 PDT
One wrinkle is that for Connections that were created using createIPCConnectionPair() (e.g. under createNetworkConnectionToWebProcess), Connection::m_xpcConnection is null.

We only care about the remote process ID on the server-side Connection (since that's the side receiving the messages we're logging), so I guess we could pass it back through the reply messages to the Web process, if we cared to show the PIDs for messages going across those connections.
Comment 10 Cameron McCormack (:heycam) 2021-08-31 17:54:09 PDT
I'm going to ignore that problem for now, and omit the remote process ID for such connections.
Comment 11 Cameron McCormack (:heycam) 2021-08-31 17:55:23 PDT
Created attachment 436976 [details]
Patch
Comment 12 Cameron McCormack (:heycam) 2021-09-02 16:23:58 PDT
Created attachment 437213 [details]
Patch
Comment 13 Alex Christensen 2021-09-07 09:03:01 PDT
Comment on attachment 437213 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=437213&action=review

> Source/WTF/wtf/text/TextStream.h:233
> +        if (i)

nit: I think it would be nice if this had the same style as the other two below and checked count here and used a c++11-style for ( : ) loop

> Source/WTF/wtf/text/TextStream.h:356
> +struct ValueOrFallback {

This is only ever used with "..." as the fallback.  Do we need something this generic, or could we do ValueOrEllipsis?

> Source/WebKit/Platform/IPC/HandleMessage.h:51
> +enum class ForReply { No, Yes };

nit: : bool
Comment 14 Cameron McCormack (:heycam) 2021-09-07 14:52:53 PDT
Created attachment 437558 [details]
Patch
Comment 15 EWS 2021-09-07 16:32:35 PDT
Committed r282115 (241412@main): <https://commits.webkit.org/241412@main>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 437558 [details].
Comment 16 Alex Christensen 2021-09-07 20:34:15 PDT
r282126
Comment 17 Fujii Hironori 2021-09-08 14:04:13 PDT
Filed: Bug 230064 – REGRESSION(r282115): undefined reference to `IPC::messageArgumentDescriptions(IPC::MessageName)' in Debug build