Josef “Jeff” Sipek

DTrace: qsort use in Firefox, part 2

Earlier, I wrote about some silly qsort behavior in Firefox. I couldn’t help but dig a bit deeper.

Before, we concluded that there were a lot of 8-element, 4-byte element sorts. What are these used for? What part of Firefox is causing these? DTrace to the rescue.

First, let’s change the last DTrace command from last time a bit. First of all, let’s look at 4-byte element invocations only (arg2 equals 4) and let’s aggregate on the caller function name:

# dtrace -n 'pid1120:libc:qsort:entry/arg2==4/{@[ufunc(ucaller)]=llquantize(arg1, 10,0,6,20)} tick-60sec{printa(@)}'

...
  1  75455                      :tick-60sec 
  libnss3.so`DPCache_GetUpToDate                    
           value  ------------- Distribution ------------- count    
             < 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 14       
               1 |                                         0        

  libglib-2.0.so.0.2501.0`g_array_sort              
           value  ------------- Distribution ------------- count    
             700 |                                         0        
             750 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
             800 |                                         0        

  libfontconfig.so.1`FcFontSetSort                  
           value  ------------- Distribution ------------- count    
              55 |                                         0        
              60 |@                                        4        
              65 |                                         2        
              70 |                                         0        
              75 |@@@@                                     20       
              80 |@@@@@                                    24       
              85 |@@@@@@@                                  36       
              90 |@@@@@                                    26       
              95 |                                         0        
             100 |@@@@@@@@@@@@@@                           76       
             150 |@@@@                                     22       
             200 |                                         0        

  libcairo.so.2.10800.10`_cairo_bentley_ottmann_tessellate_bo_edges
           value  ------------- Distribution ------------- count    
               3 |                                         0        
               4 |@                                        59       
               5 |                                         0        
               6 |                                         32       
               7 |                                         0        
               8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@            2357     
               9 |                                         0        
              10 |@@                                       137      
              15 |@@@                                      215      
              20 |@                                        52       
              25 |                                         12       
              30 |@                                        58       
              35 |@@                                       200      
              40 |@                                        67       
              45 |                                         3        
              50 |                                         2        
              55 |                                         2        
              60 |                                         7        
              65 |                                         0        
              70 |@                                        67       
              75 |                                         0        
              80 |                                         0        
              85 |                                         0        
              90 |                                         0        
              95 |                                         16       
             100 |                                         0   

We see four unique functions that call qsort. It doesn’t take long to spot the one we were looking for: _cairo_bentley_ottmann_tessellate_bo_edges in libcairo.so. Interesting, so it turns out that it wasn’t Firefox itself doing all these sorts (8-element, 4-byte element) but rather the Cairo graphics library. It would also seem that it is the only place that does these sorts. Let’s see how Firefox is involved in this.

# dtrace -n 'pid1120:libc:qsort:entry/arg2==4 && arg1==8/{@[ustack()]=count()} tick-60sec{printa(@)}'

...
  0  75455                      :tick-60sec 

              libc.so.1`qsort
              libcairo.so.2.10800.10`_cairo_bentley_ottmann_tessellate_bo_edges+0x172
              libcairo.so.2.10800.10`_cairo_bentley_ottmann_tessellate_polygon+0x41f
              libcairo.so.2.10800.10`_cairo_path_fixed_fill_to_traps+0x150
              libcairo.so.2.10800.10`_cairo_clip_clip+0xe3
              libcairo.so.2.10800.10`_cairo_gstate_clip+0x44
              libcairo.so.2.10800.10`cairo_clip_preserve+0x31
              libxul.so`__1cKgfxContextEClip6M_v_+0x24
              libxul.so`__1cInsWindowNOnExposeEvent6MpnK_GtkWidget_pnP_GdkEventExpose__i_+0x56e
              libxul.so`__1cPexpose_event_cb6FpnK_GtkWidget_pnP_GdkEventExpose__i_+0x72
              libgtk-x11-2.0.so.0.2000.0`_gtk_marshal_BOOLEAN__BOXED+0x7b
              libgobject-2.0.so.0.2501.0`g_closure_invoke+0xdf
              libgobject-2.0.so.0.2501.0`signal_emit_unlocked_R+0x9f2
              libgobject-2.0.so.0.2501.0`g_signal_emit_valist+0x6d2
              libgobject-2.0.so.0.2501.0`g_signal_emit+0x28
              libgtk-x11-2.0.so.0.2000.0`gtk_widget_event_internal+0x24d
              libgtk-x11-2.0.so.0.2000.0`gtk_widget_send_expose+0x98
              libgtk-x11-2.0.so.0.2000.0`gtk_main_do_event+0x46f
              libgdk-x11-2.0.so.0.2000.0`_gdk_window_process_updates_recurse+0x291
              libgdk-x11-2.0.so.0.2000.0`_gdk_windowing_window_process_updates_recurse+0x24
              184

