I did some investigation to query_iterator, and most of the slowdown is caused by functools.wraps. When used in nested context @wraps seems to be really slow. For example, try this with and without @wraps: http://pastebin.com/5ejAKuKd
Should we care about this slowdown? Can we do without @wraps? My understanding is that @wraps gives you __name__, __module__ and __doc__ which are easy to do manually. In addition it gives introspection the right args and kwargs for the wrapped function (so that IDEs see it correctly). This will be a lot harder to do manually, and doing so will likely result in similar slowdown. The biggest hit case is if somebody is looping over a raw SQL queryset with .fetchone(). This use case will be severely punished. Even .execute(); .fetchmany() has a 1.5x slowdown (the benchmark is this one: https://github.com/django/djangobench/commit/94fc28d99f95c65d26d0fad8af44e46c49282220 - simple SELECT + fetchall() for the ten returned rows. I have created a patch that removes the usage of @wraps and makes connection.wrap_database_errors a cached_property. The cached_property should be safe as the context manager created by wrap_database_errors is stateless. This patch gets rid of the slowdown (1.00-1.05x slower in repeated runs for raw_sql benchmark). With just removed @wraps the slowdown is 1.1x. The patch is here: https://github.com/akaariai/django/commit/eafc373c16350abe51c565c8aefbe36cabf5219e Should I apply the patch, and should I apply it to stable/1.6.x, too? Removal of @wraps is really low risk, usage of @cached_property is also low risk, but not as low as removal of @wraps. - Anssi On Saturday, September 14, 2013 9:21:43 PM UTC+3, Anssi Kääriäinen wrote: > > I just ran djangobench comparing 1.5 to 1.6. The biggest thing seems to be > form_create bechmark, the average is 15x slower. But for some reason the > minimum runtime is just 1.16x slower. This seems a bit strange. This might > be worth more investigation. > > Otherwise there doens't seem to be anything alarming going on. Most ORM > operations are slightly faster (likely due to __deepcopy__ removal). > > There are a couple of individual benchmarks worth mentioning... > url_reverse and query_iterator are slower (1.15x and 1.12x respectively). > The default_middleware and qs_filter_chaining benchmarks have gained a lot > (2.0x and 3.1x respectively). model_save_existing/model_save_new are faster > (2x+), but model_creation is slightly slower. I suspect there is something > going on with connection creation or transactions for model_creation, after > all model_creation is a convenience method for model.__init__ + > model_save_new which both aren't slower. > > What else? url_reverse and template compliation under i18n slightly > slower. For the rest of benchmarks, see below. > > Running 'default_middleware' benchmark ... > Min: 0.001260 -> 0.000554: 2.2755x faster > Avg: 0.001389 -> 0.000681: 2.0394x faster > Significant (t=8.222155) > Stddev: 0.00037 -> 0.00048: 1.2843x larger (N = 50) > > Running 'form_clean' benchmark ... > Min: 0.000042 -> 0.000042: no change > Avg: 0.000049 -> 0.000043: 1.1341x faster > Not significant > Stddev: 0.00004 -> 0.00001: 6.6718x smaller (N = 50) > > Running 'form_create' benchmark ... > Min: 0.000085 -> 0.000099: 1.1657x slower > Avg: 0.000088 -> 0.001396: 15.8410x slower > Not significant > Stddev: 0.00001 -> 0.00916: 783.3314x larger (N = 50) > > Running 'l10n_render' benchmark ... > Min: 0.011702 -> 0.014151: 1.2093x slower > Avg: 0.012200 -> 0.014846: 1.2169x slower > Significant (t=-4.824893) > Stddev: 0.00233 -> 0.00310: 1.3311x larger (N = 50) > > Running 'model_creation' benchmark ... > Min: 0.000311 -> 0.000400: 1.2860x slower > Avg: 0.000336 -> 0.000432: 1.2840x slower > Significant (t=-2.799691) > Stddev: 0.00015 -> 0.00019: 1.2751x larger (N = 50) > > Running 'model_delete' benchmark ... > Min: 0.000407 -> 0.000468: 1.1500x slower > Avg: 0.000423 -> 0.000484: 1.1440x slower > Significant (t=-7.131460) > Stddev: 0.00005 -> 0.00004: 1.1807x smaller (N = 50) > > Running 'model_save_existing' benchmark ... > Min: 0.062923 -> 0.021829: 2.8826x faster > Avg: 0.063206 -> 0.022001: 2.8729x faster > Significant (t=793.026302) > Stddev: 0.00034 -> 0.00014: 2.3570x smaller (N = 50) > > Running 'model_save_new' benchmark ... > Min: 0.041341 -> 0.021819: 1.8947x faster > Avg: 0.063127 -> 0.022379: 2.8208x faster > Significant (t=76.086085) > Stddev: 0.00344 -> 0.00158: 2.1770x smaller (N = 50) > > Running 'multi_value_dict' benchmark ... > Min: 0.000083 -> 0.000085: 1.0230x slower > Avg: 0.000165 -> 0.000168: 1.0164x slower > Not significant > Stddev: 0.00005 -> 0.00005: 1.0339x larger (N = 50) > > Running 'qs_filter_chaining' benchmark ... > Min: 0.004264 -> 0.001362: 3.1311x faster > Avg: 0.004311 -> 0.001391: 3.0996x faster > Significant (t=170.435257) > Stddev: 0.00010 -> 0.00007: 1.2953x smaller (N = 50) > > Running 'query_aggregate' benchmark ... > Min: 0.000467 -> 0.000412: 1.1331x faster > Avg: 0.000479 -> 0.000423: 1.1322x faster > Significant (t=11.625112) > Stddev: 0.00002 -> 0.00002: 1.0048x smaller (N = 50) > > Running 'query_all' benchmark ... > Min: 0.047256 -> 0.043987: 1.0743x faster > Avg: 0.049713 -> 0.046489: 1.0693x faster > Significant (t=3.604195) > Stddev: 0.00423 -> 0.00470: 1.1104x larger (N = 50) > > Running 'query_all_multifield' benchmark ... > Min: 0.103770 -> 0.099138: 1.0467x faster > Avg: 0.107616 -> 0.103382: 1.0409x faster > Significant (t=4.033836) > Stddev: 0.00495 -> 0.00553: 1.1182x larger (N = 50) > > Running 'query_annotate' benchmark ... > Min: 0.000987 -> 0.000865: 1.1408x faster > Avg: 0.001006 -> 0.000881: 1.1417x faster > Significant (t=17.891371) > Stddev: 0.00004 -> 0.00003: 1.2235x smaller (N = 50) > > Running 'query_complex_filter' benchmark ... > Min: 0.000308 -> 0.000218: 1.4136x faster > Avg: 0.000317 -> 0.000223: 1.4175x faster > Significant (t=27.463980) > Stddev: 0.00002 -> 0.00001: 1.3219x smaller (N = 50) > > Running 'query_count' benchmark ... > Min: 0.000392 -> 0.000339: 1.1561x faster > Avg: 0.000401 -> 0.000347: 1.1571x faster > Significant (t=13.345028) > Stddev: 0.00002 -> 0.00002: 1.0469x smaller (N = 50) > > Running 'query_dates' benchmark ... > Min: 0.001032 -> 0.000884: 1.1678x faster > Avg: 0.001055 -> 0.000900: 1.1730x faster > Significant (t=21.848869) > Stddev: 0.00004 -> 0.00003: 1.1197x smaller (N = 50) > > Running 'query_delete' benchmark ... > Min: 0.000475 -> 0.000425: 1.1178x faster > Avg: 0.000530 -> 0.000436: 1.2153x faster > Significant (t=2.191750) > Stddev: 0.00030 -> 0.00004: 8.3495x smaller (N = 50) > > Running 'query_delete_related' benchmark ... > Min: 0.000565 -> 0.000550: 1.0278x faster > Avg: 0.000623 -> 0.000605: 1.0289x faster > Not significant > Stddev: 0.00034 -> 0.00031: 1.0908x smaller (N = 50) > > Running 'query_distinct' benchmark ... > Min: 0.000634 -> 0.000570: 1.1121x faster > Avg: 0.000643 -> 0.000584: 1.1016x faster > Significant (t=12.118505) > Stddev: 0.00002 -> 0.00003: 1.3095x larger (N = 50) > > Running 'query_exclude' benchmark ... > Min: 0.000863 -> 0.000788: 1.0950x faster > Avg: 0.000880 -> 0.000803: 1.0953x faster > Significant (t=13.046264) > Stddev: 0.00003 -> 0.00003: 1.0791x larger (N = 50) > > Running 'query_exists' benchmark ... > Min: 0.001760 -> 0.001236: 1.4240x faster > Avg: 0.001787 -> 0.001255: 1.4232x faster > Significant (t=85.893459) > Stddev: 0.00003 -> 0.00003: 1.0897x smaller (N = 50) > > Running 'query_filter' benchmark ... > Min: 0.000670 -> 0.000638: 1.0501x faster > Avg: 0.000684 -> 0.000652: 1.0480x faster > Significant (t=5.370576) > Stddev: 0.00003 -> 0.00003: 1.0148x larger (N = 50) > > Running 'query_get' benchmark ... > Min: 0.051161 -> 0.040722: 1.2564x faster > Avg: 0.051703 -> 0.040987: 1.2614x faster > Significant (t=67.436357) > Stddev: 0.00111 -> 0.00016: 6.8096x smaller (N = 50) > > Running 'query_get_or_create' benchmark ... > Min: 0.002207 -> 0.001794: 1.2303x faster > Avg: 0.002301 -> 0.001860: 1.2370x faster > Significant (t=9.259437) > Stddev: 0.00024 -> 0.00023: 1.0271x smaller (N = 50) > > Running 'query_in_bulk' benchmark ... > Min: 0.001014 -> 0.000756: 1.3412x faster > Avg: 0.001036 -> 0.000770: 1.3464x faster > Significant (t=39.238702) > Stddev: 0.00004 -> 0.00003: 1.2649x smaller (N = 50) > > Running 'query_iterator' benchmark ... > Min: 0.000448 -> 0.000497: 1.1096x slower > Avg: 0.000458 -> 0.000508: 1.1100x slower > Significant (t=-11.870806) > Stddev: 0.00002 -> 0.00002: 1.0347x smaller (N = 50) > > Running 'query_latest' benchmark ... > Min: 0.000720 -> 0.000602: 1.1960x faster > Avg: 0.000735 -> 0.000616: 1.1929x faster > Significant (t=18.266073) > Stddev: 0.00003 -> 0.00003: 1.1321x larger (N = 50) > > Running 'query_none' benchmark ... > Min: 0.000044 -> 0.000262: 5.9674x slower > Avg: 0.000047 -> 0.000290: 6.1906x slower > Significant (t=-12.805744) > Stddev: 0.00001 -> 0.00013: 14.5148x larger (N = 50) > > Running 'query_order_by' benchmark ... > Min: 0.000694 -> 0.000629: 1.1035x faster > Avg: 0.000710 -> 0.000643: 1.1034x faster > Significant (t=12.579731) > Stddev: 0.00003 -> 0.00003: 1.0503x larger (N = 50) > > Running 'query_prefetch_related' benchmark ... > Min: 0.157446 -> 0.139648: 1.1274x faster > Avg: 0.159709 -> 0.141490: 1.1288x faster > Significant (t=25.953202) > Stddev: 0.00345 -> 0.00357: 1.0323x larger (N = 50) > > Running 'query_raw' benchmark ... > Min: 0.035057 -> 0.033581: 1.0440x faster > Avg: 0.036173 -> 0.034579: 1.0461x faster > Significant (t=3.157050) > Stddev: 0.00245 -> 0.00259: 1.0578x larger (N = 50) > > Running 'query_raw_deferred' benchmark ... > Min: 0.034473 -> 0.032813: 1.0506x faster > Avg: 0.035510 -> 0.033668: 1.0547x faster > Significant (t=4.009721) > Stddev: 0.00221 -> 0.00238: 1.0801x larger (N = 50) > > Running 'query_select_related' benchmark ... > Min: 0.101298 -> 0.092818: 1.0914x faster > Avg: 0.103418 -> 0.095025: 1.0883x faster > Significant (t=10.835818) > Stddev: 0.00374 -> 0.00400: 1.0704x larger (N = 50) > > Running 'query_update' benchmark ... > Min: 0.000473 -> 0.000415: 1.1396x faster > Avg: 0.000486 -> 0.000426: 1.1406x faster > Significant (t=13.803712) > Stddev: 0.00002 -> 0.00002: 1.1961x smaller (N = 50) > > Running 'query_values' benchmark ... > Min: 0.000535 -> 0.000479: 1.1170x faster > Avg: 0.000550 -> 0.000491: 1.1195x faster > Significant (t=9.839351) > Stddev: 0.00003 -> 0.00003: 1.0529x smaller (N = 50) > > Running 'query_values_list' benchmark ... > Min: 0.000507 -> 0.000457: 1.1096x faster > Avg: 0.000519 -> 0.000465: 1.1159x faster > Significant (t=13.620094) > Stddev: 0.00002 -> 0.00002: 1.2072x smaller (N = 50) > > Running 'startup' benchmark ... > 0.166763 -> 0.309053: 1.8532x slower > > Running 'template_compilation' benchmark ... > Min: 0.000980 -> 0.000998: 1.0182x slower > Avg: 0.001702 -> 0.001729: 1.0162x slower > Not significant > Stddev: 0.00498 -> 0.00507: 1.0169x larger (N = 50) > > Running 'template_render' benchmark ... > Min: 0.018177 -> 0.019062: 1.0487x slower > Avg: 0.018609 -> 0.019538: 1.0499x slower > Significant (t=-2.514891) > Stddev: 0.00183 -> 0.00187: 1.0232x larger (N = 50) > > Running 'template_render_simple' benchmark ... > Min: 0.000163 -> 0.000180: 1.1054x slower > Avg: 0.000874 -> 0.000894: 1.0230x slower > Not significant > Stddev: 0.00500 -> 0.00503: 1.0045x larger (N = 50) > > Running 'url_resolve' benchmark ... > Min: 0.026218 -> 0.025550: 1.0261x faster > Avg: 0.026641 -> 0.025782: 1.0333x faster > Significant (t=7.810852) > Stddev: 0.00067 -> 0.00040: 1.6905x smaller (N = 50) > > Running 'url_resolve_flat' benchmark ... > Min: 0.406173 -> 0.417229: 1.0272x slower > Avg: 0.408317 -> 0.421851: 1.0331x slower > Significant (t=-10.327930) > Stddev: 0.00627 -> 0.00682: 1.0878x larger (N = 50) > > Running 'url_resolve_flat_i18n_off' benchmark ... > Min: 0.530959 -> 0.532872: 1.0036x slower > Avg: 0.533534 -> 0.540590: 1.0132x slower > Significant (t=-4.240113) > Stddev: 0.00627 -> 0.00995: 1.5865x larger (N = 50) > > Running 'url_resolve_nested' benchmark ... > Min: 0.000155 -> 0.000151: 1.0269x faster > Avg: 0.000472 -> 0.000477: 1.0106x slower > Not significant > Stddev: 0.00221 -> 0.00227: 1.0274x larger (N = 50) > > Running 'url_reverse' benchmark ... > Min: 0.000385 -> 0.000481: 1.2497x slower > Avg: 0.000490 -> 0.000579: 1.1807x slower > Not significant > Stddev: 0.00064 -> 0.00063: 1.0144x smaller (N = 50) > -- You received this message because you are subscribed to the Google Groups "Django developers" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To post to this group, send email to [email protected]. Visit this group at http://groups.google.com/group/django-developers. For more options, visit https://groups.google.com/groups/opt_out.
