Tk performance puzzle

[timholy]

In ImageView, I have an application where I'm painting a 5-megapixel surface in a loop. It plays more slowly than I'd like under these circumstance. I noticed that if I zoom in on a smaller region---keeping the size of the window constant---that it plays much faster. I therefore assumed that the bottleneck was the fill operation. However, profiling suggests this is not the case, and that Tk.update() is the main bottleneck. For mysterious reasons, the time required for Tk.update() seems to vary with the size of the source that is painted to the canvas, even though I would have guessed that Tk.update would have no way of "knowing" that information because only the canvas should matter.

So, here's a systematic test. The code in this gist tests 3 operations---Cairo.fill, Tk.reveal, and Tk.update---for sources and canvases of different sizes. You can ignore the normalization part, here I'm just showing the raw timings.

Results:

paintarea looks like this (repeated for each column):
9-element Float64 Array:
    400.0  
   4000.0  
  40000.0  
   4000.0  
  40000.0  
 400000.0  
  40000.0  
 400000.0  
      4.0e6

winarea looks like this (repeated for each row):
1x9 Float64 Array:
 400.0  4000.0  40000.0  4000.0  40000.0  400000.0  40000.0  400000.0  4.0e6

julia> reshape(tfill, (9,9))
9x9 Float64 Array:
 0.00245289  0.0018184   0.00190354  0.0018275   0.0017293   0.00170003  0.00204117  0.00195058  0.00217543
 0.00239578  0.00318355  0.00288343  0.00309047  0.00269057  0.00318406  0.00255513  0.00279306  0.00383765
 0.00462529  0.00584485  0.00529055  0.00472924  0.00471452  0.0065624   0.00628025  0.00629306  0.00752696
 0.0025594   0.00311649  0.00291305  0.00172498  0.00290865  0.00335312  0.0030211   0.0034887   0.00371312
 0.00590883  0.00521956  0.00677782  0.005023    0.00318307  0.00713736  0.00521244  0.00680339  0.00761565
 0.0518323   0.0536135   0.0521766   0.0520546   0.0528012   0.0563673   0.0559326   0.057972    0.0575578 
 0.00596179  0.00614094  0.00720646  0.00677127  0.00563481  0.00856668  0.00696773  0.00828367  0.00794681
 0.0522692   0.0530637   0.0531833   0.0526137   0.0529721   0.0566752   0.0540204   0.0586045   0.0591545 
 0.629912    0.636078    0.623166    0.625815    0.630078    0.6572      0.626554    0.684176    0.766557

julia> reshape(treveal, (9,9))
9x9 Float64 Array:
 0.0132271   0.00943789  0.00905099  0.00870083  0.0092333   0.00931332  0.0111473   0.00973364  0.0142216
 0.00814719  0.00972981  0.0108839   0.0124309   0.0125025   0.00964868  0.008771    0.00905754  0.0109809
 0.0101579   0.0105036   0.00936286  0.00908874  0.00963928  0.0180162   0.0134028   0.0117307   0.0168576
 0.0083246   0.00965364  0.0131163   0.0143147   0.011118    0.0104047   0.00966678  0.0110059   0.0122708
 0.0119933   0.00934052  0.01202     0.00985168  0.00943573  0.0154633   0.0119803   0.0134146   0.0186537
 0.0207188   0.0250156   0.0196513   0.0236574   0.0206701   0.0235087   0.0247588   0.0295777   0.0208007
 0.0103966   0.00920776  0.0142922   0.0104327   0.010021    0.0130901   0.0131545   0.0129084   0.0117035
 0.027712    0.0220468   0.0226839   0.0278794   0.0209326   0.0228339   0.0213186   0.0214724   0.0261472
 0.0294226   0.044306    0.0447171   0.0332779   0.0391952   0.0385551   0.0293824   0.0346828   0.0348237

julia> reshape(tupdate, (9,9))
9x9 Float64 Array:
 0.0456249  0.082689   0.0910697  0.104548   0.0703653  0.102934  0.071009   0.110762   0.671718
 0.0500649  0.0821391  0.0656425  0.0714468  0.075207   0.126673  0.0722175  0.0878375  0.729297
 0.0659795  0.100264   0.0763811  0.065171   0.0756814  0.188756  0.101253   0.113759   0.683277
 0.05096    0.068492   0.072321   0.0591601  0.0647436  0.210691  0.0744623  0.146036   0.486776
 0.0779399  0.089597   0.119075   0.0653394  0.0578468  0.181642  0.0864316  0.149122   0.688707
 0.255617   0.265621   0.251711   0.265452   0.290863   0.287773  0.303016   0.304087   0.67087 
 0.0893102  0.0964651  0.0957275  0.102411   0.0803975  0.206583  0.0944839  0.154907   0.558618
 0.288977   0.294936   0.329803   0.296259   0.315333   0.347745  0.313739   0.309785   0.660055
 1.50423    1.46713    1.46059    1.508      1.47422    1.51676   1.4846     1.55611    1.68278

Interpretation:

• If one discards the smallest source, the fill operation very quickly settles into scaling with the source area. This is as I would expect.
• reveal seems approximately constant-time
• update depends more strongly on the source area than the canvas size, and undergoes a fairly catastrophic loss of performance for the largest source areas.

This last result makes absolutely no sense to me. One point worth noting is that tupdate is always larger than tfill, but that the time difference is not constant (which might be predicted if there were asynchronous operations happening). Does anyone else understand?