contentTracing categoryFilter regression on 2.0.0-beta.6 #12506

kwonoj · 2018-04-02T17:33:20Z

Electron version: 2.0.0-beta.6
Operating system: confirmed on macOS locally, assume same on other OS

Expected behavior

disabled-by-default-memory-infra should be collected.

Actual behavior

It is not.

It does seem some of other categories are also not working correctly, but hard to verify what's working vs. what's not working

How to reproduce

Below's minimal code to automatically trigger content tracing, with single category filter disabled-by-default-memory-infra specified:

index.js

const { app, BrowserView, BrowserWindow, contentTracing } = require('electron')
const path = require('path')
const url = require('url')

let win
function createWindow() {
  win = new BrowserWindow({ width: 800, height: 600 })

  win.loadURL(url.format({
    pathname: path.join(`${__dirname}/src`, 'index.html'),
    protocol: 'file:',
    slashes: true
  }));

  //setup browserview to create dummy `load` to capture memory change
  let view = new BrowserView({
    webPreferences: {
      nodeIntegration: false
    }
  })

  win.setBrowserView(view)
  view.setBounds({ x: 0, y: 0, width: 300, height: 300 })
  view.webContents.loadURL('https://web.basemark.com/')

  win.on('closed', () => {
    win = null
  })

  const options = {
    traceOptions: 'record-until-full',
    categoryFilter: '-*,disabled-by-default-memory-infra' //exclude all category, set memory-infra only
  }

  contentTracing.startRecording(options, () => {
    console.log('Tracing started')

    setTimeout(() => {
      contentTracing.stopRecording('./a.trace', (path) => {
        console.log('Tracing data recorded to ' + path)
      })
    }, 10000)
  })
}

app.on('ready', createWindow)

app.on('window-all-closed', () => {
  if (process.platform !== 'darwin') {
    app.quit()
  }
})

app.on('activate', () => {
  if (win === null) {
    createWindow()
  }
})

index.html

<!DOCTYPE html>
  <html>
    <head>
      <meta charset="UTF-8">
      <title>Hello World!</title>
    </head>
    <body>
      <h1>Hello World!</h1>
      We are using node <script>document.write(process.versions.node)</script>,
      Chrome <script>document.write(process.versions.chrome)</script>,
      and Electron <script>document.write(process.versions.electron)</script>.
    </body>
  </html>

On 1.8.4, it collects memory infra stats correctly:

On 2.0.0, the collected trace is simply empty:

this is full trace metadata on 2.0.0. As you could see below, it doesn't contain any actual trace but only initial metadata when trace kicked off

