Performance Regression with SVN version 50525

Hello All, The pypy c translation time doubled for me with SVN revision 50525 (2:13:48 PM) *bigdog:* 50524: (2:13:48 PM) *bigdog:* Timer] Timings: (2:13:48 PM) *bigdog:* Timer] annotate - 318.9 s (2:13:48 PM) *bigdog:* Timer] rtype_lltype - 174.2 s (2:13:48 PM) *bigdog:* Timer] backendopt_lltype - 183.3 s (2:13:48 PM) *bigdog:* Timer] stackcheckinsertion_lltype - 62.6 s (2:13:48 PM) *bigdog:* Timer] database_c - 128.2 s (2:13:48 PM) *bigdog:* Timer] source_c - 69.3 s (2:13:48 PM) *bigdog:* Timer] compile_c - 0.1 s (2:13:48 PM) *bigdog:* Timer] ======================================== (2:13:48 PM) *bigdog:* Timer] Total: - 936.6 s (2:55:29 PM) *bigdog:* 50525 timings: (2:55:32 PM) *bigdog:* [Timer] Timings: (2:55:32 PM) *bigdog:* [Timer] annotate - 335.2 s (2:55:32 PM) *bigdog:* [Timer] rtype_lltype - 174.3 s (2:55:32 PM) *bigdog:* [Timer] backendopt_lltype - 183.5 s (2:55:32 PM) *bigdog:* [Timer] stackcheckinsertion_lltype - 1066.0 s (2:55:32 PM) *bigdog:* [Timer] database_c - 126.3 s (2:55:32 PM) *bigdog:* [Timer] source_c - 70.4 s (2:55:32 PM) *bigdog:* [Timer] compile_c - 0.1 s (2:55:32 PM) *bigdog:* [Timer] ========================================= (2:55:32 PM) *bigdog:* [Timer] Total: - 1955.8 s The translation spent inordinate amount of time in: (2:37:52 PM) *bigdog:* ..+*%+................................*%%..................................... (2:37:52 PM) *bigdog:* [backendopt:malloc] removed 3922 simple mallocs in total (2:37:52 PM) *bigdog:* [backendopt:mergeifblocks] starting to merge if blocks (2:37:52 PM) *bigdog:* ..+*%+................................*%%.............. (2:37:52 PM) *bigdog:* [translation:info] inserting stack checks... (2:37:52 PM) *bigdog:* .. (2:37:52 PM) *bigdog:* [rtyper] -=- specialized 6 more blocks -=- Translation memory use went from ~350 meg to ~1.3 gb (memory use are not exact, I just looked at the perfomrnace monitor when runnning) Hope this is helpful, Mike

Looks like Carls' fix took care of the issue: (10:23:58 AM) *bigdog:* cfbolts: Translation timings for 50557 (10:24:01 AM) *bigdog:* [Timer] Timings: (10:24:01 AM) *bigdog:* [Timer] annotate - 329.5 s (10:24:01 AM) *bigdog:* [Timer] rtype_lltype - 172.7 s (10:24:01 AM) *bigdog:* [Timer] backendopt_lltype - 182.5 s (10:24:01 AM) *bigdog:* [Timer] stackcheckinsertion_lltype - 12.3 s (10:24:01 AM) *bigdog:* [Timer] database_c - 124.8 s (10:24:01 AM) *bigdog:* [Timer] source_c - 67.7 s (10:24:01 AM) *bigdog:* [Timer] compile_c - 0.1 s (10:24:01 AM) *bigdog:* [Timer] ======================================== (10:24:01 AM) *bigdog:* [Timer] Total: - 889.5 s Very good work, amazing turnaround time. Thanks, Mike Michael Schneider wrote:

