Index: /trunk/psphot/doc/notes.txt =================================================================== --- /trunk/psphot/doc/notes.txt (revision 21163) +++ /trunk/psphot/doc/notes.txt (revision 21164) @@ -1,2 +1,194 @@ + +2009.01.24 + + Some results from the threading work below. these are all tests on + pikake using a sample GPC1 image. This set uses an optimized + build of psLib, psModules, and psphot. + +pikake: grep --color "built models" o4771g0244o.t?.opt.log +o4771g0244o.t0.opt.log: built models for 3156 objects: 0.696490 sec +o4771g0244o.t0.opt.log: built models for 1738 objects: 0.367092 sec +o4771g0244o.t1.opt.log: built models for 3150 objects: 0.746428 sec +o4771g0244o.t1.opt.log: built models for 1745 objects: 0.411406 sec +o4771g0244o.t2.opt.log: built models for 3152 objects: 0.412824 sec +o4771g0244o.t2.opt.log: built models for 1756 objects: 0.241859 sec +o4771g0244o.t3.opt.log: built models for 3151 objects: 0.341083 sec +o4771g0244o.t3.opt.log: built models for 1746 objects: 0.176361 sec +o4771g0244o.t4.opt.log: built models for 3159 objects: 0.235669 sec +o4771g0244o.t4.opt.log: built models for 1741 objects: 0.164474 sec +o4771g0244o.t5.opt.log: built models for 3155 objects: 0.286719 sec +o4771g0244o.t5.opt.log: built models for 1747 objects: 0.165341 sec + +pikake: grep --color "measure magnitudes" o4771g0244o.t?.opt.log +o4771g0244o.t0.opt.log: measure magnitudes : 4.080628 sec for 4895 objects (2191 with apertures) +o4771g0244o.t1.opt.log: measure magnitudes : 4.155192 sec for 4896 objects (2185 with apertures) +o4771g0244o.t2.opt.log: measure magnitudes : 2.174322 sec for 4909 objects (2190 with apertures) +o4771g0244o.t3.opt.log: measure magnitudes : 1.507431 sec for 4898 objects (2189 with apertures) +o4771g0244o.t4.opt.log: measure magnitudes : 1.174447 sec for 4901 objects (2191 with apertures) +o4771g0244o.t5.opt.log: measure magnitudes : 1.149875 sec for 4903 objects (2194 with apertures) + +pikake: grep --color "full-frame aperture" o4771g0244o.t?.opt.log +o4771g0244o.t0.opt.log: measure full-frame aperture residuals for 1977 sources: 1.681260 sec +o4771g0244o.t1.opt.log: measure full-frame aperture residuals for 1972 sources: 1.728578 sec +o4771g0244o.t2.opt.log: measure full-frame aperture residuals for 1980 sources: 0.929584 sec +o4771g0244o.t3.opt.log: measure full-frame aperture residuals for 1978 sources: 0.656556 sec +o4771g0244o.t4.opt.log: measure full-frame aperture residuals for 1977 sources: 0.507413 sec +o4771g0244o.t5.opt.log: measure full-frame aperture residuals for 1981 sources: 0.512259 sec + +pikake: grep --color "fit models" o4771g0244o.t?.opt.log +o4771g0244o.t0.opt.log: fit models: 4.623715 sec for 2011 objects (1904 psf, 45 ext, 62 failed, 1146 skipped) +o4771g0244o.t1.opt.log: fit models: 5.036680 sec for 2006 objects (1901 psf, 45 ext, 60 failed, 1145 skipped) +o4771g0244o.t2.opt.log: fit models: 3.507495 sec for 2014 objects (1912 psf, 44 ext, 58 failed, 1139 skipped) +o4771g0244o.t3.opt.log: fit models: 3.236495 sec for 2012 objects (1906 psf, 44 ext, 62 failed, 1140 skipped) +o4771g0244o.t4.opt.log: fit models: 3.929518 sec for 2013 objects (1906 psf, 44 ext, 63 failed, 1147 skipped) +o4771g0244o.t5.opt.log: fit models: 4.152286 sec for 2012 objects (1903 psf, 45 ext, 64 failed, 1144 skipped) + +pikake: grep failed o4771g0244o.t?.opt.log | grep --color "moments" +o4771g0244o.t0.opt.log: 3161 sources, 3147 moments, 14 failed: 1.288588 sec +o4771g0244o.t0.opt.log: 1738 sources, 1698 moments, 40 failed: 0.700303 sec +o4771g0244o.t1.opt.log: 3155 sources, 3142 moments, 13 failed: 1.329107 sec +o4771g0244o.t1.opt.log: 1745 sources, 1702 moments, 43 failed: 0.739017 sec +o4771g0244o.t2.opt.log: 3157 sources, 3144 moments, 13 failed: 0.717423 sec +o4771g0244o.t2.opt.log: 1756 sources, 1712 moments, 44 failed: 0.409145 sec +o4771g0244o.t3.opt.log: 3156 sources, 3142 moments, 14 failed: 0.510468 sec +o4771g0244o.t3.opt.log: 1746 sources, 1702 moments, 44 failed: 0.311198 sec +o4771g0244o.t4.opt.log: 3164 sources, 3150 moments, 14 failed: 0.412192 sec +o4771g0244o.t4.opt.log: 1741 sources, 1698 moments, 43 failed: 0.240172 sec +o4771g0244o.t5.opt.log: 3160 sources, 3144 moments, 16 failed: 0.418781 sec +o4771g0244o.t5.opt.log: 1747 sources, 1701 moments, 46 failed: 0.244808 sec + +pikake: grep --color "complete psphot" o4771g0244o.t?.opt.log +o4771g0244o.t0.opt.log: complete psphot run: 38.044034 sec +o4771g0244o.t1.opt.log: complete psphot run: 39.039324 sec +o4771g0244o.t2.opt.log: complete psphot run: 28.565228 sec +o4771g0244o.t3.opt.log: complete psphot run: 25.380312 sec +o4771g0244o.t4.opt.log: complete psphot run: 24.606107 sec +o4771g0244o.t5.opt.log: complete psphot run: 24.796387 sec + + Some results from the threading work below. these are all tests on + pikake using a sample GPC1 image. This set uses an unoptimized + build of psphot (though psLib may be optmized). + +pikake: grep --color "built models" o4771g0244o.t?.no-opt.log +o4771g0244o.t0.no-opt.log: built models for 3160 objects: 0.997456 sec +o4771g0244o.t0.no-opt.log: built models for 1725 objects: 0.523033 sec +o4771g0244o.t1.no-opt.log: built models for 3154 objects: 1.031943 sec +o4771g0244o.t1.no-opt.log: built models for 1725 objects: 0.562166 sec +o4771g0244o.t2.no-opt.log: built models for 3156 objects: 0.563504 sec +o4771g0244o.t2.no-opt.log: built models for 1729 objects: 0.311835 sec +o4771g0244o.t3.no-opt.log: built models for 3155 objects: 0.399958 sec +o4771g0244o.t3.no-opt.log: built models for 1728 objects: 0.235203 sec +o4771g0244o.t4.no-opt.log: built models for 3153 objects: 0.329366 sec +o4771g0244o.t4.no-opt.log: built models for 1726 objects: 0.192076 sec +o4771g0244o.t5.no-opt.log: built models for 3155 objects: 0.408434 sec +o4771g0244o.t5.no-opt.log: built models for 1734 objects: 0.198095 sec + +pikake: grep --color "measure magnitudes" o4771g0244o.t?.no-opt.log +o4771g0244o.t0.no-opt.log: measure magnitudes : 5.939663 sec for 4886 objects (2187 with apertures) +o4771g0244o.t1.no-opt.log: measure magnitudes : 6.041825 sec for 4880 objects (2189 with apertures) +o4771g0244o.t2.no-opt.log: measure magnitudes : 3.126765 sec for 4886 objects (2192 with apertures) +o4771g0244o.t3.no-opt.log: measure magnitudes : 2.158470 sec for 4884 objects (2188 with apertures) +o4771g0244o.t4.no-opt.log: measure magnitudes : 1.756856 sec for 4880 objects (2192 with apertures) +o4771g0244o.t5.no-opt.log: measure magnitudes : 1.697331 sec for 4890 objects (2188 with apertures) + +pikake: grep --color "full-frame aperture" o4771g0244o.t?.no-opt.log +o4771g0244o.t0.no-opt.log: measure full-frame aperture residuals for 1976 sources: 2.869795 sec +o4771g0244o.t1.no-opt.log: measure full-frame aperture residuals for 1973 sources: 2.908194 sec +o4771g0244o.t2.no-opt.log: measure full-frame aperture residuals for 1977 sources: 1.545140 sec +o4771g0244o.t3.no-opt.log: measure full-frame aperture residuals for 1977 sources: 1.091451 sec +o4771g0244o.t4.no-opt.log: measure full-frame aperture residuals for 1976 sources: 0.857477 sec +o4771g0244o.t5.no-opt.log: measure full-frame aperture residuals for 1979 sources: 0.860652 sec + +pikake: grep --color "fit models" o4771g0244o.t?.no-opt.log +o4771g0244o.t0.no-opt.log: fit models: 7.771925 sec for 2011 objects (1902 psf, 45 ext, 64 failed, 1150 skipped) +o4771g0244o.t1.no-opt.log: fit models: 8.053570 sec for 2010 objects (1904 psf, 45 ext, 61 failed, 1145 skipped) +o4771g0244o.t2.no-opt.log: fit models: 5.063026 sec for 2009 objects (1904 psf, 44 ext, 61 failed, 1148 skipped) +o4771g0244o.t3.no-opt.log: fit models: 4.314687 sec for 2012 objects (1905 psf, 44 ext, 63 failed, 1144 skipped) +o4771g0244o.t4.no-opt.log: fit models: 4.147600 sec for 2009 objects (1904 psf, 44 ext, 61 failed, 1145 skipped) +o4771g0244o.t5.no-opt.log: fit models: 4.207860 sec for 2012 objects (1906 psf, 44 ext, 62 failed, 1144 skipped) + +pikake: grep failed o4771g0244o.t?.no-opt.log | grep --color "moments" +o4771g0244o.t0.no-opt.log: 3165 sources, 3151 moments, 14 failed: 2.867193 sec +o4771g0244o.t0.no-opt.log: 1725 sources, 1681 moments, 44 failed: 1.513526 sec +o4771g0244o.t1.no-opt.log: 3159 sources, 3146 moments, 13 failed: 2.966456 sec +o4771g0244o.t1.no-opt.log: 1725 sources, 1685 moments, 40 failed: 1.568208 sec +o4771g0244o.t2.no-opt.log: 3161 sources, 3148 moments, 13 failed: 1.590746 sec +o4771g0244o.t2.no-opt.log: 1729 sources, 1687 moments, 42 failed: 0.823426 sec +o4771g0244o.t3.no-opt.log: 3160 sources, 3146 moments, 14 failed: 1.068936 sec +o4771g0244o.t3.no-opt.log: 1728 sources, 1684 moments, 44 failed: 0.603041 sec +o4771g0244o.t4.no-opt.log: 3158 sources, 3144 moments, 14 failed: 0.869741 sec +o4771g0244o.t4.no-opt.log: 1726 sources, 1685 moments, 41 failed: 0.505545 sec +o4771g0244o.t5.no-opt.log: 3160 sources, 3146 moments, 14 failed: 0.830094 sec +o4771g0244o.t5.no-opt.log: 1734 sources, 1695 moments, 39 failed: 0.469828 sec + +pikake: grep --color "complete psphot" o4771g0244o.t?.no-opt.log +o4771g0244o.t0.no-opt.log: complete psphot run: 70.375518 sec +o4771g0244o.t1.no-opt.log: complete psphot run: 71.167205 sec +o4771g0244o.t2.no-opt.log: complete psphot run: 51.237604 sec +o4771g0244o.t3.no-opt.log: complete psphot run: 44.195015 sec +o4771g0244o.t4.no-opt.log: complete psphot run: 41.782608 sec +o4771g0244o.t5.no-opt.log: complete psphot run: 42.483942 sec + +Not bad: almost a factor of 2 overall. psphotMagnitudes, +psphotApResid, psphotSourceStats all get nearly the max improvement. +psphotBlendFit seems to be saturating. There are a lot of allocs in +the main functions: pmSourceFitModel and pmSourceFitSet, which are +probably blocking each other. + +2009.01.22 + + working on more psphot threading. So far, I have threaded code for: + + * psphotGuessModel (DONE) : not working so well just yet (see + below). Late Update: in recent tests, the result below may have + been caused by the unoptimized psLib. + + here are functions for which a modest gain can be realized and which + should be easy to thread: + + * psphotMagnitudes (DONE) + + ** this function uses psImageShiftMask to interpolate the source + flux to compensate for fractional pixel offsets. This function + requires a call to psImageAlloc and a subsequent call to + psFree. This probably will make the threading + inefficient. However, it is not clear we need to perform this + interpolation for all sources: the correction is probably only + signficant compared to the errors for the brighter sources. + + ** psImageShiftMask gratuitously calls psImageInterpolationAlloc; + perhaps it should accept this as an argument, or perhaps this + function should be re-examined. + + * psphotApResid (DONE) + + * this function is basically calling pmSourceMagnitudes, so + suffers the same issues as psphotMagnitudes + + * psphotFindDetections (footprints) (fairly tricky, actually) + + ** need to examine the steps in the function. it is not obvious + yet what needs to be improved. + + * psphotBlendFit (DONE) + + ** this one will be a little tricky: this function currently + extends the source array to add new sources detected as part of + psphotFitBlob. I would need to have a way of saving these from + each thread, then joining them back together at the end. + + * psphotSourceStats (DONE) + + ** this one includes the allocs to generate the source pixels, but + could be split into two steps: 1) generate the complete array + of sources; 2) measure the sky, sky variance, and moments. + + Otherwise, this function should be easy: no other allocs or + frees, i think. + + * psphotChoosePSF : + + ** need to use the grid technique for the pmPSFtryModel which does + the source fitting 2008.10.26 Index: /trunk/psphot/doc/timing.v4.txt =================================================================== --- /trunk/psphot/doc/timing.v4.txt (revision 21164) +++ /trunk/psphot/doc/timing.v4.txt (revision 21164) @@ -0,0 +1,105 @@ + +timing on ipp008 *unoptimized* : + +06 : 0.003753 sec : psphotDeblendSatstars +22 : 0.005017 sec : psphotRoughClass +08 : 0.026426 sec : psphotRoughClass +07 : 0.038862 sec : psphotBasicDeblend +24 : 0.215222 sec : psphotReplaceAllSources +16 : 0.217380 sec : psphotAddNoise +20 : 0.217596 sec : psphotSubNoise +14 : 0.233694 sec : psphotReplaceAllSources +21 : 0.366264 sec : psphotSourceStats +29 : 0.435839 sec : psphotSkyReplace +23 : 0.572896 sec : psphotGuessModels +01 : 0.650438 sec : psphotSubtractBackground +03 : 0.711178 sec : psphotFindDetections (peaks) +18 : 0.735544 sec : psphotFindDetections (peaks) +12 : 0.775521 sec : psphotSourceSize +26 : 0.777268 sec : psphotSourceSize +10 : 1.154189 sec : psphotGuessModels +00 : 1.589681 sec : psphotModelBackground +11 : 1.724959 sec : psphotFitSourcesLinear +15 : 1.853397 sec : psphotFitSourcesLinear +25 : 2.392153 sec : psphotFitSourcesLinear +04 : 2.949543 sec : psphotFindDetections (footprints) +27 : 3.238548 sec : psphotApResid +05 : 3.339873 sec : psphotSourceStats +19 : 6.059952 sec : psphotFindDetections (footprints) +28 : 6.948404 sec : psphotMagnitudes +13 : 8.305355 sec : psphotBlendFit +09 : 11.317836 sec : psphotChoosePSF +17 : 16.353613 sec : psphotFindDetections (smooth) +02 : 16.857492 sec : psphotFindDetections (smooth) + +complete psphot run: 95.722628 sec + +timing on ipp008 *optimized* : + +06 : 0.001866 sec : psphotDeblendSatstars +22 : 0.003328 sec : psphotRoughClass +08 : 0.016906 sec : psphotRoughClass +07 : 0.020168 sec : psphotBasicDeblend +24 : 0.068499 sec : psphotReplaceAllSources +16 : 0.069682 sec : psphotAddNoise +20 : 0.072236 sec : psphotSubNoise +14 : 0.087402 sec : psphotReplaceAllSources +29 : 0.093756 sec : psphotSkyReplace +21 : 0.151939 sec : psphotSourceStats +03 : 0.203476 sec : psphotFindDetections (peaks) +18 : 0.210160 sec : psphotFindDetections (peaks) +01 : 0.242636 sec : psphotSubtractBackground +23 : 0.366264 sec : psphotGuessModels +11 : 0.506939 sec : psphotFitSourcesLinear +15 : 0.539799 sec : psphotFitSourcesLinear +12 : 0.542919 sec : psphotSourceSize +26 : 0.550523 sec : psphotSourceSize +25 : 0.724011 sec : psphotFitSourcesLinear +00 : 0.777303 sec : psphotModelBackground +10 : 0.780365 sec : psphotGuessModels +05 : 1.332723 sec : psphotSourceStats +27 : 1.728141 sec : psphotApResid +04 : 2.009312 sec : psphotFindDetections (footprints) +28 : 4.153111 sec : psphotMagnitudes +13 : 4.527469 sec : psphotBlendFit +19 : 4.538490 sec : psphotFindDetections (footprints) +09 : 5.504840 sec : psphotChoosePSF +02 : 7.316287 sec : psphotFindDetections (smooth) +17 : 7.367393 sec : psphotFindDetections (smooth) + +complete psphot run: 49.315078 sec + +timing on ipp008 *threaded* : currently (2009.01.22, 11:48 HST) only affects psphotFindDetections (smooth) + +06 : 0.001843 sec : psphotDeblendSatstars +22 : 0.003371 sec : psphotRoughClass +08 : 0.016955 sec : psphotRoughClass +07 : 0.020379 sec : psphotBasicDeblend +16 : 0.069632 sec : psphotAddNoise +20 : 0.072203 sec : psphotSubNoise +24 : 0.085762 sec : psphotReplaceAllSources +14 : 0.087238 sec : psphotReplaceAllSources +29 : 0.093757 sec : psphotSkyReplace +21 : 0.153800 sec : psphotSourceStats +03 : 0.214963 sec : psphotFindDetections (peaks) +18 : 0.232736 sec : psphotFindDetections (peaks) +01 : 0.248905 sec : psphotSubtractBackground +23 : 0.458357 sec : psphotGuessModels +26 : 0.510125 sec : psphotSourceSize +11 : 0.513049 sec : psphotFitSourcesLinear +15 : 0.538855 sec : psphotFitSourcesLinear +12 : 0.654045 sec : psphotSourceSize +00 : 0.774769 sec : psphotModelBackground +25 : 1.024339 sec : psphotFitSourcesLinear +05 : 1.329678 sec : psphotSourceStats +10 : 1.347421 sec : psphotGuessModels +04 : 2.043960 sec : psphotFindDetections (footprints) +27 : 2.075074 sec : psphotApResid +02 : 2.824503 sec : psphotFindDetections (smooth) ** threaded ** +17 : 2.986548 sec : psphotFindDetections (smooth) ** threaded ** +28 : 4.184633 sec : psphotMagnitudes +19 : 4.323182 sec : psphotFindDetections (footprints) +09 : 5.611547 sec : psphotChoosePSF +13 : 5.620031 sec : psphotBlendFit + +complete psphot run: 41.861923 sec