Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 1 | # Debugging GPU related code |
| 2 | |
| 3 | Chromium's GPU system is multi-process, which can make debugging it rather |
| 4 | difficult. See [GPU Command Buffer] for some of the nitty gitty. These are just |
| 5 | a few notes to help with debugging. |
| 6 | |
| 7 | [TOC] |
| 8 | |
| 9 | <!-- TODO(kainino): update link if the page moves --> |
| 10 | [GPU Command Buffer]: https://sites.google.com/a/chromium.org/dev/developers/design-documents/gpu-command-buffer |
| 11 | |
| 12 | ## Renderer Process Code |
| 13 | |
| 14 | ### `--enable-gpu-client-logging` |
| 15 | |
| 16 | If you are trying to track down a bug in a GPU client process (compositing, |
| 17 | WebGL, Skia/Ganesh, Aura), then in a debug build you can use the |
| 18 | `--enable-gpu-client-logging` flag, which will show every GL call sent to the |
| 19 | GPU service process. (From the point of view of a GPU client, it's calling |
| 20 | OpenGL ES functions - but the real driver calls are made in the GPU process.) |
| 21 | |
Kenneth Russell | dca586f | 2018-12-01 01:53:19 | [diff] [blame] | 22 | You can also use this flag in a release build by specifying the GN argument: |
| 23 | |
| 24 | ``` |
| 25 | enable_gpu_client_logging=true |
| 26 | ``` |
| 27 | |
| 28 | It's typically necessary to specify the `--enable-logging=stderr` flag as well: |
| 29 | |
| 30 | ``` |
| 31 | --enable-gpu-client-logging --enable-logging=stderr |
| 32 | ``` |
| 33 | |
| 34 | The output looks like this: |
| 35 | |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 36 | ``` |
| 37 | [4782:4782:1219/141706:INFO:gles2_implementation.cc(1026)] [.WebGLRenderingContext] glUseProgram(3) |
| 38 | [4782:4782:1219/141706:INFO:gles2_implementation_impl_autogen.h(401)] [.WebGLRenderingContext] glGenBuffers(1, 0x7fffc9e1269c) |
| 39 | [4782:4782:1219/141706:INFO:gles2_implementation_impl_autogen.h(416)] 0: 1 |
| 40 | [4782:4782:1219/141706:INFO:gles2_implementation_impl_autogen.h(23)] [.WebGLRenderingContext] glBindBuffer(GL_ARRAY_BUFFER, 1) |
| 41 | [4782:4782:1219/141706:INFO:gles2_implementation.cc(1313)] [.WebGLRenderingContext] glBufferData(GL_ARRAY_BUFFER, 36, 0x7fd268580120, GL_STATIC_DRAW) |
| 42 | [4782:4782:1219/141706:INFO:gles2_implementation.cc(2480)] [.WebGLRenderingContext] glEnableVertexAttribArray(0) |
| 43 | [4782:4782:1219/141706:INFO:gles2_implementation.cc(1140)] [.WebGLRenderingContext] glVertexAttribPointer(0, 3, GL_FLOAT, GL_FALSE, 0, 0) |
| 44 | [4782:4782:1219/141706:INFO:gles2_implementation_impl_autogen.h(135)] [.WebGLRenderingContext] glClear(16640) |
| 45 | [4782:4782:1219/141706:INFO:gles2_implementation.cc(2490)] [.WebGLRenderingContext] glDrawArrays(GL_TRIANGLES, 0, 3) |
| 46 | ``` |
| 47 | |
| 48 | ### Checking about:gpu |
| 49 | |
| 50 | The GPU process logs many errors and warnings. You can see these by navigating |
| 51 | to `about:gpu`. Logs appear at the bottom of the page. You can also see them |
| 52 | on standard output if Chromium is run from the command line on Linux/Mac. |
| 53 | On Windows, you need debugging tools (like VS, WinDbg, etc.) to connect to the |
| 54 | debug output stream. |
| 55 | |
| 56 | **Note:** If `about:gpu` is telling you that your GPU is disabled and |
| 57 | hardware acceleration is unavailable, it might be a problem with your GPU being |
| 58 | unsupported. To override this and turn on hardware acceleration anyway, you can |
Corentin Wallez | e660b15 | 2020-07-15 16:07:54 | [diff] [blame] | 59 | use the `--ignore-gpu-blocklist` command line option when starting Chromium. |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 60 | |
| 61 | ### Breaking on GL Error |
| 62 | |
| 63 | In <code>[gles2_implementation.h]</code>, there is some code like this: |
| 64 | |
| 65 | ```cpp |
| 66 | // Set to 1 to have the client fail when a GL error is generated. |
| 67 | // This helps find bugs in the renderer since the debugger stops on the error. |
| 68 | #if DCHECK_IS_ON() |
| 69 | #if 0 |
| 70 | #define GL_CLIENT_FAIL_GL_ERRORS |
| 71 | #endif |
| 72 | #endif |
| 73 | ``` |
| 74 | |
| 75 | Change that `#if 0` to `#if 1`, build a debug build, then run in a debugger. |
| 76 | The debugger will break when any renderer code sees a GL error, and you should |
| 77 | be able to examine the call stack to find the issue. |
| 78 | |
| 79 | [gles2_implementation.h]: https://chromium.googlesource.com/chromium/src/+/master/gpu/command_buffer/client/gles2_implementation.h |
| 80 | |
| 81 | ### Labeling your calls |
| 82 | |
| 83 | The output of all of the errors, warnings and debug logs are prefixed. You can |
| 84 | set this prefix by calling `glPushGroupMarkerEXT`, `glPopGroupMarkerEXT` and |
| 85 | `glInsertEventMarkerEXT`. `glPushGroupMarkerEXT` appends a string to the end of |
| 86 | the current log prefix (think namespace in C++). `glPopGroupmarkerEXT` pops off |
| 87 | the last string appended. `glInsertEventMarkerEXT` sets a suffix for the |
| 88 | current string. Example: |
| 89 | |
| 90 | ```cpp |
| 91 | glPushGroupMarkerEXT(0, "Foo"); // -> log prefix = "Foo" |
| 92 | glInsertEventMarkerEXT(0, "This"); // -> log prefix = "Foo.This" |
| 93 | glInsertEventMarkerEXT(0, "That"); // -> log prefix = "Foo.That" |
| 94 | glPushGroupMarkerEXT(0, "Bar"); // -> log prefix = "Foo.Bar" |
| 95 | glInsertEventMarkerEXT(0, "Orange"); // -> log prefix = "Foo.Bar.Orange" |
| 96 | glInsertEventMarkerEXT(0, "Banana"); // -> log prefix = "Foo.Bar.Banana" |
| 97 | glPopGroupMarkerEXT(); // -> log prefix = "Foo.That" |
| 98 | ``` |
| 99 | |
| 100 | ### Making a reduced test case. |
| 101 | |
| 102 | You can often make a simple OpenGL-ES-2.0-only C++ reduced test case that is |
Takuto Ikuta | f533325 | 2019-11-06 16:07:08 | [diff] [blame] | 103 | relatively quick to compile and test, by adding tests to the `gl_tests` target. |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 104 | Those tests exist in `src/gpu/command_buffer/tests` and are made part of the |
Takuto Ikuta | f533325 | 2019-11-06 16:07:08 | [diff] [blame] | 105 | build in `src/gpu/BUILD.gn`. Build with `ninja -C out/Debug gl_tests`. All the |
| 106 | same command line options listed on this page will work with the `gl_tests`, |
| 107 | plus `--gtest_filter=NameOfTest` to run a specific test. Note the `gl_tests` |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 108 | are not multi-process, so they probably won't help with race conditions, but |
| 109 | they do go through most of the same code and are much easier to debug. |
| 110 | |
| 111 | ### Debugging the renderer process |
| 112 | |
| 113 | Given that Chrome starts many renderer processes I find it's easier if I either |
| 114 | have a remote webpage I can access or I make one locally and then use a local |
| 115 | server to serve it like `python -m SimpleHTTPServer`. Then |
| 116 | |
| 117 | On Linux this works for me: |
| 118 | |
| 119 | * `out/Debug/chromium --no-sandbox --renderer-cmd-prefix="xterm -e gdb |
| 120 | --args" http://localhost:8000/page-to-repro.html` |
| 121 | |
| 122 | On OSX this works for me: |
| 123 | |
| 124 | * `out/Debug/Chromium.app/Contents/MacOSX/Chromium --no-sandbox |
| 125 | --renderer-cmd-prefix="xterm -e gdb --args" |
| 126 | http://localhost:8000/page-to-repro.html` |
| 127 | |
| 128 | On Windows I use `--renderer-startup-dialog` and then connect to the listed process. |
| 129 | |
| 130 | Note 1: On Linux and OSX I use `cgdb` instead of `gdb`. |
| 131 | |
| 132 | Note 2: GDB can take minutes to index symbol. To save time, you can precache |
| 133 | that computation by running `build/gdb-add-index out/Debug/chrome`. |
| 134 | |
| 135 | ## GPU Process Code |
| 136 | |
| 137 | ### `--enable-gpu-service-logging` |
| 138 | |
Vikas Soni | 78daa63 | 2019-01-12 01:32:52 | [diff] [blame] | 139 | In a debug build or a release build with dcheck_always_on=true in GN argument, |
| 140 | this will print all actual calls into the GL driver. |
| 141 | |
| 142 | To use it in Release builds without dcheck_always_on = true, specify GN argument |
| 143 | enable_gpu_service_logging=true. |
| 144 | |
| 145 | For non-rooted devices running production builds, we can not set the command |
| 146 | line flags. Use about://flags 'Enable gpu service logging' instead. |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 147 | |
| 148 | ``` |
| 149 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kEnableVertexAttribArray |
| 150 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(905)] glEnableVertexAttribArray(0) |
| 151 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kVertexAttribPointer |
| 152 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(1573)] glVertexAttribPointer(0, 3, GL_FLOAT, GL_FALSE, 0, 0) |
| 153 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kClear |
| 154 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(746)] glColorMask(GL_TRUE, GL_TRUE, GL_TRUE, GL_TRUE) |
| 155 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(840)] glDepthMask(GL_TRUE) |
| 156 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(900)] glEnable(GL_DEPTH_TEST) |
| 157 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(1371)] glStencilMaskSeparate(GL_FRONT, 4294967295) |
| 158 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(1371)] glStencilMaskSeparate(GL_BACK, 4294967295) |
| 159 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(860)] glDisable(GL_STENCIL_TEST) |
| 160 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(860)] glDisable(GL_CULL_FACE) |
| 161 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(860)] glDisable(GL_SCISSOR_TEST) |
| 162 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(900)] glEnable(GL_BLEND) |
| 163 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(721)] glClear(16640) |
| 164 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kDrawArrays |
| 165 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(870)] glDrawArrays(GL_TRIANGLES, 0, 3) |
| 166 | ``` |
| 167 | |
| 168 | Note that GL calls into the driver are not currently prefixed (todo?). But, you |
| 169 | can tell from the commands logged which command, from which context caused the |
| 170 | following GL calls to be made. |
| 171 | |
| 172 | Also note that client resource IDs are virtual IDs, so calls into the real GL |
| 173 | driver will not match (though some commands print the mapping). Examples: |
| 174 | |
| 175 | ``` |
| 176 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kBindTexture |
| 177 | [5497:5497:1219/142413:INFO:gles2_cmd_decoder.cc(837)] [.WebGLRenderingContext] glBindTexture: client_id = 2, service_id = 10 |
| 178 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(662)] glBindTexture(GL_TEXTURE_2D, 10) |
| 179 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [0052064A367F0000]cmd: kBindBuffer |
| 180 | [5497:5497:1219/142413:INFO:gles2_cmd_decoder.cc(837)] [0052064A367F0000] glBindBuffer: client_id = 2, service_id = 6 |
| 181 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(637)] glBindBuffer(GL_ARRAY_BUFFER, 6) |
| 182 | [5497:5497:1219/142413:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kBindFramebuffer |
| 183 | [5497:5497:1219/142413:INFO:gles2_cmd_decoder.cc(837)] [.WebGLRenderingContext] glBindFramebuffer: client_id = 1, service_id = 3 |
| 184 | [5497:5497:1219/142413:INFO:gl_bindings_autogen_gl.cc(652)] glBindFramebufferEXT(GL_FRAMEBUFFER, 3) |
| 185 | ``` |
| 186 | |
| 187 | etc... so that you can see renderer process code would be using the client IDs |
| 188 | where as the gpu process is using the service IDs. This is useful for matching |
| 189 | up calls if you're dumping both client and service GL logs. |
| 190 | |
| 191 | ### `--enable-gpu-debugging` |
| 192 | |
| 193 | In any build, this will call glGetError after each command |
| 194 | |
| 195 | ### `--enable-gpu-command-logging` |
| 196 | |
| 197 | This will print the name of each GPU command before it is executed. |
| 198 | |
| 199 | ``` |
| 200 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kBindBuffer |
| 201 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kBufferData |
| 202 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: SetToken |
| 203 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kEnableVertexAttribArray |
| 204 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kVertexAttribPointer |
| 205 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kClear |
| 206 | [5234:5234:1219/052139:ERROR:gles2_cmd_decoder.cc(3301)] [.WebGLRenderingContext]cmd: kDrawArrays |
| 207 | ``` |
| 208 | |
| 209 | ### Debugging in the GPU Process |
| 210 | |
| 211 | Given the multi-processness of chromium it can be hard to debug both sides. |
Bruce Dawson | f17419f | 2018-06-12 01:47:03 | [diff] [blame] | 212 | Turning on all the logging and having a small test case is useful. One minor |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 213 | suggestion, if you have some idea where the bug is happening a call to some |
| 214 | obscure gl function like `glHint()` can give you a place to catch a command |
| 215 | being processed in the GPU process (put a break point on |
| 216 | `gpu::gles2::GLES2DecoderImpl::HandleHint`. Once in you can follow the commands |
| 217 | after that. All of them go through `gpu::gles2::GLES2DecoderImpl::DoCommand`. |
| 218 | |
| 219 | To actually debug the GPU process: |
| 220 | |
Bruce Dawson | a33b7c4 | 2018-06-14 16:22:23 | [diff] [blame] | 221 | On Linux this works for me: |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 222 | |
Bruce Dawson | a33b7c4 | 2018-06-14 16:22:23 | [diff] [blame] | 223 | * `out/Debug/chromium --no-sandbox --gpu-launcher="xterm -e gdb --args" |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 224 | http://localhost:8000/page-to-repro.html` |
| 225 | |
Bruce Dawson | a33b7c4 | 2018-06-14 16:22:23 | [diff] [blame] | 226 | On OSX this works for me: |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 227 | |
| 228 | * `out/Debug/Chromium.app/Contents/MacOSX/Chromium --no-sandbox |
Bruce Dawson | a33b7c4 | 2018-06-14 16:22:23 | [diff] [blame] | 229 | --gpu-launcher="xterm -e gdb --args" |
Kai Ninomiya | a6429fb3 | 2018-03-30 01:30:56 | [diff] [blame] | 230 | http://localhost:8000/page-to-repro.html` |
| 231 | |
| 232 | On Windows I use `--gpu-startup-dialog` and then connect to the listed process. |
| 233 | |
| 234 | ### `GPU PARSE ERROR` |
| 235 | |
| 236 | If you see this message in `about:gpu` or your console and you didn't cause it |
| 237 | directly (by calling `glLoseContextCHROMIUM`) and it's something other than 5 |
| 238 | that means there's likely a bug. Please file an issue at <http://crbug.com/new>. |
| 239 | |
| 240 | ## Debugging Performance |
| 241 | |
| 242 | If you have something to add here please add it. Most perf debugging is done |
| 243 | using `about:tracing` (see [Trace Event Profiling] for details). Otherwise, |
| 244 | be aware that, since the system is multi-process, calling: |
| 245 | |
| 246 | ``` |
| 247 | start = GetTime() |
| 248 | DoSomething() |
| 249 | glFinish() |
| 250 | end = GetTime |
| 251 | printf("elapsedTime = %f\n", end - start); |
| 252 | ``` |
| 253 | |
| 254 | **will not** give you meaningful results. |
| 255 | |
| 256 | [See Trace Event Profiling for details]: https://sites.google.com/a/chromium.org/dev/developers/how-tos/trace-event-profiling-tool |