Hello All, Hope you are having fun at the sprint. I have been working on getting the windows translation going again. There are 3 issues, and I have fixes for 2 of them 1) translator/c/src/stack.h includes a unix only include file without guards, this is an easy fix. This include is not used, simply delete this #include #include <unistd.h> 2) translator/c/src/ll_strtod.h apply this patch to add #include<winsock2.h> during a windows compile. The patch at then end of this email will fix the winsoc2 related compile errors 3) The generated code module_0.c #includes <sys/wait.h> rumor has a fix is close for this, so I did not work this. module_0.c module_0.c(859) : fatal error C1083: Cannot open include file: 'sys/wait.h': No such file or directory Can some kind soul please review and commit these changes? Thanks, and happy skiing/snowboarding/lounging in a nice place, Mike ---------------------------------------------------------------------------------------------------------- m #------------------------------------------ start patch------------------------------------------- Index: ll_strtod.h =================================================================== --- ll_strtod.h (revision 50566) +++ ll_strtod.h (working copy) @@ -1,6 +1,10 @@ #ifndef LL_STRTOD_H #define LL_STRTOD_H +#ifdef MS_WINDOWS +#include <winsock2.h> +#endif + #include <locale.h> #include <ctype.h> #include <string.h>

Hi Mike, Michael Schneider wrote:
Hope you are having fun at the sprint.
yes, apart from the usual head-wall interactions :-).
I committed both of these, thanks a lot!
According to Maciek this should be fixed as of revision 50588 Thanks again, Carl Friedrich

Good News, things are progressing nicely. 1) the 3 classes are compile errors have been address, and the source files now compile (note: header cleanup may still occur) 2) The link is very close, the emmited link command includes a m.lib command which is an error on visual studio links.. I am sorry, I don't understand how the link line is emmited. Can someone familiar with this please remove the m.lib from the generated link line for visual studio 2003? Thanks Mike PS. I will be happy to test the fix ---------------------------------------- compile and link line from simple Visual Studio Project 2003, that includes a sin(90.0) ------------ Command Lines Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000005.rsp" with contents [ /Od /D "WIN32" /D "_DEBUG" /D "_CONSOLE" /D "_MBCS" /Gm /EHsc /RTC1 /MLd /Yu"stdafx.h" /Fp"Debug/simplemath.pch" /Fo"Debug/" /Fd"Debug/vc70.pdb" /W3 /c /Wp64 /ZI /TP ".\simplemath.cpp" ] Creating command line "cl.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000005.rsp" /nologo" Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000006.rsp" with contents [ /Od /D "WIN32" /D "_DEBUG" /D "_CONSOLE" /D "_MBCS" /Gm /EHsc /RTC1 /MLd /Yc"stdafx.h" /Fp"Debug/simplemath.pch" /Fo"Debug/" /Fd"Debug/vc70.pdb" /W3 /c /Wp64 /ZI /TP ".\stdafx.cpp" ] Creating command line "cl.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000006.rsp" /nologo" Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000007.rsp" with contents [ /OUT:"Debug/simplemath.exe" /INCREMENTAL /NOLOGO /DEBUG /PDB:"Debug/simplemath.pdb" /SUBSYSTEM:CONSOLE /MACHINE:X86 kernel32.lib user32.lib gdi32.lib winspool.lib comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib uuid.lib odbc32.lib odbccp32.lib ".\debug\stdafx.obj" ".\debug\simplemath.obj" ] Creating command line "link.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000007.rsp"" Output Window Compiling... stdafx.cpp Compiling... simplemath.cpp Linking... Results Build log was saved at "file://c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\BuildLog.htm" simplemath - 0 error(s), 0 warning(s) -------------------------------------end simple visual studio project ----------------------------------------------------------------------------------------------- ------------------------------------- current pypy compile and link line --------------------------------------------------------------------- .... compile other .obj's cut \pypy-dist\pypy\translator\c /Tcmodule_2.c /Fomodule_2.obj [cbuild:execute] C:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\bin\cl.exe /c /nologo /Ox /MD /W3 /GX /DNDEBUG -Ic:\python25\include -IH:\pypy\pypy-dist\pypy\translator\c /Tcmodule_3.c /Fomodule_3.obj [cbuild:execute] C:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\bin\link.exe /DEBUG /nologo /INCREMENTAL:NO gc_pypy.lib m.lib h:\temp\usession-27\testing_1\testing_1.obj h:\temp\usession-27\testing_1\structimpl.obj h:\temp\usession-27\testing_1\nonfuncnodes.obj h:\temp\usession-27\testing_1\nonfuncnodes_1.obj h:\temp\usession-27\testing_1\nonfuncnodes_2.obj h:\temp\usession-27\testing_1\nonfuncnodes_3.obj h:\temp\usession-27\testing_1\nonfuncnodes_4.obj h:\temp\usession-27\testing_1\nonfuncnodes_5.obj h:\temp\usession-27\testing_1\nonfuncnodes_6.obj h:\temp\usession-27\testing_1\nonfuncnodes_7.obj h:\temp\usession-27\testing_1\implement.obj h:\temp\usession-27\testing_1\implement_1.obj h:\temp\usession-27\testing_1\implement_2.obj h:\temp\usession-27\testing_1\implement_3.obj h:\temp\usession-27\testing_1\implement_4.obj h:\temp\usession-27\testing_1\implement_5.obj h:\temp\usession-27\testing_1\implement_6.obj h:\temp\usession-27\testing_1\implement_7.obj h:\temp\usession-27\testing_1\implement_8.obj h:\temp\usession-27\testing_1\implement_9.obj h:\temp\usession-27\testing_1\implement_10.obj h:\temp\usession-27\testing_1\implement_11.obj h:\temp\usession-27\testing_1\implement_12.obj h:\temp\usession-27\testing_1\implement_13.obj h:\temp\usession-27\testing_1\implement_14.obj h:\temp\usession-27\module_cache\module_0.obj h:\temp\usession-27\module_cache\module_1.obj h:\temp\usession-27\module_cache\module_2.obj h:\temp\usession-27\module_cache\module_3.obj /OUT:h:\temp\usession-27\testing_1\testing_1.exe -=- specialized 0 more blocks -=- [backendopt:inlining] phase with threshold factor: 32. --------------------------------- end pypy link line -----------------------------------------------------------------