This counts the number of 4-byte element, 8-element arrays qsort aggregated on the stack trace. We get to use ustack() here because we are in userspace (stack() would give us the kernel stack trace). Where is Firefox in this mess? libxul.so. This is the limit of my knowledge of Firefox internals and someone more knowledgeable could tell you more.

Your Turn

Do you use DTrace? Do you have some interesting war stories? Let me know in the comments!

DTrace: qsort use in Firefox

I’ve talked about OpenIndiana a bunch. I’ve mentioned several of its features. Let me tell you about my Wikipedia article: DTrace experiments from today. Inspired by Wikipedia article: Con Kolivas, I decided to see how Firefox uses the qsort C function.

First things first, let’s look at what the function signature looks like.

void qsort(void *base, size_t nel, size_t width,
           int (*compar)(const void *, const void *));

The second argument contains the number of elements.

Now, let’s take a look at DTrace. We want the pid provider, which lets us instrument a specific process. In my case, Firefox was pid 1069. pid1069:libc:qsort:entry is the name of the probe that will fire every time qsort in libc.so is called by Firefox (pid 1069). Let’s aggregate the second argument (the number of elements). To keep things sane, I used the llquantize function. It is a log-linear quantization function that was rather well explained by Bryan Cantrill. (Base 10 with buckets between zero and one million seemed reasonable enough.) Additionally, I wanted DTrace to give me the current histogram every minute — that’s why there is the tick-60sec probe.

# dtrace -n 'pid1069:libc:qsort:entry{@=llquantize(arg1, 10,0,6,20)} tick-60sec{printa(@)}'

...
  1  78738                      :tick-60sec 

           value  ------------- Distribution ------------- count    
             < 1 |                                         2        
               1 |                                         0        
               2 |                                         21       
               3 |                                         2        
               4 |@@@@                                     365      
               5 |                                         1        
               6 |@                                        132      
               7 |                                         0        
               8 |@@@@@@@@@@@@@@@@@@@@@                    1923     
               9 |                                         0        
              10 |@                                        135      
              15 |@@                                       194      
              20 |@                                        134      
              25 |                                         9        
              30 |@@@                                      246      
              35 |                                         31       
              40 |                                         8        
              45 |                                         0        
              50 |                                         0        
              55 |                                         10       
              60 |                                         1        
              65 |                                         10       
              70 |                                         39       
              75 |                                         2        
              80 |@                                        112      
              85 |@                                        56       
              90 |@                                        82       
              95 |                                         1        
             100 |@                                        132      
             150 |@                                        90       
             200 |                                         0        
             250 |                                         0        
             300 |                                         4        
             350 |                                         0        

Interesting! After several minutes of browsing various websites, we can see that Firefox really likes to sort 8-element arrays. (The value column is the bucket for the various array lengths. The count column specifies how many times there was a qsort call for each bucket.) Let’s dig a little deeper. Sorting 1 byte array elements is very different from sorting 1 MB elements. It would be really nice if we could break the histogram down into several histograms — one for each size. Well, guess what? DTrace lets you do that very easily.

Note that the command changed only a little. Now, in addition to looking at the second argument (the array length), DTrace breaks down the distribution based on the value of the third argument (the array element size). Since I visited different websites and Firefox does caching, the distribution of qsorts is a bit different — but it is still close enough.

