{"id":584,"date":"2021-05-11T07:00:00","date_gmt":"2021-05-11T06:00:00","guid":{"rendered":"https:\/\/eocanha.org\/blog\/?p=584"},"modified":"2021-05-04T18:30:47","modified_gmt":"2021-05-04T17:30:47","slug":"gstreamer-webkit-debugging-by-instrumenting-source-code-3-3","status":"publish","type":"post","link":"https:\/\/eocanha.org\/blog\/2021\/05\/11\/gstreamer-webkit-debugging-by-instrumenting-source-code-3-3\/","title":{"rendered":"GStreamer WebKit debugging by instrumenting source code (3\/3)"},"content":{"rendered":"\n<p>This is the last post on the instrumenting source code series. I hope you to find the tricks below as useful as the previous ones. <\/p>\n\n\n\n<p>In this post I show some more useful debugging tricks. Don&#8217;t forget to have a look at the other posts of the series:<\/p>\n\n\n\n<ul id=\"block-b42f86ed-cff9-42e2-b084-bd3cfb76f92c\"><li><a href=\"https:\/\/eocanha.org\/blog\/2021\/04\/13\/gstreamer-webkit-debugging-tricks-using-gdb-1-2\/\">GStreamer WebKit debugging tricks using GDB (1\/2)<\/a><\/li><li><a href=\"https:\/\/eocanha.org\/blog\/2021\/04\/20\/gstreamer-webkit-debugging-tricks-using-gdb-2-2\/\">GStreamer WebKit debugging tricks using GDB (2\/2)<\/a><\/li><li><a href=\"https:\/\/eocanha.org\/blog\/2021\/04\/27\/gstreamer-webkit-debugging-by-instrumenting-source-code-1-3\/\">GStreamer WebKit debugging by instrumenting source code (1\/3)<\/a><\/li><li><a href=\"https:\/\/eocanha.org\/blog\/2021\/05\/04\/gstreamer-webkit-debugging-by-instrumenting-source-code-2-3\/\">GStreamer WebKit debugging by instrumenting source code (2\/3)<\/a><\/li><\/ul>\n\n\n\n<h2>Finding memory leaks in a RefCounted subclass<\/h2>\n\n\n\n<p>The source code shown below must be placed in the .h where the class to be debugged is defined. It&#8217;s written in a way that doesn&#8217;t need to rebuild <code>RefCounted.h<\/code>, so it saves a lot of build time. It logs all refs, unrefs and adoptPtrs, so that any anomaly in the refcounting can be traced and investigated later. To use it, just make your class inherit from <code>LoggedRefCounted<\/code> instead of <code>RefCounted<\/code>.<\/p>\n\n\n\n<p>Example output:<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">void WTF::adopted(WTF::LoggedRefCounted&lt;T>*) [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1\nvoid WTF::adopted(WTF::LoggedRefCounted&lt;T>*) [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1\n^^^ Two adopts, this is not good.\nvoid WTF::LoggedRefCounted&lt;T>::ref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1 --> ...\nvoid WTF::LoggedRefCounted&lt;T>::ref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount ... --> 2\nvoid WTF::LoggedRefCounted&lt;T>::deref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 2 --> ...\nvoid WTF::LoggedRefCounted&lt;T>::deref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount ... --> 1\nvoid WTF::adopted(WTF::LoggedRefCounted&lt;T>*) [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1\nvoid WTF::LoggedRefCounted&lt;T>::deref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1 --> ...\nvoid WTF::LoggedRefCounted&lt;T>::deref() [with T = WebCore::MediaSourceClientGStreamerMSE]: this=0x673c07a4, refCount 1 --> ...\n^^^ Two recursive derefs, not good either.<\/pre>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">#include \"Logging.h\"\n\nnamespace WTF {\n\ntemplate&lt;typename T> class LoggedRefCounted : public WTF::RefCounted&lt;T> {\n    WTF_MAKE_NONCOPYABLE(LoggedRefCounted); WTF_MAKE_FAST_ALLOCATED;\npublic:\n    void ref() {\n        printf(\"%s: this=%p, refCount %d --> ...\\n\", __PRETTY_FUNCTION__, this, WTF::RefCounted&lt;T>::refCount()); fflush(stdout);\n        WTF::RefCounted&lt;T>::ref();\n        printf(\"%s: this=%p, refCount ... --> %d\\n\", __PRETTY_FUNCTION__, this, WTF::RefCounted&lt;T>::refCount()); fflush(stdout);\n    }\n\n    void deref() {\n        printf(\"%s: this=%p, refCount %d --> ...\\n\", __PRETTY_FUNCTION__, this, WTF::RefCounted&lt;T>::refCount()); fflush(stdout);\n        WTF::RefCounted&lt;T>::deref();\n        printf(\"%s: this=%p, refCount ... --> %d\\n\", __PRETTY_FUNCTION__, this, WTF::RefCounted&lt;T>::refCount()); fflush(stdout);\n    }\n\nprotected:\n    LoggedRefCounted() { }\n    ~LoggedRefCounted() { }\n};\n\ntemplate&lt;typename T> inline void adopted(WTF::LoggedRefCounted&lt;T>* object)\n{\n    printf(\"%s: this=%p, refCount %d\\n\", __PRETTY_FUNCTION__, object, (object)?object->refCount():0); fflush(stdout);\n    adopted(static_cast&lt;RefCountedBase*>(object));\n}\n\n} \/\/ Namespace WTF<\/pre>\n\n\n\n<h2>Pause WebProcess on launch<\/h2>\n\n\n\n<p><a href=\"https:\/\/github.com\/WebKit\/WebKit\/blob\/main\/Source\/WebKit\/WebProcess\/gtk\/WebProcessMainGtk.cpp#L55\">WebProcessMainGtk<\/a> and <a href=\"https:\/\/github.com\/WebKit\/WebKit\/blob\/main\/Source\/WebKit\/WebProcess\/wpe\/WebProcessMainWPE.cpp#L88\">WebProcessMainWPE<\/a> will sleep for 30 seconds if a special environment variable is defined:<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">export WEBKIT2_PAUSE_WEB_PROCESS_ON_LAUNCH=1<\/pre>\n\n\n\n<p>It only works <code>#if ENABLE(DEVELOPER_MODE)<\/code>, so you might want to remove those ifdefs if you&#8217;re building in Release mode.<\/p>\n\n\n\n<h2>Log tracers<\/h2>\n\n\n\n<p>In big pipelines (e.g. playbin) it can be very hard to find what element is replying to a query or handling an event. Even using gdb can be extremely tedious due to the very high level of recursion. My coworker <a href=\"https:\/\/github.com\/ntrrgc\" data-type=\"URL\" data-id=\"https:\/\/github.com\/ntrrgc\">Alicia<\/a> commented that using log tracers is more helpful in this case.<\/p>\n\n\n\n<p><code>GST_TRACERS=log<\/code> enables additional GST_TRACE() calls all accross GStreamer. The following example logs entries and exits into the query function.<\/p>\n\n\n\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"generic\" data-enlighter-theme=\"\" data-enlighter-highlight=\"\" data-enlighter-linenumbers=\"\" data-enlighter-lineoffset=\"\" data-enlighter-title=\"\" data-enlighter-group=\"\">GST_TRACERS=log GST_DEBUG='query:TRACE'<\/pre>\n\n\n\n<p>The names of the logging categories are somewhat inconsistent:<\/p>\n\n\n\n<ul><li>log (the log tracer itself)<\/li><li>GST_BUFFER<\/li><li>GST_BUFFER_LIST<\/li><li>GST_EVENT<\/li><li>GST_MESSAGE<\/li><li>GST_STATES<\/li><li>GST_PADS<\/li><li>GST_ELEMENT_PADS<\/li><li>GST_ELEMENT_FACTORY<\/li><li>query<\/li><li>bin<\/li><\/ul>\n\n\n\n<p>The log tracer code is in <code>subprojects\/gstreamer\/plugins\/tracers\/gstlog.c<\/code>.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>This is the last post on the instrumenting source code series. I hope you to find the tricks below as useful as the previous ones. In this post I show some more useful debugging tricks. Don&#8217;t forget to have a look at the other posts of the series: GStreamer WebKit debugging tricks using GDB (1\/2) &hellip; <a href=\"https:\/\/eocanha.org\/blog\/2021\/05\/11\/gstreamer-webkit-debugging-by-instrumenting-source-code-3-3\/\" class=\"more-link\">Continue reading <span class=\"screen-reader-text\">GStreamer WebKit debugging by instrumenting source code (3\/3)<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":[],"categories":[11,13,2,1,7,12],"tags":[20],"_links":{"self":[{"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/posts\/584"}],"collection":[{"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/comments?post=584"}],"version-history":[{"count":4,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/posts\/584\/revisions"}],"predecessor-version":[{"id":610,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/posts\/584\/revisions\/610"}],"wp:attachment":[{"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/media?parent=584"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/categories?post=584"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/eocanha.org\/blog\/wp-json\/wp\/v2\/tags?post=584"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}