Wow, Thanks to everyone for their efforts. The compile errors have been addressed, and the first couple of layers of the link-issue onion have been peeled. We are down to this link issue on windows Mike Note: this translation does not include the allmodules flag, we did the first trial balloon of that today, and there are some issues in the mmap area. Those issues can until we finish this first level of success. ---------------------------------------------------------------------------------------------- module_0.c module_0.c(885) : warning C4013: 'WCOREDUMP' undefined; assuming extern returnin g int module_0.c(890) : warning C4013: 'WIFCONTINUED' undefined; assuming extern retur ning int module_0.c(895) : warning C4013: 'WIFSTOPPED' undefined; assuming extern returni ng int module_0.c(900) : warning C4013: 'WIFSIGNALED' undefined; assuming extern return ing int module_0.c(905) : warning C4013: 'WIFEXITED' undefined; assuming extern returnin g int module_0.c(910) : warning C4013: 'WEXITSTATUS' undefined; assuming extern return ing int module_0.c(915) : warning C4013: 'WSTOPSIG' undefined; assuming extern returning int module_0.c(920) : warning C4013: 'WTERMSIG' undefined; assuming extern returning int module_1.c module_1.c(860) : warning C4273: '_errno' : inconsistent dll linkage module_2.c module_3.c module_3.c(859) : warning C4273: '__p__environ' : inconsistent dll linkage Creating library h:\temp\usession-36\testing_1\testing_1.lib and object h:\te mp\usession-36\testing_1\testing_1.exp module_0.obj : error LNK2019: unresolved external symbol _WCOREDUMP referenced i n function _pypy_macro_wrapper_WCOREDUMP module_0.obj : error LNK2019: unresolved external symbol _WIFCONTINUED reference d in function _pypy_macro_wrapper_WIFCONTINUED module_0.obj : error LNK2019: unresolved external symbol _WIFSTOPPED referenced in function _pypy_macro_wrapper_WIFSTOPPED module_0.obj : error LNK2019: unresolved external symbol _WIFSIGNALED referenced in function _pypy_macro_wrapper_WIFSIGNALED module_0.obj : error LNK2019: unresolved external symbol _WIFEXITED referenced i n function _pypy_macro_wrapper_WIFEXITED module_0.obj : error LNK2019: unresolved external symbol _WEXITSTATUS referenced in function _pypy_macro_wrapper_WEXITSTATUS module_0.obj : error LNK2019: unresolved external symbol _WSTOPSIG referenced in function _pypy_macro_wrapper_WSTOPSIG module_0.obj : error LNK2019: unresolved external symbol _WTERMSIG referenced in function _pypy_macro_wrapper_WTERMSIG h:\temp\usession-36\testing_1\testing_1.exe : fatal error LNK1120: 8 unresolved externals