# dtrace -n 'pid1069:libc:qsort:entry{@[arg2]=llquantize(arg1, 10,0,6,20)} tick-60sec{printa(@)}'

...
  4  78738                      :tick-60sec 
               52
           value  ------------- Distribution ------------- count    
               1 |                                         0        
               2 |@@@@@@@@@@@@@@@@@                        60       
               3 |@@                                       9        
               4 |@@@@@                                    17       
               5 |                                         0        
               6 |@@@@@@@@@@@@@@@                          55       
               7 |                                         0        
               8 |@                                        3        
               9 |                                         1        
              10 |                                         0        

                8
           value  ------------- Distribution ------------- count    
             < 1 |@@@@@@@@@@@@@                            2        
               1 |                                         0        
               2 |                                         0        
               3 |                                         0        
               4 |                                         0        
               5 |                                         0        
               6 |                                         0        
               7 |                                         0        
               8 |                                         0        
               9 |                                         0        
              10 |                                         0        
              15 |                                         0        
              20 |                                         0        
              25 |                                         0        
              30 |                                         0        
              35 |                                         0        
              40 |                                         0        
              45 |                                         0        
              50 |                                         0        
              55 |                                         0        
              60 |                                         0        
              65 |                                         0        
              70 |                                         0        
              75 |                                         0        
              80 |                                         0        
              85 |                                         0        
              90 |                                         0        
              95 |                                         0        
             100 |                                         0        
             150 |                                         0        
             200 |@@@@@@@@@@@@@@@@@@@@                     3        
             250 |                                         0        
             300 |@@@@@@@                                  1        
             350 |                                         0        

                4
           value  ------------- Distribution ------------- count    
             < 1 |                                         12       
               1 |                                         0        
               2 |                                         1        
               3 |                                         0        
               4 |@@@@@@@                                  1351     
               5 |                                         0        
               6 |@                                        247      
               7 |                                         0        
               8 |@@@@@@@@@                                1868     
               9 |                                         0        
              10 |@@@                                      594      
              15 |@@                                       422      
              20 |@                                        230      
              25 |                                         4        
              30 |@@@@@@                                   1193     
              35 |@@                                       466      
              40 |                                         57       
              45 |                                         63       
              50 |                                         1        
              55 |                                         18       
              60 |@                                        190      
              65 |@@                                       341      
              70 |@                                        207      
              75 |                                         2        
              80 |                                         56       
              85 |@                                        158      
              90 |                                         46       
              95 |                                         0        
             100 |@@                                       350      
             150 |@                                        206      
             200 |                                         3        
             250 |                                         10       
             300 |                                         8        
             350 |                                         0        
             400 |                                         0        
             450 |                                         0        
             500 |                                         0        
             550 |                                         0        
             600 |                                         0        
             650 |                                         0        
             700 |                                         1        
             750 |                                         10       
             800 |                                         0        
             850 |                                         0        
             900 |                                         0        
             950 |                                         0        
            1000 |                                         0        
            1500 |                                         0        
            2000 |                                         0        
            2500 |                                         0        
            3000 |                                         8        
            3500 |                                         0        

As you can see, there are now three histograms printed — that’s because DTrace saw 3 unique values of arg2. The first histogram is for 52-byte array element sorts. There weren’t many of those over the few minutes of browsing I did. The second is for 8-bytes elements — there are six of those total! The third distribution is where things get interesting. These are all the sorts of 4-byte array elements. Now we know that the large amount of 8-element sorts Firefox performs are on 4-byte element arrays. I wonder what that’s about. We also see that there were eight times that Firefox ended up sorting an array that had somewhere between 3000 and 3500 4-byte elements. Eeek!

DTrace is a really powerful tool. It lets you inspect the operation of a system with minimal disruption (the performance overhead is rather small). I hope to post more analyses of various software in the future.

I should add, this experiment was conducted with Firefox 3.6.12 on OpenIndiana 151a.

Powered by blahgd