Mercurial > vim
view src/testdir/test_profile.vim @ 32936:c517845bd10e v9.0.1776
patch 9.0.1776: No support for stable Python 3 ABI
Commit: https://github.com/vim/vim/commit/c13b3d1350b60b94fe87f0761ea31c0e7fb6ebf3
Author: Yee Cheng Chin <ychin.git@gmail.com>
Date: Sun Aug 20 21:18:38 2023 +0200
patch 9.0.1776: No support for stable Python 3 ABI
Problem: No support for stable Python 3 ABI
Solution: Support Python 3 stable ABI
Commits:
1) Support Python 3 stable ABI to allow mixed version interoperatbility
Vim currently supports embedding Python for use with plugins, and the
"dynamic" linking option allows the user to specify a locally installed
version of Python by setting `pythonthreedll`. However, one caveat is
that the Python 3 libs are not binary compatible across minor versions,
and mixing versions can potentially be dangerous (e.g. let's say Vim was
linked against the Python 3.10 SDK, but the user sets `pythonthreedll`
to a 3.11 lib). Usually, nothing bad happens, but in theory this could
lead to crashes, memory corruption, and other unpredictable behaviors.
It's also difficult for the user to tell something is wrong because Vim
has no way of reporting what Python 3 version Vim was linked with.
For Vim installed via a package manager, this usually isn't an issue
because all the dependencies would already be figured out. For prebuilt
Vim binaries like MacVim (my motivation for working on this), AppImage,
and Win32 installer this could potentially be an issue as usually a
single binary is distributed. This is more tricky when a new Python
version is released, as there's a chicken-and-egg issue with deciding
what Python version to build against and hard to keep in sync when a new
Python version just drops and we have a mix of users of different Python
versions, and a user just blindly upgrading to a new Python could lead to
bad interactions with Vim.
Python 3 does have a solution for this problem: stable ABI / limited API
(see https://docs.python.org/3/c-api/stable.html). The C SDK limits the
API to a set of functions that are promised to be stable across
versions. This pull request adds an ifdef config that allows us to turn
it on when building Vim. Vim binaries built with this option should be
safe to freely link with any Python 3 libraies without having the
constraint of having to use the same minor version.
Note: Python 2 has no such concept and this doesn't change how Python 2
integration works (not that there is going to be a new version of Python
2 that would cause compatibility issues in the future anyway).
---
Technical details:
======
The stable ABI can be accessed when we compile with the Python 3 limited
API (by defining `Py_LIMITED_API`). The Python 3 code (in `if_python3.c`
and `if_py_both.h`) would now handle this and switch to limited API
mode. Without it set, Vim will still use the full API as before so this
is an opt-in change.
The main difference is that `PyType_Object` is now an opaque struct that
we can't directly create "static types" out of, and we have to create
type objects as "heap types" instead. This is because the struct is not
stable and changes from version to version (e.g. 3.8 added a
`tp_vectorcall` field to it). I had to change all the types to be
allocated on the heap instead with just a pointer to them.
Other functions are also simply missing in limited API, or they are
introduced too late (e.g. `PyUnicode_AsUTF8AndSize` in 3.10) to it that
we need some other ways to do the same thing, so I had to abstract a few
things into macros, and sometimes re-implement functions like
`PyObject_NEW`.
One caveat is that in limited API, `OutputType` (used for replacing
`sys.stdout`) no longer inherits from `PyStdPrinter_Type` which I don't
think has any real issue other than minor differences in how they
convert to a string and missing a couple functions like `mode()` and
`fileno()`.
Also fixed an existing bug where `tp_basicsize` was set incorrectly for
`BufferObject`, `TabListObject, `WinListObject`.
Technically, there could be a small performance drop, there is a little
more indirection with accessing type objects, and some APIs like
`PyUnicode_AsUTF8AndSize` are missing, but in practice I didn't see any
difference, and any well-written Python plugin should try to avoid
excessing callbacks to the `vim` module in Python anyway.
I only tested limited API mode down to Python 3.7, which seemes to
compile and work fine. I haven't tried earlier Python versions.
2) Fix PyIter_Check on older Python vers / type##Ptr unused warning
For PyIter_Check, older versions exposed them as either macros (used in
full API), or a function (for use in limited API). A previous change
exposed PyIter_Check to the dynamic build because Python just moved it
to function-only in 3.10 anyway. Because of that, just make sure we
always grab the function in dynamic builds in earlier versions since
that's what Python eventually did anyway.
3) Move Py_LIMITED_API define to configure script
Can now use --with-python-stable-abi flag to customize what stable ABI
version to target. Can also use an env var to do so as well.
4) Show +python/dyn-stable in :version, and allow has() feature query
Not sure if the "/dyn-stable" suffix would break things, or whether we
should do it another way. Or just don't show it in version and rely on
has() feature checking.
5) Documentation first draft. Still need to implement v:python3_version
6) Fix PyIter_Check build breaks when compiling against Python 3.8
7) Add CI coverage stable ABI on Linux/Windows / make configurable on Windows
This adds configurable options for Windows make files (both MinGW and
MSVC). CI will also now exercise both traditional full API and stable
ABI for Linux and Windows in the matrix for coverage.
Also added a "dynamic" option to Linux matrix as a drive-by change to
make other scripting languages like Ruby / Perl testable under both
static and dynamic builds.
8) Fix inaccuracy in Windows docs
Python's own docs are confusing but you don't actually want to use
`python3.dll` for the dynamic linkage.
9) Add generated autoconf file
10) Add v:python3_version support
This variable indicates the version of Python3 that Vim was built
against (PY_VERSION_HEX), and will be useful to check whether the Python
library you are loading in dynamically actually fits it. When built with
stable ABI, it will be the limited ABI version instead
(`Py_LIMITED_API`), which indicates the minimum version of Python 3 the
user should have, rather than the exact match. When stable ABI is used,
we won't be exposing PY_VERSION_HEX in this var because it just doesn't
seem necessary to do so (the whole point of stable ABI is the promise
that it will work across versions), and I don't want to confuse the user
with too many variables.
Also, cleaned up some documentation, and added help tags.
11) Fix Python 3.7 compat issues
Fix a couple issues when using limited API < 3.8
- Crash on exit: In Python 3.7, if a heap-allocated type is destroyed
before all instances are, it would cause a crash later. This happens
when we destroyed `OptionsType` before calling `Py_Finalize` when
using the limited API. To make it worse, later versions changed the
semantics and now each instance has a strong reference to its own type
and the recommendation has changed to have each instance de-ref its
own type and have its type in GC traversal. To avoid dealing with
these cross-version variations, we just don't free the heap type. They
are static types in non-limited-API anyway and are designed to last
through the entirety of the app, and we also don't restart the Python
runtime and therefore do not need it to have absolutely 0 leaks.
See:
- https://docs.python.org/3/whatsnew/3.8.html#changes-in-the-c-api
- https://docs.python.org/3/whatsnew/3.9.html#changes-in-the-c-api
- PyIter_Check: This function is not provided in limited APIs older than
3.8. Previously I was trying to mock it out using manual
PyType_GetSlot() but it was brittle and also does not actually work
properly for static types (it will generate a Python error). Just
return false. It does mean using limited API < 3.8 is not recommended
as you lose the functionality to handle iterators, but from playing
with plugins I couldn't find it to be an issue.
- Fix loading of PyIter_Check so it will be done when limited API < 3.8.
Otherwise loading a 3.7 Python lib will fail even if limited API was
specified to use it.
12) Make sure to only load `PyUnicode_AsUTF8AndSize` in needed in limited API
We don't use this function unless limited API >= 3.10, but we were
loading it regardless. Usually it's ok in Unix-like systems where Python
just has a single lib that we load from, but in Windows where there is a
separate python3.dll this would not work as the symbol would not have
been exposed in this more limited DLL file. This makes it much clearer
under what condition is this function needed.
closes: #12032
Signed-off-by: Christian Brabandt <cb@256bit.org>
Co-authored-by: Yee Cheng Chin <ychin.git@gmail.com>
| author | Christian Brabandt <cb@256bit.org> |
|---|---|
| date | Sun, 20 Aug 2023 21:30:04 +0200 |
| parents | 98774a275d6d |
| children |
line wrap: on
line source
" Test Vim profiler source check.vim CheckFeature profile source shared.vim source screendump.vim if has('prof_nsec') let s:header = 'count total (s) self (s)' let s:header_func = 'count total (s) self (s) function' else let s:header = 'count total (s) self (s)' let s:header_func = 'count total (s) self (s) function' endif func Test_profile_func() call RunProfileFunc('func', 'let', 'let') call RunProfileFunc('def', 'var', '') endfunc func RunProfileFunc(command, declare, assign) let lines =<< trim [CODE] profile start Xprofile_func.log profile func Foo* XXX Foo1() endXXX XXX Foo2() DDD counter = 100 while counter > 0 AAA counter = counter - 1 endwhile sleep 1m endXXX XXX Foo3() endXXX XXX Bar() endXXX call Foo1() call Foo1() profile pause call Foo1() profile continue call Foo2() call Foo3() call Bar() if !v:profiling delfunc Foo2 endif delfunc Foo3 [CODE] call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) call map(lines, {k, v -> substitute(v, 'AAA', a:assign, '') }) call writefile(lines, 'Xprofile_func.vim', 'D') call system(GetVimCommand() \ . ' -es --clean' \ . ' -c "so Xprofile_func.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) sleep 50m let lines = readfile('Xprofile_func.log') " - Foo1() is called 3 times but should be reported as called twice " since one call is in between "profile pause" .. "profile continue". " - Foo2() should come before Foo1() since Foo1() does much more work. " - Foo3() is not reported because function is deleted. " - Unlike Foo3(), Foo2() should not be deleted since there is a check " for v:profiling. " - Bar() is not reported since it does not match "profile func Foo*". call assert_equal(31, len(lines)) call assert_equal('FUNCTION Foo1()', lines[0]) call assert_match('Defined:.*Xprofile_func.vim:3', lines[1]) call assert_equal('Called 2 times', lines[2]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) call assert_equal('', lines[5]) call assert_equal(s:header, lines[6]) call assert_equal('', lines[7]) call assert_equal('FUNCTION Foo2()', lines[8]) call assert_equal('Called 1 time', lines[10]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12]) call assert_equal('', lines[13]) call assert_equal(s:header, lines[14]) call assert_match('^\s*1\s\+.*\s\(let\|var\) counter = 100$', lines[15]) call assert_match('^\s*101\s\+.*\swhile counter > 0$', lines[16]) call assert_match('^\s*100\s\+.*\s \(let\)\= counter = counter - 1$', lines[17]) call assert_match('^\s*10[01]\s\+.*\sendwhile$', lines[18]) call assert_match('^\s*1\s\+.\+sleep 1m$', lines[19]) call assert_equal('', lines[20]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[21]) call assert_equal(s:header_func, lines[22]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[23]) call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[24]) call assert_equal('', lines[25]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[26]) call assert_equal(s:header_func, lines[27]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[28]) call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[29]) call assert_equal('', lines[30]) call delete('Xprofile_func.log') endfunc func Test_profile_func_with_ifelse() call Run_profile_func_with_ifelse('func', 'let') call Run_profile_func_with_ifelse('def', 'var') endfunc func Run_profile_func_with_ifelse(command, declare) let lines =<< trim [CODE] XXX Foo1() if 1 DDD x = 0 elseif 1 DDD x = 1 else DDD x = 2 endif endXXX XXX Foo2() if 0 DDD x = 0 elseif 1 DDD x = 1 else DDD x = 2 endif endXXX XXX Foo3() if 0 DDD x = 0 elseif 0 DDD x = 1 else DDD x = 2 endif endXXX call Foo1() call Foo2() call Foo3() [CODE] call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) call writefile(lines, 'Xprofile_func.vim', 'D') call system(GetVimCommand() \ . ' -es -i NONE --noplugin' \ . ' -c "profile start Xprofile_func.log"' \ . ' -c "profile func Foo*"' \ . ' -c "so Xprofile_func.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_func.log') " - Foo1() should pass 'if' block. " - Foo2() should pass 'elseif' block. " - Foo3() should pass 'else' block. call assert_equal(57, len(lines)) call assert_equal('FUNCTION Foo1()', lines[0]) call assert_match('Defined:.*Xprofile_func.vim', lines[1]) call assert_equal('Called 1 time', lines[2]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) call assert_equal('', lines[5]) call assert_equal(s:header, lines[6]) call assert_match('^\s*1\s\+.*\sif 1$', lines[7]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 0$', lines[8]) call assert_match( '^\s\+elseif 1$', lines[9]) call assert_match( '^\s\+\(let\|var\) x = 1$', lines[10]) call assert_match( '^\s\+else$', lines[11]) call assert_match( '^\s\+\(let\|var\) x = 2$', lines[12]) call assert_match('^\s*1\s\+.*\sendif$', lines[13]) call assert_equal('', lines[14]) call assert_equal('FUNCTION Foo2()', lines[15]) call assert_equal('Called 1 time', lines[17]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19]) call assert_equal('', lines[20]) call assert_equal(s:header, lines[21]) call assert_match('^\s*1\s\+.*\sif 0$', lines[22]) call assert_match( '^\s\+\(let\|var\) x = 0$', lines[23]) call assert_match('^\s*1\s\+.*\selseif 1$', lines[24]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 1$', lines[25]) call assert_match( '^\s\+else$', lines[26]) call assert_match( '^\s\+\(let\|var\) x = 2$', lines[27]) call assert_match('^\s*1\s\+.*\sendif$', lines[28]) call assert_equal('', lines[29]) call assert_equal('FUNCTION Foo3()', lines[30]) call assert_equal('Called 1 time', lines[32]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34]) call assert_equal('', lines[35]) call assert_equal(s:header, lines[36]) call assert_match('^\s*1\s\+.*\sif 0$', lines[37]) call assert_match( '^\s\+\(let\|var\) x = 0$', lines[38]) call assert_match('^\s*1\s\+.*\selseif 0$', lines[39]) call assert_match( '^\s\+\(let\|var\) x = 1$', lines[40]) call assert_match('^\s*1\s\+.*\selse$', lines[41]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[42]) call assert_match('^\s*1\s\+.*\sendif$', lines[43]) call assert_equal('', lines[44]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45]) call assert_equal(s:header_func, lines[46]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49]) call assert_equal('', lines[50]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51]) call assert_equal(s:header_func, lines[52]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55]) call assert_equal('', lines[56]) call delete('Xprofile_func.log') endfunc func Test_profile_func_with_trycatch() call Run_profile_func_with_trycatch('func', 'let') call Run_profile_func_with_trycatch('def', 'var') endfunc func Run_profile_func_with_trycatch(command, declare) let lines =<< trim [CODE] XXX Foo1() try DDD x = 0 catch DDD x = 1 finally DDD x = 2 endtry endXXX XXX Foo2() try throw 0 catch DDD x = 1 finally DDD x = 2 endtry endXXX XXX Foo3() try throw 0 catch throw 1 finally DDD x = 2 endtry endXXX call Foo1() call Foo2() let rethrown = 0 try call Foo3() catch let rethrown = 1 endtry if rethrown != 1 " call Foo1 again so that the test fails call Foo1() endif [CODE] call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) call writefile(lines, 'Xprofile_func.vim', 'D') call system(GetVimCommand() \ . ' -es -i NONE --noplugin' \ . ' -c "profile start Xprofile_func.log"' \ . ' -c "profile func Foo*"' \ . ' -c "so Xprofile_func.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_func.log') " - Foo1() should pass 'try' 'finally' blocks. " - Foo2() should pass 'catch' 'finally' blocks. " - Foo3() should not pass 'endtry'. call assert_equal(57, len(lines)) call assert_equal('FUNCTION Foo1()', lines[0]) call assert_match('Defined:.*Xprofile_func.vim', lines[1]) call assert_equal('Called 1 time', lines[2]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) call assert_equal('', lines[5]) call assert_equal(s:header, lines[6]) call assert_match('^\s*1\s\+.*\stry$', lines[7]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 0$', lines[8]) call assert_match( '^\s\+catch$', lines[9]) call assert_match( '^\s\+\(let\|var\) x = 1$', lines[10]) call assert_match('^\s*1\s\+.*\sfinally$', lines[11]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[12]) call assert_match('^\s*1\s\+.*\sendtry$', lines[13]) call assert_equal('', lines[14]) call assert_equal('FUNCTION Foo2()', lines[15]) call assert_equal('Called 1 time', lines[17]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19]) call assert_equal('', lines[20]) call assert_equal(s:header, lines[21]) call assert_match('^\s*1\s\+.*\stry$', lines[22]) call assert_match('^\s*1\s\+.*\s throw 0$', lines[23]) call assert_match('^\s*1\s\+.*\scatch$', lines[24]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 1$', lines[25]) call assert_match('^\s*1\s\+.*\sfinally$', lines[26]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[27]) call assert_match('^\s*1\s\+.*\sendtry$', lines[28]) call assert_equal('', lines[29]) call assert_equal('FUNCTION Foo3()', lines[30]) call assert_equal('Called 1 time', lines[32]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34]) call assert_equal('', lines[35]) call assert_equal(s:header, lines[36]) call assert_match('^\s*1\s\+.*\stry$', lines[37]) call assert_match('^\s*1\s\+.*\s throw 0$', lines[38]) call assert_match('^\s*1\s\+.*\scatch$', lines[39]) call assert_match('^\s*1\s\+.*\s throw 1$', lines[40]) call assert_match('^\s*1\s\+.*\sfinally$', lines[41]) call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[42]) call assert_match( '^\s\+endtry$', lines[43]) call assert_equal('', lines[44]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45]) call assert_equal(s:header_func, lines[46]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49]) call assert_equal('', lines[50]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51]) call assert_equal(s:header_func, lines[52]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55]) call assert_equal('', lines[56]) call delete('Xprofile_func.log') endfunc func Test_profile_file() let lines =<< trim [CODE] func! Foo() endfunc for i in range(10) " a comment call Foo() endfor call Foo() [CODE] call writefile(lines, 'Xprofile_file.vim', 'D') call system(GetVimCommandClean() \ . ' -es' \ . ' -c "profile start Xprofile_file.log"' \ . ' -c "profile file Xprofile_file.vim"' \ . ' -c "so Xprofile_file.vim"' \ . ' -c "so Xprofile_file.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_file.log') call assert_equal(14, len(lines)) call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) call assert_equal('Sourced 2 times', lines[1]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) call assert_equal('', lines[4]) call assert_equal(s:header, lines[5]) call assert_match(' 2 0.\d\+ func! Foo()', lines[6]) call assert_equal(' endfunc', lines[7]) " Loop iterates 10 times. Since script runs twice, body executes 20 times. " First line of loop executes one more time than body to detect end of loop. call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8]) call assert_equal(' " a comment', lines[9]) " if self and total are equal we only get one number call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10]) call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11]) " if self and total are equal we only get one number call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12]) call assert_equal('', lines[13]) call delete('Xprofile_file.log') endfunc func Test_profile_file_with_cont() let lines = [ \ 'echo "hello', \ ' \ world"', \ 'echo "foo ', \ ' \bar"', \ ] call writefile(lines, 'Xprofile_file.vim', 'D') call system(GetVimCommandClean() \ . ' -es' \ . ' -c "profile start Xprofile_file.log"' \ . ' -c "profile file Xprofile_file.vim"' \ . ' -c "so Xprofile_file.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_file.log') call assert_equal(11, len(lines)) call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) call assert_equal('Sourced 1 time', lines[1]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) call assert_equal('', lines[4]) call assert_equal(s:header, lines[5]) call assert_match(' 1 0.\d\+ echo "hello', lines[6]) call assert_equal(' \ world"', lines[7]) call assert_match(' 1 0.\d\+ echo "foo ', lines[8]) call assert_equal(' \bar"', lines[9]) call assert_equal('', lines[10]) call delete('Xprofile_file.log') endfunc " Test for ':profile stop' and ':profile dump' commands func Test_profile_stop_dump() call delete('Xprof1.out') call delete('Xprof2.out') call delete('Xprof3.out') func Xprof_test1() return "Hello" endfunc func Xprof_test2() return "World" endfunc " Test for ':profile stop' profile start Xprof1.out profile func Xprof_test1 call Xprof_test1() profile stop let lines = readfile('Xprof1.out') call assert_equal(17, len(lines)) call assert_equal('FUNCTION Xprof_test1()', lines[0]) call assert_match('Defined:.*test_profile.vim:', lines[1]) call assert_equal('Called 1 time', lines[2]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) call assert_equal('', lines[5]) call assert_equal(s:header, lines[6]) call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7]) call assert_equal('', lines[8]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[9]) call assert_equal(s:header_func, lines[10]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[11]) call assert_equal('', lines[12]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[13]) call assert_equal(s:header_func, lines[14]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[15]) call assert_equal('', lines[16]) " Test for ':profile stop' for a different function profile start Xprof2.out profile func Xprof_test2 call Xprof_test2() profile stop let lines = readfile('Xprof2.out') call assert_equal(17, len(lines)) call assert_equal('FUNCTION Xprof_test2()', lines[0]) call assert_match('Defined:.*test_profile.vim:', lines[1]) call assert_equal('Called 1 time', lines[2]) call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) call assert_equal('', lines[5]) call assert_equal(s:header, lines[6]) call assert_match('^\s*1\s\+.*\sreturn "World"$', lines[7]) call assert_equal('', lines[8]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[9]) call assert_equal(s:header_func, lines[10]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$', lines[11]) call assert_equal('', lines[12]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[13]) call assert_equal(s:header_func, lines[14]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$', lines[15]) call assert_equal('', lines[16]) " Test for ':profile dump' profile start Xprof3.out profile func Xprof_test1 profile func Xprof_test2 call Xprof_test1() profile dump " dump the profile once and verify the contents let lines = readfile('Xprof3.out') call assert_equal(17, len(lines)) call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[11]) call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[15]) " dump the profile again and verify the contents call Xprof_test2() profile dump profile stop let lines = readfile('Xprof3.out') call assert_equal(28, len(lines)) call assert_equal('FUNCTION Xprof_test1()', lines[0]) call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7]) call assert_equal('FUNCTION Xprof_test2()', lines[9]) call assert_match('^\s*1\s\+.*\sreturn "World"$', lines[16]) delfunc Xprof_test1 delfunc Xprof_test2 call delete('Xprof1.out') call delete('Xprof2.out') call delete('Xprof3.out') endfunc " Test for :profile sub-command completion func Test_profile_completion() call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx') call assert_equal('"profile continue dump file func pause start stop', @:) call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx') call assert_match('^"profile start.* test_profile\.vim', @:) call feedkeys(":profile file test_prof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_match('"profile file test_profile\.vim', @:) call feedkeys(":profile file test_prof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_match('"profile file test_profile\.vim', @:) call feedkeys(":profile file test_prof \<Tab>\<C-B>\"\<CR>", 'tx') call assert_match('"profile file test_prof ', @:) call feedkeys(":profile file X1B2C3\<Tab>\<C-B>\"\<CR>", 'tx') call assert_match('"profile file X1B2C3', @:) func Xprof_test() endfunc call feedkeys(":profile func Xprof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profile func Xprof_test', @:) call feedkeys(":profile func Xprof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profile func Xprof_test', @:) call feedkeys(":profile func Xprof \<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profile func Xprof ', @:) call feedkeys(":profile func X1B2C3\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profile func X1B2C3', @:) call feedkeys(":profdel \<C-A>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel file func', @:) call feedkeys(":profdel fu\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel func', @:) call feedkeys(":profdel he\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel he', @:) call feedkeys(":profdel here \<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel here ', @:) call feedkeys(":profdel file test_prof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel file test_profile.vim', @:) call feedkeys(":profdel file X1B2C3\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel file X1B2C3', @:) call feedkeys(":profdel func Xprof\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel func Xprof_test', @:) call feedkeys(":profdel func Xprof_test \<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel func Xprof_test ', @:) call feedkeys(":profdel func X1B2C3\<Tab>\<C-B>\"\<CR>", 'tx') call assert_equal('"profdel func X1B2C3', @:) delfunc Xprof_test endfunc func Test_profile_errors() call assert_fails("profile func Foo", 'E750:') call assert_fails("profile pause", 'E750:') call assert_fails("profile continue", 'E750:') call assert_fails("profile stop", 'E750:') call assert_fails("profile dump", 'E750:') endfunc func Test_profile_truncate_mbyte() if &enc !=# 'utf-8' return endif let lines = [ \ 'scriptencoding utf-8', \ 'func! Foo()', \ ' return [', \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",', \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",', \ ' \ ]', \ 'endfunc', \ 'call Foo()', \ ] call writefile(lines, 'Xprofile_file.vim', 'D') call system(GetVimCommandClean() \ . ' -es --cmd "set enc=utf-8"' \ . ' -c "profile start Xprofile_file.log"' \ . ' -c "profile file Xprofile_file.vim"' \ . ' -c "so Xprofile_file.vim"' \ . ' -c "qall!"') call assert_equal(0, v:shell_error) split Xprofile_file.log if &fenc != '' call assert_equal('utf-8', &fenc) endif /func! Foo() let lnum = line('.') call assert_match('^\s*return \[$', getline(lnum + 1)) call assert_match("\u4F52$", getline(lnum + 2)) call assert_match("\u5052$", getline(lnum + 3)) call assert_match('^\s*\\ \]$', getline(lnum + 4)) bwipe! call delete('Xprofile_file.log') endfunc func Test_profdel_func() let lines =<< trim [CODE] profile start Xprofile_file.log func! Foo1() endfunc func! Foo2() endfunc func! Foo3() endfunc profile func Foo1 profile func Foo2 call Foo1() call Foo2() profile func Foo3 profdel func Foo2 profdel func Foo3 call Foo1() call Foo2() call Foo3() [CODE] call writefile(lines, 'Xprofile_file.vim', 'D') call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_file.log') call assert_equal(26, len(lines)) " Check that: " - Foo1() is called twice (profdel not invoked) " - Foo2() is called once (profdel invoked after it was called) " - Foo3() is not called (profdel invoked before it was called) call assert_equal('FUNCTION Foo1()', lines[0]) call assert_match('Defined:.*Xprofile_file.vim', lines[1]) call assert_equal('Called 2 times', lines[2]) call assert_equal('FUNCTION Foo2()', lines[8]) call assert_equal('Called 1 time', lines[10]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21]) call delete('Xprofile_file.log') endfunc func Test_profdel_star() " Foo() is invoked once before and once after 'profdel *'. " So profiling should report it only once. let lines =<< trim [CODE] profile start Xprofile_file.log func! Foo() endfunc profile func Foo call Foo() profdel * call Foo() [CODE] call writefile(lines, 'Xprofile_file.vim', 'D') call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') call assert_equal(0, v:shell_error) let lines = readfile('Xprofile_file.log') call assert_equal(16, len(lines)) call assert_equal('FUNCTION Foo()', lines[0]) call assert_match('Defined:.*Xprofile_file.vim', lines[1]) call assert_equal('Called 1 time', lines[2]) call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8]) call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12]) call delete('Xprofile_file.log') endfunc " When typing the function it won't have a script ID, test that this works. func Test_profile_typed_func() CheckScreendump let lines =<< trim END profile start XprofileTypedFunc END call writefile(lines, 'XtestProfile', 'D') let buf = RunVimInTerminal('-S XtestProfile', #{}) call term_sendkeys(buf, ":func DoSomething()\<CR>" \ .. "echo 'hello'\<CR>" \ .. "endfunc\<CR>") call term_sendkeys(buf, ":profile func DoSomething\<CR>") call term_sendkeys(buf, ":call DoSomething()\<CR>") call TermWait(buf, 100) call StopVimInTerminal(buf) let lines = readfile('XprofileTypedFunc') call assert_equal("FUNCTION DoSomething()", lines[0]) call assert_equal("Called 1 time", lines[1]) " clean up call delete('XprofileTypedFunc') endfunc func Test_vim9_profiling() " only tests that compiling and calling functions doesn't crash let lines =<< trim END vim9script def Func() Crash() enddef def Crash() enddef prof start Xprofile_crash.log prof func Func Func() END call writefile(lines, 'Xprofile_crash.vim', 'D') call system(GetVimCommandClean() . ' -es -c "so Xprofile_crash.vim" -c q') call assert_equal(0, v:shell_error) call assert_true(readfile('Xprofile_crash.log')->len() > 10) call delete('Xprofile_crash.log') endfunc func Test_vim9_nested_call() let lines =<< trim END vim9script var total = 0 def One(Ref: func(number)) for i in range(3) Ref(i) endfor enddef def Two(nr: number) total += nr enddef prof start Xprofile_nested.log prof func One prof func Two One((nr) => Two(nr)) assert_equal(3, total) END call writefile(lines, 'Xprofile_nested.vim', 'D') call system(GetVimCommandClean() . ' -es -c "so Xprofile_nested.vim" -c q') call assert_equal(0, v:shell_error) let prof_lines = readfile('Xprofile_nested.log')->join('#') call assert_match('FUNCTION <SNR>\d\+_One().*' \ .. '#Called 1 time.*' \ .. '# 1 \s*[0-9.]\+ for i in range(3)' \ .. '# 3 \s*[0-9.]\+ \s*[0-9.]\+ Ref(i)' \ .. '# 3 \s*[0-9.]\+ endfor', prof_lines) call assert_match('FUNCTION <SNR>\d\+_Two().*' \ .. '#Called 3 times.*' \ .. '# 3 \s*[0-9.]\+ total += nr', prof_lines) call delete('Xprofile_nested.log') endfunc " vim: shiftwidth=2 sts=2 expandtab