Looks like Carls' fix took care of the issue: (10:23:58 AM) *bigdog:* cfbolts: Translation timings for 50557 (10:24:01 AM) *bigdog:* [Timer] Timings: (10:24:01 AM) *bigdog:* [Timer] annotate - 329.5 s (10:24:01 AM) *bigdog:* [Timer] rtype_lltype - 172.7 s (10:24:01 AM) *bigdog:* [Timer] backendopt_lltype - 182.5 s (10:24:01 AM) *bigdog:* [Timer] stackcheckinsertion_lltype - 12.3 s (10:24:01 AM) *bigdog:* [Timer] database_c - 124.8 s (10:24:01 AM) *bigdog:* [Timer] source_c - 67.7 s (10:24:01 AM) *bigdog:* [Timer] compile_c - 0.1 s (10:24:01 AM) *bigdog:* [Timer] ======================================== (10:24:01 AM) *bigdog:* [Timer] Total: - 889.5 s Very good work, amazing turnaround time. Thanks, Mike Michael Schneider wrote:

Hello All, Hope you are having fun at the sprint. I have been working on getting the windows translation going again. There are 3 issues, and I have fixes for 2 of them 1) translator/c/src/stack.h includes a unix only include file without guards, this is an easy fix. This include is not used, simply delete this #include #include <unistd.h> 2) translator/c/src/ll_strtod.h apply this patch to add #include<winsock2.h> during a windows compile. The patch at then end of this email will fix the winsoc2 related compile errors 3) The generated code module_0.c #includes <sys/wait.h> rumor has a fix is close for this, so I did not work this. module_0.c module_0.c(859) : fatal error C1083: Cannot open include file: 'sys/wait.h': No such file or directory Can some kind soul please review and commit these changes? Thanks, and happy skiing/snowboarding/lounging in a nice place, Mike ---------------------------------------------------------------------------------------------------------- m #------------------------------------------ start patch------------------------------------------- Index: ll_strtod.h =================================================================== --- ll_strtod.h (revision 50566) +++ ll_strtod.h (working copy) @@ -1,6 +1,10 @@ #ifndef LL_STRTOD_H #define LL_STRTOD_H +#ifdef MS_WINDOWS +#include <winsock2.h> +#endif + #include <locale.h> #include <ctype.h> #include <string.h>

Hi Mike, Michael Schneider wrote:
Hope you are having fun at the sprint.
yes, apart from the usual head-wall interactions :-).
I committed both of these, thanks a lot!
According to Maciek this should be fixed as of revision 50588 Thanks again, Carl Friedrich

