Zrychlit generate_prod_data
Opened this issue · 8 comments
Aktualne generovanie produkcnych dat trva asi 8 hodin. Bolo by super to skratit na 2-3 hodiny, nech to moze bez problemov bezat kazdu noc.
Na koniec prikladam vypis z profilera. Je jasne, ze najviac stracame cas komplikovanou manipulaciou stringov pre normalizaciu kazdej adresu (co je skoro pre kazdy novy riadok hociakej tabulky).
Teda konkretne je podla mna problem, ze pre kazdu adresu najskor vygenerujeme vela klucov (s vela regexp a string operaciami)
- keys = self.GetKeysForAddress(address)
a nasledne cez ne postupne iterujeme az kym nenajdeme match v cache. - vid kod v LookupKeysInCache(keys)
Vela by sme usetril kebyze generujeme kluce az on-demand (v relativne rozumnom poradi). Potom, ak by napriklad 3. z 15. klucov matchol tak by sme zrychlili vsetko 5 nasobne ...
Assignujem zatial Danovi, ale kebyze sa chce na to pozriet niekto iny, tak si to assignite sebe ;-)
Da sa to testovat tak, ze potom ako user datautils spustite:
python -m cProfile -s time generate_prod_data.py
a porovnate na kolko sa to zlepsilo oproti vystupu dole.
48501377 function calls (48499968 primitive calls) in 642.895 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
406050 71.647 0.000 507.320 0.001 geocoder.py:75(GetKeysForAddress)
4307483 71.185 0.000 117.841 0.000 geocoder.py:70(NormalizeAddress)
3295675 60.605 0.000 153.514 0.000 re.py:143(search)
8706388 50.816 0.000 50.816 0.000 {method 'replace' of 'str' objects}
3295741 50.706 0.000 69.846 0.000 re.py:230(_compile)
8928 35.524 0.004 35.647 0.004 {method 'execute' of 'psycopg2.extensions.cursor' objects}
5011985 28.743 0.000 28.743 0.000 {isinstance}
406050 28.006 0.000 84.958 0.000 geocoder.py:103(ExpandKeysRemoveSuffixes)
4615072 24.683 0.000 24.683 0.000 {method 'strip' of 'str' objects}
406050 23.753 0.000 73.190 0.000 geocoder.py:93(ExpandKeysRemovePSC)
4307709 23.644 0.000 23.644 0.000 {method 'lower' of 'str' objects}
3295748 23.524 0.000 23.524 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
406050 18.920 0.000 120.353 0.000 geocoder.py:122(ExpandKeysRemoveCityPart)
406050 14.742 0.000 44.408 0.000 geocoder.py:83(ExpandKeysRemoveSlash)
Predpokladám, že skript generate_prod_data.py strávi veľkú väčšinu času vykonávaním SQL príkazov generujúcich produkčné tabuľky, a tento čas nie je zachytený Python profilerom. Vo vyššie priloženom výstupe vyzerá byť uvedený celkový čas 642.895 sekúnd, čo by vysvetľovalo len 11 minút zo spomínaných celkových 8 hodín.
642 sekund je praveze celkovy cas, lebo to bolo v TEST_MODE. S profilerom to cele bezi pomalsie.
Realny skript v produkcii, okrem uvodu kde pridavame vela novych entit z RPO, pouziva 80 az 100% cpu na python a len malo na DB, co sme s Frankiem videli aj v logoch, kde nezriedka bolo vidno SQL operaciu trvajucu dost menej nez milisekundu a potom 1-2 sekundy ziadnu dalsiu.
Vsetky tie string manipulacie a regular expressions pouzite na vygenerovanie desiatok klucov sa zdaju na prvy pohlad mozno nic, ale treba to vynasobit x 10 milionov zistovani addreess_id zo stringu a uz to zacina byt problem ....
Vďaka za objasnenie; zabudol som, že test mode sa vypína negatívnym flagom (neviem, či som to tak ja nespravil...). Super, že databáza tu nie je bottleneck.
Ak dobre pozerám, GetKeysForAddress(address) sa používa v dvoch fázach skriptu: (1) pri načítavaní geocode cache (adresy úspešne geokódované v minulosti) a potom (2) pri spracovávaní každého riadku zdrojových tabuliek. Lazy počítanie kľúčov v GetKeysForAddress(address) môže zrýchliť fázu (2), ale asi nie (1)? (A vzhľadom na zvolené limity v test móde, väčšina času je tam momentálne zrejme strávená vo fáze (1).)
Aká je inak definícia cache tabuľky address_cache/toprocess? Pamätáme si niekde adresy, ktoré Google API nevedelo zgeokódovať, alebo hrozí, že sa o ich geokódovanie pokúšame opakovane? Napríklad sa mi zdá možné, že do geokódovacieho API momentálne posielame aj prázdny string, keď nejaký zdrojový riadok nemá vyplnenú adresu.
ako vidim, Dano zacal zlepsovat kod, aktualny profil:
43980160 function calls (43978525 primitive calls) in 661.970 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
2666496 104.739 0.000 479.601 0.000 geocoder.py:76(GetKeysForAddress)
3269601 65.630 0.000 162.494 0.000 re.py:143(search)
9168 63.621 0.007 63.745 0.007 {method 'execute' of 'psycopg2.extensions.cursor' objects}
8640114 55.818 0.000 55.818 0.000 {method 'replace' of 'str' objects}
3271703 52.609 0.000 73.050 0.000 re.py:230(_compile)
4990847 30.881 0.000 30.881 0.000 {isinstance}
405907 25.550 0.000 78.227 0.000 geocoder.py:94(ExpandKeysRemovePSC)
200000 25.334 0.000 502.964 0.003 geocoder.py:56(AddToCache)
4147370 24.576 0.000 24.576 0.000 {method 'append' of 'list' objects}
3269644 24.400 0.000 24.400 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
404991 20.196 0.000 128.580 0.000 geocoder.py:121(ExpandKeysRemoveCityPart)
405865 19.632 0.000 33.482 0.000 geocoder.py:104(ExpandKeysRemoveSuffixes)
405910 15.502 0.000 46.136 0.000 geocoder.py:84(ExpandKeysRemoveSlash)
2309181/2308950 13.837 0.000 13.839 0.000 {len}
2262509 13.522 0.000 13.522 0.000 {method 'add' of 'set' objects}
869768 12.113 0.000 17.385 0.000 extras.py:172(setitem)
839780 11.559 0.000 17.209 0.000 extras.py:167(getitem)
1 11.431 11.431 569.014 569.014 geocoder.py:21(init)
207009 11.385 0.000 34.028 0.000 extras.py:108(iter)
1417712 8.742 0.000 8.742 0.000 {method 'group' of '_sre.SRE_Match' objects}
406074 7.682 0.000 12.782 0.000 geocoder.py:71(NormalizeAddress)
406074 5.272 0.000 18.054 0.000 geocoder.py:131(Identity)
Dnesne pregenerovanie dat trvalo cca 7 hodin, cize nedavne zmeny to asi moc nezrychlili .. alebo ich treba nejako specialne zapnut?
Novy profil, spustil som to bez test modu pre prvy source z prod_tables (rpo tabulka) a bez commitu ;)
1035723061 function calls (1035721674 primitive calls) in 16578.589 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
3401304 2736.312 0.001 5301.390 0.002 entities.py:48(parse_entity_name)
5999603 2391.768 0.000 2512.832 0.000 {method 'execute' of 'psycopg2.extensions.cursor' objects}
173433564 1071.995 0.000 1071.995 0.000 {method 'endswith' of 'unicode' objects}
27302319 1021.354 0.000 4542.385 0.000 geocoder.py:89(GetKeysForAddress)
115623854 717.577 0.000 717.577 0.000 {method 'startswith' of 'unicode' objects}
31499083 628.130 0.000 1561.907 0.000 re.py:143(search)
97624382/97624157 594.341 0.000 594.344 0.000 {len}
87853662 567.653 0.000 567.653 0.000 {isinstance}
31523242 508.498 0.000 703.634 0.000 re.py:230(_compile)
78718075 507.256 0.000 507.256 0.000 {method 'replace' of 'str' objects}
28350921 404.617 0.000 600.988 0.000 extras.py:167(getitem)
26372028 378.726 0.000 544.318 0.000 extras.py:172(setitem)
57812665 359.258 0.000 359.258 0.000 {method 'strip' of 'unicode' objects}
1 351.909 351.909 10708.063 10708.063 generate_prod_data.py:78(ProcessSource)
6169203 308.455 0.000 952.532 0.000 extras.py:108(iter)
2271817 244.723 0.000 4786.876 0.002 geocoder.py:69(AddToCache)
31499095 231.025 0.000 231.025 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
37206172 224.266 0.000 224.266 0.000 {method 'append' of 'list' objects}
4543868 223.719 0.000 694.808 0.000 geocoder.py:107(ExpandKeysRemovePSC)
4543868 202.112 0.000 348.928 0.000 geocoder.py:117(ExpandKeysRemoveSuffixes)
1 190.158 190.158 5851.044 5851.044 geocoder.py:24(init)
4543868 181.531 0.000 1183.185 0.000 geocoder.py:134(ExpandKeysRemoveCityPart)
1979829 154.361 0.000 1147.445 0.001 generate_prod_data.py:102(AddValuesToTable)
7738942 131.241 0.000 181.468 0.000 extras.py:163(init)
4543868 129.241 0.000 442.556 0.000 geocoder.py:97(ExpandKeysRemoveSlash)
20778968 126.120 0.000 126.120 0.000 {method 'add' of 'set' objects}
1980297 115.214 0.000 1525.421 0.001 geocoder.py:225(LookupKeysInCache)
2039929 111.824 0.000 981.424 0.000 db.py:53(add_values)
15839185 108.281 0.000 108.281 0.000 {method 'get' of 'dict' objects}
1980063 105.325 0.000 1700.254 0.001 geocoder.py:220(GetAddressId)
5999600 98.492 0.000 240.398 0.000 {method 'cursor' of 'psycopg2.extensions.connection' objects}
1979829 87.488 0.000 1358.626 0.001 generate_prod_data.py:128(AddToTable)
4543868 85.393 0.000 142.261 0.000 geocoder.py:84(NormalizeAddress)
10358365 82.841 0.000 82.844 0.000 {method 'encode' of 'unicode' objects}
4019771 77.859 0.000 121.064 0.000 :8(new)
3959664 71.486 0.000 71.486 0.000 extras.py:69(init)
3959663 70.420 0.000 141.906 0.000 extras.py:136(init)
3959666 68.792 0.000 1787.062 0.000 extras.py:141(execute)
10552407 65.613 0.000 65.613 0.000 {method 'group' of '_sre.SRE_Match' objects}
3959663 61.708 0.000 270.485 0.000 db.py:43(dict_cursor)
4019758 59.854 0.000 141.564 0.000 {function fetchone at 0x8020af500}
4543868 58.520 0.000 200.781 0.000 geocoder.py:144(Identity)
1979829 52.403 0.000 6271.076 0.003 entities.py:172(GetEntity)
1979829 51.700 0.000 250.580 0.000 extras.py:81(fetchone)
1979832 48.375 0.000 75.223 0.000 extras.py:151(_build_index)
4019787 43.205 0.000 43.205 0.000 {built-in method new of type object at 0x800defce8}
1629608 42.859 0.000 831.031 0.001 entities.py:158(AddNewEntity)
6023710 41.106 0.000 41.107 0.000 {method 'join' of 'str' objects}
5378784 40.922 0.000 40.922 0.000 {method 'split' of 'unicode' objects}
1957795 39.847 0.000 5341.238 0.003 entities.py:119(is_merge_desired)
4891897 30.135 0.000 30.135 0.000 {method 'strip' of 'str' objects}
4310569 29.142 0.000 29.142 0.000 generate_prod_data.py:110()
4543869 28.845 0.000 28.845 0.000 {method 'lower' of 'str' objects}
1979866 27.862 0.000 43.080 0.000 {all}
3960126 27.712 0.000 27.712 0.000 extras.py:208(contains)
1980063 22.920 0.000 22.920 0.000 {itertools.tee}
3398721 22.874 0.000 22.874 0.000 {method 'find' of 'unicode' objects}
350911 20.807 0.000 5362.045 0.015 entities.py:147(ExistsPerson)
1979829 16.668 0.000 16.668 0.000 entities.py:33(AddOrg2Eid)
1628918 14.488 0.000 14.488 0.000 entities.py:142(ExistsICO)
1980003 14.214 0.000 14.214 0.000 {range}
1539275 13.773 0.000 13.773 0.000 entities.py:155(AddICO)
1979829 13.450 0.000 13.450 0.000 geocoder.py:249(UpdateKeyHint)
Ak sa da verit bash time, commit d768c15 zrychlil generovanie produkcnych dat z cca 8h 30min na 5h 45min.
Po commite 29cfe31 (regexp matchovanie akademickych titulov v parse_entity_name) mi to zbehlo za 4h 50min.