scop / bash-completion

Programmable completion functions for bash
GNU General Public License v2.0
2.91k stars 380 forks source link

test: py.test fails due to timeout (cold cache) #137

Open mgorny opened 7 years ago

mgorny commented 7 years ago
Test run by mgorny on Sun Jul  2 10:09:40 2017
Native configuration is x86_64-pc-linux-gnu

        === completion tests ===

Schedule of variations:
    unix

Running target unix
Using /usr/share/dejagnu/baseboards/unix.exp as board description file for target.
Using /usr/share/dejagnu/config/unix.exp as generic interface file for target.
Using ./config/default.exp as tool-and-target-specific interface file.
Running ./completion/py.test.exp ...
exp_spawn bash --rcfile ./config/bashrc
/@echo $?
0
/@BASH_COMPLETION_COMPAT_DIR="$SRCDIR/fixtures/shared/empty_dir"
/@echo $?
0
/@source $(cd "$SRCDIR/.."; pwd)/bash_completion
/@echo $?
0
/@printf "%s" "$COMP_WORDBREAKS"

"'><=;|&(:/@echo $?
0
/@printf "%s " "${BASH_VERSINFO[@]}"
4 4 12 1 release x86_64-pc-linux-gnu /@echo $?
0
/@printf "%s" "$BASH_VERSION"
4.4.12(1)-release/@echo $?
0
/@printf "%s" "$TESTDIR"
/home/mgorny/git/bash-completion/test/@echo $?
0
/@eval $(locale); printf "%s" "$LC_CTYPE"
en_US.utf8/@echo $?
0
/@exec 6>'xtrace.log'
/@echo $?
0
/@BASH_XTRACEFD=6
/@echo $?
0
/@set -o xtrace
/@echo $?
0
/@type py.test &> /dev/null && echo -n 0 || echo -n 1
0/@__load_completion py.test ; complete -p py.test &> /dev/null && echo -n 0 || echo -n 1
0/@{ (set -o posix ; set); declare -F; shopt -p; set -o; } > "$TESTDIR/tmp/env.env1~"
/@echo $?
0
/@py.test 
completion/ config/     docker/     fixtures/   lib/        log/        log-full/   log-old/    tmp/        unit/
/@py.test PASS: py.test  should show completions
^C
/@py.test -FAIL: py.test - should show completions at timeout
FAIL: Sync after INT at timeout
{ (set -o posix ; set); declare -F; shopt -p; set -o; } > "$TESTDIR/tmp/env.env2~"
bash: błąd składni przy nieoczekiwanym znaczniku `('
/@FAIL: ERROR Unexpected output from bash command "{ (set -o posix ; set); declare -F; shopt -p; set -o; } > "$TESTDIR/tmp/env.env2~""
echo $?
2
/@FAIL: ERROR executing bash command "{ (set -o posix ; set); declare -F; shopt -p; set -o; } > "$TESTDIR/tmp/env.env2~""
diff_env "$TESTDIR/tmp/env.env1~" "$TESTDIR/tmp/env.env2~" "" LAST-ARG
/@PASS: Environment should not be modified
testcase ./completion/py.test.exp completed in 22 seconds

        === completion Summary ===

# of expected passes        2
# of unexpected failures    4
runtest completed at Sun Jul  2 10:10:02 2017

xtrace:

+ echo 0
+ type py.test
+ echo -n 0
+ __load_completion py.test
+ dirs=(${BASH_COMPLETION_USER_DIR:-${XDG_DATA_HOME:-$HOME/.local/share}/bash-completion}/completions)
+ local -a dirs
+ local 'OIFS=  
' IFS=: dir cmd=py.test compfile
+ for dir in ${XDG_DATA_DIRS:-/usr/local/share:/usr/share}
+ dirs+=($dir/bash-completion/completions)
+ for dir in ${XDG_DATA_DIRS:-/usr/local/share:/usr/share}
+ dirs+=($dir/bash-completion/completions)
+ for dir in ${XDG_DATA_DIRS:-/usr/local/share:/usr/share}
+ dirs+=($dir/bash-completion/completions)
+ for dir in ${XDG_DATA_DIRS:-/usr/local/share:/usr/share}
+ dirs+=($dir/bash-completion/completions)
+ IFS='     
'
+ [[ /home/mgorny/git/bash-completion/bash_completion == */* ]]
+ dirs+=("${BASH_SOURCE%/*}/completions")
+ for dir in "${dirs[@]}"
+ for compfile in "${cmd##*/}" "${cmd##*/}".bash _"${cmd##*/}"
+ compfile=/home/mgorny/git/bash-completion/completions/py.test
+ [[ -f /home/mgorny/git/bash-completion/completions/py.test ]]
+ . /home/mgorny/git/bash-completion/completions/py.test
++ complete -F _py_test py.test py.test-2 py.test-3
+ return 0
+ complete -p py.test
+ echo -n 0
+ set -o posix
+ set
+ declare -F
+ shopt -p
+ set -o
+ echo 0
+ local cur prev words cword split
+ _init_completion -s
+ local exclude= flag outx errx inx OPTIND=1
+ getopts n:e:o:i:s flag -s
+ case $flag in
+ split=false
+ exclude+==
+ getopts n:e:o:i:s flag -s
+ COMPREPLY=()
+ local 'redir=@(?([0-9])<|?([0-9&])>?(>)|>&)'
+ _get_comp_words_by_ref -n '=<>&' cur prev words cword
+ local exclude flag i OPTIND=1
+ words=()
+ local cur cword words
+ upargs=()
+ upvars=()
+ local upargs upvars vcur vcword vprev vwords
+ getopts c:i:n:p:w: flag -n '=<>&' cur prev words cword
+ case $flag in
+ exclude='=<>&'
+ getopts c:i:n:p:w: flag -n '=<>&' cur prev words cword
+ [[ 6 -ge 3 ]]
+ case ${!OPTIND} in
+ vcur=cur
+ let 'OPTIND += 1'
+ [[ 6 -ge 4 ]]
+ case ${!OPTIND} in
+ vprev=prev
+ let 'OPTIND += 1'
+ [[ 6 -ge 5 ]]
+ case ${!OPTIND} in
+ vwords=words
+ let 'OPTIND += 1'
+ [[ 6 -ge 6 ]]
+ case ${!OPTIND} in
+ vcword=cword
+ let 'OPTIND += 1'
+ [[ 6 -ge 7 ]]
+ __get_cword_at_cursor_by_ref '=<>&' words cword cur
+ words=()
+ local cword words
+ __reassemble_comp_words_by_ref '=<>&' words cword
+ local exclude i j line ref
+ [[ -n =<>& ]]
+ exclude='=<>&'
+ printf -v cword %s 1
+ [[ -n =<>& ]]
+ line='py.test '
+ (( i=0, j=0 ))
+ (( i < 2 ))
+ [[ 0 -gt 0 ]]
+ ref='words[0]'
+ printf -v 'words[0]' %s py.test
+ line=' '
+ [[ 0 == 1 ]]
+ (( i++, j++ ))
+ (( i < 2 ))
+ [[ 1 -gt 0 ]]
+ [[ '' == +([=<>&]) ]]
+ ref='words[1]'
+ printf -v 'words[1]' %s ''
+ line=' '
+ [[ 1 == 1 ]]
+ printf -v cword %s 1
+ (( i++, j++ ))
+ (( i < 2 ))
+ [[ 2 == 1 ]]
+ local i cur index=8 'lead=py.test '
+ [[ 8 -gt 0 ]]
+ [[ -n py.test  ]]
+ [[ -n py.test ]]
+ cur='py.test '
+ (( i = 0 ))
+ (( i <= cword ))
+ [[ 8 -ge 7 ]]
+ [[ py.test != \p\y\.\t\e\s\t ]]
+ [[ 0 -lt 1 ]]
+ local old_size=8
+ cur=' '
+ local new_size=1
+ index=1
+ (( ++i  ))
+ (( i <= cword ))
+ [[ 1 -ge 0 ]]
+ [[ '' != '' ]]
+ [[ 1 -lt 1 ]]
+ (( ++i  ))
+ (( i <= cword ))
+ [[ -n   ]]
+ [[ ! -n '' ]]
+ cur=
+ [[ 1 -lt 0 ]]
+ local words cword cur
+ _upvars -a2 words py.test '' -v cword 1 -v cur ''
+ ((  10  ))
+ ((  10  ))
+ case $1 in
+ [[ -n 2 ]]
+ printf %d 2
+ [[ -n words ]]
+ unset -v words
+ eval 'words=("${@:3:2}")'
++ words=("${@:3:2}")
+ shift 4
+ ((  6  ))
+ case $1 in
+ [[ -n cword ]]
+ unset -v cword
+ eval 'cword="$3"'
++ cword=1
+ shift 3
+ ((  3  ))
+ case $1 in
+ [[ -n cur ]]
+ unset -v cur
+ eval 'cur="$3"'
++ cur=
+ shift 3
+ ((  0  ))
+ [[ -n cur ]]
+ upvars+=("$vcur")
+ upargs+=(-v $vcur "$cur")
+ [[ -n cword ]]
+ upvars+=("$vcword")
+ upargs+=(-v $vcword "$cword")
+ [[ -n prev ]]
+ [[ 1 -ge 1 ]]
+ upvars+=("$vprev")
+ upargs+=(-v $vprev "${words[cword - 1]}")
+ [[ -n words ]]
+ upvars+=("$vwords")
+ upargs+=(-a${#words[@]} $vwords "${words[@]}")
+ ((  4  ))
+ local cur cword prev words
+ _upvars -v cur '' -v cword 1 -v prev py.test -a2 words py.test ''
+ ((  13  ))
+ ((  13  ))
+ case $1 in
+ [[ -n cur ]]
+ unset -v cur
+ eval 'cur="$3"'
++ cur=
+ shift 3
+ ((  10  ))
+ case $1 in
+ [[ -n cword ]]
+ unset -v cword
+ eval 'cword="$3"'
++ cword=1
+ shift 3
+ ((  7  ))
+ case $1 in
+ [[ -n prev ]]
+ unset -v prev
+ eval 'prev="$3"'
++ prev=py.test
+ shift 3
+ ((  4  ))
+ case $1 in
+ [[ -n 2 ]]
+ printf %d 2
+ [[ -n words ]]
+ unset -v words
+ eval 'words=("${@:3:2}")'
++ words=("${@:3:2}")
+ shift 4
+ ((  0  ))
+ _variables
+ [[ '' =~ ^(\$(\{[!#]?)?)([A-Za-z0-9_]*)$ ]]
+ [[ '' =~ ^(\$\{[#!]?)([A-Za-z0-9_]*)\[([^]]*)$ ]]
+ [[ '' =~ ^\$\{[#!]?[A-Za-z0-9_]*\[.*]$ ]]
+ case $prev in
+ return 1
+ [[ '' == @(?([0-9])<|?([0-9&])>?(>)|>&)* ]]
+ [[ py.test == @(?([0-9])<|?([0-9&])>?(>)|>&) ]]
+ local i skip
+ (( i=1 ))
+ (( i < 2 ))
+ [[ '' == @(?([0-9])<|?([0-9&])>?(>)|>&)* ]]
+ i=2
+ (( 1 ))
+ (( i < 2 ))
+ [[ 1 -le 0 ]]
+ prev=py.test
+ [[ -n false ]]
+ _split_longopt
+ [[ '' == --?*=* ]]
+ return 1
+ return 0
+ case $prev in
+ false
+ [[ '' == -* ]]
+ _filedir py
+ local 'IFS=
'
+ _tilde ''
+ local result=0
+ [[ '' == \~* ]]
+ return 0
+ local -a toks
+ local x tmp
++ compgen -d -- ''
+ x='tmp
completion
unit
log-full
docker
fixtures
log
log-old
lib
config'
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ toks+=("$tmp")
+ read -r tmp
+ [[ py != -d ]]
+ local quoted
+ _quote_readline_by_ref '' quoted
+ [[ '' == \'* ]]
+ printf -v quoted %q ''
+ [[ '' == \$* ]]
+ local 'xspec=!*.@(py|PY)'
++ compgen -f -X '!*.@(py|PY)' -- ''\'''\'''
+ x=
+ [[ -n '' ]]
+ [[ 10 -ne 0 ]]
+ compopt -o filenames
+ COMPREPLY+=("${toks[@]}")
+ local cur prev words cword split
+ _init_completion -s
+ local exclude= flag outx errx inx OPTIND=1
+ getopts n:e:o:i:s flag -s
+ case $flag in
+ split=false
+ exclude+==
+ getopts n:e:o:i:s flag -s
+ COMPREPLY=()
+ local 'redir=@(?([0-9])<|?([0-9&])>?(>)|>&)'
+ _get_comp_words_by_ref -n '=<>&' cur prev words cword
+ local exclude flag i OPTIND=1
+ words=()
+ local cur cword words
+ upargs=()
+ upvars=()
+ local upargs upvars vcur vcword vprev vwords
+ getopts c:i:n:p:w: flag -n '=<>&' cur prev words cword
+ case $flag in
+ exclude='=<>&'
+ getopts c:i:n:p:w: flag -n '=<>&' cur prev words cword
+ [[ 6 -ge 3 ]]
+ case ${!OPTIND} in
+ vcur=cur
+ let 'OPTIND += 1'
+ [[ 6 -ge 4 ]]
+ case ${!OPTIND} in
+ vprev=prev
+ let 'OPTIND += 1'
+ [[ 6 -ge 5 ]]
+ case ${!OPTIND} in
+ vwords=words
+ let 'OPTIND += 1'
+ [[ 6 -ge 6 ]]
+ case ${!OPTIND} in
+ vcword=cword
+ let 'OPTIND += 1'
+ [[ 6 -ge 7 ]]
+ __get_cword_at_cursor_by_ref '=<>&' words cword cur
+ words=()
+ local cword words
+ __reassemble_comp_words_by_ref '=<>&' words cword
+ local exclude i j line ref
+ [[ -n =<>& ]]
+ exclude='=<>&'
+ printf -v cword %s 1
+ [[ -n =<>& ]]
+ line='py.test -'
+ (( i=0, j=0 ))
+ (( i < 2 ))
+ [[ 0 -gt 0 ]]
+ ref='words[0]'
+ printf -v 'words[0]' %s py.test
+ line=' -'
+ [[ 0 == 1 ]]
+ (( i++, j++ ))
+ (( i < 2 ))
+ [[ 1 -gt 0 ]]
+ [[ - == +([=<>&]) ]]
+ ref='words[1]'
+ printf -v 'words[1]' %s -
+ line=
+ [[ 1 == 1 ]]
+ printf -v cword %s 1
+ (( i++, j++ ))
+ (( i < 2 ))
+ [[ 2 == 1 ]]
+ local i cur index=9 'lead=py.test -'
+ [[ 9 -gt 0 ]]
+ [[ -n py.test - ]]
+ [[ -n py.test- ]]
+ cur='py.test -'
+ (( i = 0 ))
+ (( i <= cword ))
+ [[ 9 -ge 7 ]]
+ [[ py.test != \p\y\.\t\e\s\t ]]
+ [[ 0 -lt 1 ]]
+ local old_size=9
+ cur=' -'
+ local new_size=2
+ index=2
+ (( ++i  ))
+ (( i <= cword ))
+ [[ 2 -ge 1 ]]
+ [[   != \- ]]
+ cur=-
+ [[ 2 -gt 0 ]]
+ (( index-- ))
+ [[ 1 -ge 1 ]]
+ [[ - != \- ]]
+ [[ 1 -lt 1 ]]
+ (( ++i  ))
+ (( i <= cword ))
+ [[ -n - ]]
+ [[ ! -n - ]]
+ [[ 1 -lt 0 ]]
+ local words cword cur
+ _upvars -a2 words py.test - -v cword 1 -v cur -
+ ((  10  ))
+ ((  10  ))
+ case $1 in
+ [[ -n 2 ]]
+ printf %d 2
+ [[ -n words ]]
+ unset -v words
+ eval 'words=("${@:3:2}")'
++ words=("${@:3:2}")
+ shift 4
+ ((  6  ))
+ case $1 in
+ [[ -n cword ]]
+ unset -v cword
+ eval 'cword="$3"'
++ cword=1
+ shift 3
+ ((  3  ))
+ case $1 in
+ [[ -n cur ]]
+ unset -v cur
+ eval 'cur="$3"'
++ cur=-
+ shift 3
+ ((  0  ))
+ [[ -n cur ]]
+ upvars+=("$vcur")
+ upargs+=(-v $vcur "$cur")
+ [[ -n cword ]]
+ upvars+=("$vcword")
+ upargs+=(-v $vcword "$cword")
+ [[ -n prev ]]
+ [[ 1 -ge 1 ]]
+ upvars+=("$vprev")
+ upargs+=(-v $vprev "${words[cword - 1]}")
+ [[ -n words ]]
+ upvars+=("$vwords")
+ upargs+=(-a${#words[@]} $vwords "${words[@]}")
+ ((  4  ))
+ local cur cword prev words
+ _upvars -v cur - -v cword 1 -v prev py.test -a2 words py.test -
+ ((  13  ))
+ ((  13  ))
+ case $1 in
+ [[ -n cur ]]
+ unset -v cur
+ eval 'cur="$3"'
++ cur=-
+ shift 3
+ ((  10  ))
+ case $1 in
+ [[ -n cword ]]
+ unset -v cword
+ eval 'cword="$3"'
++ cword=1
+ shift 3
+ ((  7  ))
+ case $1 in
+ [[ -n prev ]]
+ unset -v prev
+ eval 'prev="$3"'
++ prev=py.test
+ shift 3
+ ((  4  ))
+ case $1 in
+ [[ -n 2 ]]
+ printf %d 2
+ [[ -n words ]]
+ unset -v words
+ eval 'words=("${@:3:2}")'
++ words=("${@:3:2}")
+ shift 4
+ ((  0  ))
+ _variables
+ [[ - =~ ^(\$(\{[!#]?)?)([A-Za-z0-9_]*)$ ]]
+ [[ - =~ ^(\$\{[#!]?)([A-Za-z0-9_]*)\[([^]]*)$ ]]
+ [[ - =~ ^\$\{[#!]?[A-Za-z0-9_]*\[.*]$ ]]
+ case $prev in
+ return 1
+ [[ - == @(?([0-9])<|?([0-9&])>?(>)|>&)* ]]
+ [[ py.test == @(?([0-9])<|?([0-9&])>?(>)|>&) ]]
+ local i skip
+ (( i=1 ))
+ (( i < 2 ))
+ [[ - == @(?([0-9])<|?([0-9&])>?(>)|>&)* ]]
+ i=2
+ (( 1 ))
+ (( i < 2 ))
+ [[ 1 -le 0 ]]
+ prev=py.test
+ [[ -n false ]]
+ _split_longopt
+ [[ - == --?*=* ]]
+ return 1
+ return 0
+ case $prev in
+ false
+ [[ - == -* ]]
+ COMPREPLY=($( compgen -W '$( _parse_help "$1" )' -- "$cur" ))
++ compgen -W '$( _parse_help "$1" )' -- -
+++ _parse_help py.test
++++ quote py.test
++++ local quoted=py.test
++++ printf ''\''%s'\''' py.test
+++ eval local 'cmd='\''py.test'\'''
++++ local cmd=py.test
+++ local line
+++ read -r line
+++ case $cmd in
++++ dequote py.test
++++ eval printf %s py.test
+++++ printf %s py.test
+++ case $cmd in
+++ LC_ALL=C
+++ py.test --help
+ [[ '' == *= ]]
+ return
+ echo 2
+ diff_env /home/mgorny/git/bash-completion/test/tmp/env.env1~ /home/mgorny/git/bash-completion/test/tmp/env.env2~ '' LAST-ARG
+ diff /home/mgorny/git/bash-completion/test/tmp/env.env1~ /home/mgorny/git/bash-completion/test/tmp/env.env2~
+ sed -e '
# Remove diff line indicators
        /^[0-9,]\{1,\}[acd]/d
# Remove diff block separators
        /---/d
# Remove underscore variable
        /[<>] _=/d
# Remove PPID bash variable
        /[<>] PPID=/d
# Remove BASH_REMATCH bash variable
        /[<>] BASH_REMATCH=/d
# Remove functions starting with underscore
        /[<>] declare -f _/d
        '
+ exit

time needed for cold cache py.test --help:

real    0m37.943s
user    0m8.059s
sys 0m0.729s

Warm cache gets it down to ~8s. It's probably related to loading py.test plugins.

scop commented 7 years ago

Huh. On my SSD based system, warm cache, probably no py.test plugins installed:

$ time py.test --help >/dev/null

real    0m0.274s
user    0m0.242s
sys 0m0.031s
mgorny commented 7 years ago

Some of us are still running 5400 RPM spinning disks. And anyway, you can't really rely on people ensuring that the system is 100% idle when running tests. Some systems just have to deal with constant load.

mgorny commented 7 years ago

However, in this particular case it seems to be actually CPU-busy.

$ time py.test --version
This is pytest version 3.0.6, imported from /usr/lib64/python3.5/site-packages/pytest.py
setuptools registered plugins:
  pytest-timeout-1.2.0 at /usr/lib64/python3.5/site-packages/pytest_timeout.py
  pytest-subtesthack-0.1.1 at /usr/lib64/python3.5/site-packages/pytest_subtesthack.py
  pytest-pep8-1.0.6 at /usr/lib64/python3.5/site-packages/pytest_pep8.py
  pytest-mock-1.6.0 at /usr/lib64/python3.5/site-packages/pytest_mock.py
  pytest-localserver-0.3.7 at /usr/lib64/python3.5/site-packages/pytest_localserver/plugin.py
  pytest-httpbin-0.2.3 at /usr/lib64/python3.5/site-packages/pytest_httpbin/plugin.py
  pytest-cov-2.3.1 at /usr/lib64/python3.5/site-packages/pytest_cov/plugin.py
  hypothesis-3.6.1 at /usr/lib64/python3.5/site-packages/hypothesis/extra/pytestplugin.py
  betamax-0.8.0 at /usr/lib64/python3.5/site-packages/betamax/fixtures/pytest.py
  backports.unittest-mock-1.2.1 at /usr/lib64/python3.5/site-packages/backports/unittest_mock/__init__.py

real    0m7,461s
user    0m7,368s
sys 0m0,387s
scop commented 7 years ago

Sure, I'm not relying on anything. Just surprised to see especially almost two orders of magnitude slower warm cache times, they sound like something's wrong or misbehaving. My system isn't exactly new either, it's a 2012 i7 laptop.

scop commented 7 years ago

FWIW I just tested with the same set of plugins as you have in a freshly created virtualenv:

$ time py.test --version
This is pytest version 3.1.3, imported from /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest.py
setuptools registered plugins:
  pytest-timeout-1.2.0 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_timeout.py
  pytest-subtesthack-0.1.1 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_subtesthack.py
  pytest-pep8-1.0.6 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_pep8.py
  pytest-mock-1.6.2 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_mock.py
  pytest-localserver-0.3.7 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_localserver/plugin.py
  pytest-httpbin-0.2.3 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_httpbin/plugin.py
  pytest-cov-2.5.1 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/pytest_cov/plugin.py
  hypothesis-3.14.0 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/hypothesis/extra/pytestplugin.py
  betamax-0.8.0 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/betamax/fixtures/pytest.py
  backports.unittest-mock-1.3 at /home/scop/workspace/pyenv/versions/3.6.2/envs/testing/lib/python3.6/site-packages/backports/unittest_mock/__init__.py

real    0m0.956s
user    0m0.882s
sys 0m0.073s

Started removing plugins one by one, and have a hunch that the largest contributor to startup time was removal of pytest-httpbin.