Good News, things are progressing nicely. 1) the 3 classes are compile errors have been address, and the source files now compile (note: header cleanup may still occur) 2) The link is very close, the emmited link command includes a m.lib command which is an error on visual studio links.. I am sorry, I don't understand how the link line is emmited. Can someone familiar with this please remove the m.lib from the generated link line for visual studio 2003? Thanks Mike PS. I will be happy to test the fix ---------------------------------------- compile and link line from simple Visual Studio Project 2003, that includes a sin(90.0) ------------ Command Lines Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000005.rsp" with contents [ /Od /D "WIN32" /D "_DEBUG" /D "_CONSOLE" /D "_MBCS" /Gm /EHsc /RTC1 /MLd /Yu"stdafx.h" /Fp"Debug/simplemath.pch" /Fo"Debug/" /Fd"Debug/vc70.pdb" /W3 /c /Wp64 /ZI /TP ".\simplemath.cpp" ] Creating command line "cl.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000005.rsp" /nologo" Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000006.rsp" with contents [ /Od /D "WIN32" /D "_DEBUG" /D "_CONSOLE" /D "_MBCS" /Gm /EHsc /RTC1 /MLd /Yc"stdafx.h" /Fp"Debug/simplemath.pch" /Fo"Debug/" /Fd"Debug/vc70.pdb" /W3 /c /Wp64 /ZI /TP ".\stdafx.cpp" ] Creating command line "cl.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000006.rsp" /nologo" Creating temporary file "c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000007.rsp" with contents [ /OUT:"Debug/simplemath.exe" /INCREMENTAL /NOLOGO /DEBUG /PDB:"Debug/simplemath.pdb" /SUBSYSTEM:CONSOLE /MACHINE:X86 kernel32.lib user32.lib gdi32.lib winspool.lib comdlg32.lib advapi32.lib shell32.lib ole32.lib oleaut32.lib uuid.lib odbc32.lib odbccp32.lib ".\debug\stdafx.obj" ".\debug\simplemath.obj" ] Creating command line "link.exe @"c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\RSP000007.rsp"" Output Window Compiling... stdafx.cpp Compiling... simplemath.cpp Linking... Results Build log was saved at "file://c:\Documents and Settings\scmikes\My Documents\Visual Studio Projects\simplemath\simplemath\Debug\BuildLog.htm" simplemath - 0 error(s), 0 warning(s) -------------------------------------end simple visual studio project ----------------------------------------------------------------------------------------------- ------------------------------------- current pypy compile and link line --------------------------------------------------------------------- .... compile other .obj's cut \pypy-dist\pypy\translator\c /Tcmodule_2.c /Fomodule_2.obj [cbuild:execute] C:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\bin\cl.exe /c /nologo /Ox /MD /W3 /GX /DNDEBUG -Ic:\python25\include -IH:\pypy\pypy-dist\pypy\translator\c /Tcmodule_3.c /Fomodule_3.obj [cbuild:execute] C:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\bin\link.exe /DEBUG /nologo /INCREMENTAL:NO gc_pypy.lib m.lib h:\temp\usession-27\testing_1\testing_1.obj h:\temp\usession-27\testing_1\structimpl.obj h:\temp\usession-27\testing_1\nonfuncnodes.obj h:\temp\usession-27\testing_1\nonfuncnodes_1.obj h:\temp\usession-27\testing_1\nonfuncnodes_2.obj h:\temp\usession-27\testing_1\nonfuncnodes_3.obj h:\temp\usession-27\testing_1\nonfuncnodes_4.obj h:\temp\usession-27\testing_1\nonfuncnodes_5.obj h:\temp\usession-27\testing_1\nonfuncnodes_6.obj h:\temp\usession-27\testing_1\nonfuncnodes_7.obj h:\temp\usession-27\testing_1\implement.obj h:\temp\usession-27\testing_1\implement_1.obj h:\temp\usession-27\testing_1\implement_2.obj h:\temp\usession-27\testing_1\implement_3.obj h:\temp\usession-27\testing_1\implement_4.obj h:\temp\usession-27\testing_1\implement_5.obj h:\temp\usession-27\testing_1\implement_6.obj h:\temp\usession-27\testing_1\implement_7.obj h:\temp\usession-27\testing_1\implement_8.obj h:\temp\usession-27\testing_1\implement_9.obj h:\temp\usession-27\testing_1\implement_10.obj h:\temp\usession-27\testing_1\implement_11.obj h:\temp\usession-27\testing_1\implement_12.obj h:\temp\usession-27\testing_1\implement_13.obj h:\temp\usession-27\testing_1\implement_14.obj h:\temp\usession-27\module_cache\module_0.obj h:\temp\usession-27\module_cache\module_1.obj h:\temp\usession-27\module_cache\module_2.obj h:\temp\usession-27\module_cache\module_3.obj /OUT:h:\temp\usession-27\testing_1\testing_1.exe -=- specialized 0 more blocks -=- [backendopt:inlining] phase with threshold factor: 32. --------------------------------- end pypy link line -----------------------------------------------------------------