{"traceEvents":[{"pid":93553,"tid":0,"ts":0,"ph":"M","cat":"__metadata","name":"num_cpus","args":{"number":8}},
{"pid":93553,"tid":13827,"ts":0,"ph":"M","cat":"__metadata","name":"process_sort_index","args":{"sort_index":-1}},
{"pid":93553,"tid":13827,"ts":0,"ph":"M","cat":"__metadata","name":"process_name","args":{"name":"GPU Process"}},
{"pid":93553,"tid":13827,"ts":0,"ph":"M","cat":"__metadata","name":"process_uptime_seconds","args":{"uptime":10}},{"pid":93565,"tid":0,"ts":0,"ph":"M","cat":"__metadata","name":"num_cpus","args":{"number":8}},
{"pid":93565,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_sort_index","args":{"sort_index":-5}},
{"pid":93565,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_name","args":{"name":"Renderer"}},
{"pid":93565,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_uptime_seconds","args":{"uptime":0}},
{"pid":93565,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_labels","args":{"labels":"Basemark Web 3.0 | Main page"}},
{"pid":93565,"tid":775,"ts":0,"ph":"M","cat":"__metadata","name":"thread_sort_index","args":{"sort_index":-1}},{"pid":93556,"tid":0,"ts":0,"ph":"M","cat":"__metadata","name":"num_cpus","args":{"number":8}},
{"pid":93556,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_sort_index","args":{"sort_index":-5}},
{"pid":93556,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_name","args":{"name":"Renderer"}},
{"pid":93556,"tid":21511,"ts":0,"ph":"M","cat":"__metadata","name":"process_uptime_seconds","args":{"uptime":10}},
{"pid":93556,"tid":775,"ts":0,"ph":"M","cat":"__metadata","name":"thread_sort_index","args":{"sort_index":-1}},{"pid":93554,"tid":0,"ts":0,"ph":"M","cat":"__metadata","name":"num_cpus","args":{"number":8}},
{"pid":93554,"tid":8455,"ts":0,"ph":"M","cat":"__metadata","name":"process_sort_index","args":{"sort_index":-5}},
{"pid":93554,"tid":8455,"ts":0,"ph":"M","cat":"__metadata","name":"process_name","args":{"name":"Renderer"}},
{"pid":93554,"tid":8455,"ts":0,"ph":"M","cat":"__metadata","name":"process_uptime_seconds","args":{"uptime":10}},
{"pid":93554,"tid":8455,"ts":0,"ph":"M","cat":"__metadata","name":"process_labels","args":{"labels":"Hello World!"}},
{"pid":93554,"tid":775,"ts":0,"ph":"M","cat":"__metadata","name":"thread_sort_index","args":{"sort_index":-1}},{"pid":93551,"tid":775,"ts":473973638595,"ph":"M","cat":"__metadata","name":"IsTimeTicksHighResolution","args":{"value":true},"tts":311029},
{"pid":93551,"tid":0,"ts":0,"ph":"M","cat":"__metadata","name":"num_cpus","args":{"number":8}},
{"pid":93551,"tid":26883,"ts":0,"ph":"M","cat":"__metadata","name":"process_sort_index","args":{"sort_index":-6}},
{"pid":93551,"tid":26883,"ts":0,"ph":"M","cat":"__metadata","name":"process_name","args":{"name":"Browser"}},
{"pid":93551,"tid":26883,"ts":0,"ph":"M","cat":"__metadata","name":"process_uptime_seconds","args":{"uptime":10}}],"metadata": {"clock-domain":"MAC_MACH_ABSOLUTE_TIME","command_line":"/Users/ojkwon/github/dummy-electron/node_modules/electron/dist/Electron.app/Contents/MacOS/Electron --no-sandbox --allow-file-access-from-files --enable-avfoundation ./src/index.js","cpu-brand":"Intel(R) Core(TM) i7-4980HQ CPU @ 2.80GHz","cpu-family":6,"cpu-model":70,"cpu-stepping":1,"gpu-devid":26657,"gpu-driver":"","gpu-glver":"","gpu-psver":"","gpu-venid":4098,"gpu-vsver":"","highres-ticks":true,"network-type":"WiFi","num-cpus":8,"os-arch":"x86_64","os-name":"Mac OS X","os-version":"10.13.3","physical-memory":16384,"product-version":"Chrome/61.0.3163.100","trace-capture-datetime":"2018-4-2 17:23:53","trace-config":"{\"enable_argument_filter\":false,\"enable_systrace\":false,\"excluded_categories\":[\"*\"],\"included_categories\":[\"disabled-by-default-memory-infra\"],\"memory_dump_config\":{\"allowed_dump_modes\":[\"background\",\"light\",\"detailed\"],\"triggers\":[]},\"record_mode\":\"record-until-full\"}","user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/61.0.3163.100 Electron/2.0.0-beta.6 Safari/537.36","v8-version":"6.1.534.41"}}

Both (1.8.4/2.0.0) getCategories reports given trace category is supported one

I couldn't verify each category, but it does seem few other categories are not working as well (mostly around net-* related, but based on limited testing)

The text was updated successfully, but these errors were encountered:

codebytere · 2018-04-20T04:34:41Z

@kwonoj did you verify this to work in 1-8-x? The api file for contentTracing is identical between the 1-8-x and 2-0-x release line branches so i'm not sure it's a regression; if 1-8-x does indeed work than it may be an upstream issue in chromium

kwonoj · 2018-04-20T04:39:17Z

@codebytere issue body attaches comparison between latest 1.8 and 2.0. With attached code snippet it can be reproduced easily.

ZacWalk · 2018-07-27T15:40:09Z

I have been investigating the memory tracing. I think it is likely memory tracing was broken by this chromium change -> https://groups.google.com/a/chromium.org/forum/#!msg/tracing/cLKj2Nb9SaA/x_vh_F1OBgAJ
If a memory_dump_config is not set in tracing then memory dumps won't occur periodically. This would mean no tracing for memory. Electron does not allow memory_dump_config to be specified currently.
Maybe a fix would allow this to be set in tracing config.

ZacWalk · 2018-08-02T15:02:54Z

I have a PR for fixing the tracing of memory-infra by passing a full tracing config. Still a WIP but I am interested in feedback.

This allows memory-infra to be traced correctly. Fixes #12506.