Wow, Thanks to everyone for their efforts. The compile errors have been addressed, and the first couple of layers of the link-issue onion have been peeled. We are down to this link issue on windows Mike Note: this translation does not include the allmodules flag, we did the first trial balloon of that today, and there are some issues in the mmap area. Those issues can until we finish this first level of success. ---------------------------------------------------------------------------------------------- module_0.c module_0.c(885) : warning C4013: 'WCOREDUMP' undefined; assuming extern returnin g int module_0.c(890) : warning C4013: 'WIFCONTINUED' undefined; assuming extern retur ning int module_0.c(895) : warning C4013: 'WIFSTOPPED' undefined; assuming extern returni ng int module_0.c(900) : warning C4013: 'WIFSIGNALED' undefined; assuming extern return ing int module_0.c(905) : warning C4013: 'WIFEXITED' undefined; assuming extern returnin g int module_0.c(910) : warning C4013: 'WEXITSTATUS' undefined; assuming extern return ing int module_0.c(915) : warning C4013: 'WSTOPSIG' undefined; assuming extern returning int module_0.c(920) : warning C4013: 'WTERMSIG' undefined; assuming extern returning int module_1.c module_1.c(860) : warning C4273: '_errno' : inconsistent dll linkage module_2.c module_3.c module_3.c(859) : warning C4273: '__p__environ' : inconsistent dll linkage Creating library h:\temp\usession-36\testing_1\testing_1.lib and object h:\te mp\usession-36\testing_1\testing_1.exp module_0.obj : error LNK2019: unresolved external symbol _WCOREDUMP referenced i n function _pypy_macro_wrapper_WCOREDUMP module_0.obj : error LNK2019: unresolved external symbol _WIFCONTINUED reference d in function _pypy_macro_wrapper_WIFCONTINUED module_0.obj : error LNK2019: unresolved external symbol _WIFSTOPPED referenced in function _pypy_macro_wrapper_WIFSTOPPED module_0.obj : error LNK2019: unresolved external symbol _WIFSIGNALED referenced in function _pypy_macro_wrapper_WIFSIGNALED module_0.obj : error LNK2019: unresolved external symbol _WIFEXITED referenced i n function _pypy_macro_wrapper_WIFEXITED module_0.obj : error LNK2019: unresolved external symbol _WEXITSTATUS referenced in function _pypy_macro_wrapper_WEXITSTATUS module_0.obj : error LNK2019: unresolved external symbol _WSTOPSIG referenced in function _pypy_macro_wrapper_WSTOPSIG module_0.obj : error LNK2019: unresolved external symbol _WTERMSIG referenced in function _pypy_macro_wrapper_WTERMSIG h:\temp\usession-36\testing_1\testing_1.exe : fatal error LNK1120: 8 unresolved externals
participants (3)
-
Carl Friedrich Bolz
-
Maciej Fijalkowski
-
Michael Schneider