`numpy.load` slows `runcell`

OverLordGoldDragon commented 3 years ago

Despite last command printing 0.0, runcell(3, ...) took several seconds. Strangely, shape = (2, ...) & dtype='float64', which is same size in memory, doesn't yield this effect; haven't tested with 'float32'. Also, IPython commands aren't slowed.

Using spyder 4.2.1 as conda doesn't have 4.2.2 yet; Win 10 x64, Python 3.7.9, numpy 1.19.2.

Code:

import numpy as np

X = np.random.randn(16, 16, 240, 24000).astype('float16')
np.save('arr.npy', X)

Restart kernel

import numpy as np
from time import time
out = np.load('arr.npy')

#%%
t0 = time()
t1 = time()

#%% 
print(t1 - t0)

juanis2112 commented 3 years ago

Hi @OverLordGoldDragon thanks for reporting this. @CAM-Gerlach can you take a look at this one?

CAM-Gerlach commented 3 years ago

Sorry for the delay @OverLordGoldDragon and the accidental close, thought I'd submitted this yesterday but I ended up hitting the wrong button instead.

I could not reproduce the problem described/shown in the video running Spyder 4.2.1 on Win 8.1 x64 under Anaconda with Python 3.7.9 and Numpy 1.19.2 (same config as the user in the video, minus Win version), nor with Numpy 1.18.5 from defaults, either by following the (incomplete) example code and procedure posted to this thread, or the different code and procedure shown in the video.

However, there certainly does appear to be something strange going on either pre- or post-execution of the actual cell code. Given the description, it seems possible it has something to do with strange behavior with half-precision floats, maybe something with hardware instructions/support (since unlike all the other Numpy formats, it was only recently standardized and implemented in hardware). Interestingly, my machine, despite being moderately performant, takes well over a minute to run the first instruction (regardless of data type) and the Spyder UI even hung for a good portion of that time (which it shouldn't, but unsure if related).

What I would suggest asking the user to do, to attempt to isolate the problem:

Try the same procedure as before, except running the code by selecting it and hitting the run lines/selection shortcut (F9 by default).
- If the problem does not re-occur, it would appears to be isolated to something with Spyder's runcell command, and can be investigated further
- If it does, try running the same lines in a Qtconsole instance in the same working environment (conda install qtconsole then jupyter qtconsole).
  - If it does re-occur, try with IPython and the standard Python interpreter and report it to Qtconsole, IPython or Numpy respectively depending on the last level it worked ata
  - If it does not, the problem may be with Spyder/Spyder-Kernels itself, and can be investigated further

Unless the problem occurs in QtConsole, please also report the full output of conda list in your working environment, try conda update numpy ipykernel jupyter_client spyder_kernels in the same, and try different Numpy verisons to determine if is isolated to any of them. Thanks, and best of luck!

OverLordGoldDragon commented 3 years ago

As noted in OP, IPython execution is unaffected, this includes F9 or running pasted code. I also don't reproduce this in an Anaconda python terminal. Below is after running conda install -c conda-forge spyder==4.2.3 and numpy==1.20.1 and conda update ipykernel jupyter_client spyder-kernels (didn't help).

conda list

``` # packages in environment at D:\Anaconda\envs\pyt: # # Name Version Build Channel _anaconda_depends 2020.07 py37_0 _ipyw_jlab_nb_ext_conf 0.1.0 py37_0 absl-py 0.10.0 pypi_0 pypi alabaster 0.7.12 py37_0 anaconda custom py37_1 anaconda-client 1.7.2 py37_0 anaconda-navigator 1.10.0 py37_0 anaconda-project 0.9.1 pyhd3eb1b0_1 appdirs 1.4.4 py_0 argh 0.26.2 py37_0 argon2-cffi 20.1.0 py37h2bbff1b_1 asn1crypto 1.4.0 py_0 astroid 2.4.2 py37_0 astropy 4.2 py37h2bbff1b_0 async_generator 1.10 py37h28b3542_0 atomicwrites 1.4.0 py_0 attrs 20.3.0 pyhd3eb1b0_0 audioread 2.1.8 py37hc8dfbb8_3 conda-forge autopep8 1.5.4 py_0 babel 2.9.0 pyhd3eb1b0_0 backcall 0.2.0 pyhd3eb1b0_0 backports 1.0 pyhd3eb1b0_2 backports.functools_lru_cache 1.6.1 pyhd3eb1b0_0 backports.shutil_get_terminal_size 1.0.0 pyhd3eb1b0_3 backports.tempfile 1.0 pyhd3eb1b0_1 backports.weakref 1.0.post1 py_1 bcrypt 3.2.0 py37he774522_0 beautifulsoup4 4.9.3 pyha847dfd_0 bitarray 1.6.3 py37h2bbff1b_1 bkcharts 0.2 py37_0 black 19.10b0 py_0 blas 1.0 mkl bleach 3.3.0 pyhd3eb1b0_0 blosc 1.10.2 pypi_0 pypi bokeh 2.2.3 py37_0 boto 2.49.0 py37_0 bottleneck 1.3.2 py37h2a96729_1 brotli 1.0.7 pypi_0 pypi brotlipy 0.7.0 py37h2bbff1b_1003 bzip2 1.0.8 he774522_0 ca-certificates 2021.1.19 haa95532_0 cachetools 4.1.1 pypi_0 pypi calmsize 0.1.3 pypi_0 pypi certifi 2020.12.5 py37haa95532_0 cffi 1.14.4 py37hcd4344a_0 chardet 4.0.0 py37haa95532_1003 charls 2.1.0 h33f27b4_2 click 7.1.2 pyhd3eb1b0_0 cloudpickle 1.6.0 py_0 clyent 1.2.2 py37_1 colorama 0.4.4 pyhd3eb1b0_0 comtypes 1.1.8 py37haa95532_1002 conda-package-handling 1.7.2 py37h76e460a_0 conda-verify 3.4.2 py_1 configparser 5.0.1 pypi_0 pypi console_shortcut 0.1.1 4 contextlib2 0.6.0.post1 py_0 cryptography 3.3.1 py37hcd4344a_0 cudatoolkit 10.1.243 h3826478_8 conda-forge cudnn 7.6.5 cuda10.1_0 cupy 8.3.0 py37hd4ca531_0 curl 7.71.1 h2a8f88b_1 cutensor 1.2.2.5 h1ba89ec_3 conda-forge cycler 0.10.0 py37_0 cython 0.29.21 py37hd77b12b_0 cytoolz 0.11.0 py37he774522_0 dask 2021.1.1 pyhd3eb1b0_0 dask-core 2021.1.1 pyhd3eb1b0_0 dataclasses 0.6 pypi_0 pypi decorator 4.4.2 pyhd3eb1b0_0 defusedxml 0.6.0 pyhd3eb1b0_0 diff-match-patch 20200713 py_0 distributed 2021.1.1 py37haa95532_1 docutils 0.16 py37_1 entrypoints 0.3 py37_0 et_xmlfile 1.0.1 py_1001 fastcache 1.1.0 py37he774522_0 fastrlock 0.5 py37ha925a31_0 fftw 3.3.9 h2bbff1b_1 filelock 3.0.12 pyhd3eb1b0_1 flake8 3.8.4 py_0 flask 1.1.2 pyhd3eb1b0_0 flask-compress 1.5.0 pypi_0 pypi freetype 2.10.4 hd328e21_0 fsspec 0.8.3 py_0 future 0.18.2 py37_1 get_terminal_size 1.0.0 h38e98db_0 gevent 21.1.1 py37h2bbff1b_1 giflib 5.2.1 h62dcd97_0 glob2 0.7 pyhd3eb1b0_0 gmpy2 2.0.8 py37h0964b28_3 google-auth 1.20.1 pypi_0 pypi google-auth-oauthlib 0.4.1 pypi_0 pypi greenlet 1.0.0 py37hd77b12b_2 grpcio 1.31.0 pypi_0 pypi h5py 2.10.0 py37h5e291fa_0 hdf5 1.10.4 h7ebc959_0 heapdict 1.0.1 py_0 html5lib 1.1 py_0 hypothesis 6.1.1 pyhd3eb1b0_0 icc_rt 2019.0.0 h0cc432a_1 icu 58.2 ha925a31_3 idna 2.10 pyhd3eb1b0_0 imagecodecs 2021.1.11 py37h5da4933_1 imageio 2.9.0 py_0 imagesize 1.2.0 pyhd3eb1b0_0 importlib-metadata 2.0.0 py_1 importlib_metadata 2.0.0 1 iniconfig 1.1.1 pyhd3eb1b0_0 intel-openmp 2020.2 254 intervaltree 3.1.0 py_0 ipykernel 5.3.4 py37h5ca1d4c_0 ipython 7.20.0 py37hd4e2768_1 ipython_genutils 0.2.0 pyhd3eb1b0_1 ipywidgets 7.6.3 pyhd3eb1b0_1 isort 5.7.0 pyhd3eb1b0_0 itsdangerous 1.1.0 py37_0 jdcal 1.4.1 py_0 jedi 0.17.2 py37haa95532_1 jinja2 2.11.3 pyhd3eb1b0_0 joblib 1.0.0 pyhd3eb1b0_0 jpeg 9b hb83a4c4_2 json5 0.9.5 py_0 jsonschema 3.2.0 py_2 jupyter 1.0.0 py37_7 jupyter_client 6.1.7 py_0 jupyter_console 6.2.0 py_0 jupyter_core 4.7.1 py37haa95532_0 jupyterlab 2.2.6 py_0 jupyterlab_pygments 0.1.2 py_0 jupyterlab_server 1.2.0 py_0 jupyterlab_widgets 1.0.0 pyhd3eb1b0_1 keyring 22.0.1 py37haa95532_0 kiwisolver 1.3.1 py37hd77b12b_0 krb5 1.18.2 hc04afaa_0 kymatio 0.2.0 pypi_0 pypi lazy-object-proxy 1.4.3 py37h2bbff1b_2 lcms2 2.11 hc51a39a_0 lerc 2.2.1 hd77b12b_0 libaec 1.0.4 h33f27b4_1 libarchive 3.4.2 h5e25573_0 libblas 3.9.0 1_h8933c1f_netlib conda-forge libcblas 3.9.0 3_hd5c7e75_netlib conda-forge libcurl 7.71.1 h2a8f88b_1 libdeflate 1.7 h2bbff1b_5 libflac 1.3.3 h6538335_0 conda-forge libiconv 1.15 h1df5818_7 liblapack 3.9.0 3_hd5c7e75_netlib conda-forge liblief 0.10.1 ha925a31_0 libllvm9 9.0.1 h21ff451_0 libogg 1.3.2 he774522_0 libpng 1.6.37 h2a8f88b_0 librosa 0.8.0 pyh9f0ad1d_0 conda-forge libsndfile 1.0.29 ha925a31_0 conda-forge libsodium 1.0.18 h62dcd97_0 libspatialindex 1.9.3 h33f27b4_0 libssh2 1.9.0 h7a1dbc1_1 libtiff 4.1.0 h56a325e_1 libuv 1.40.0 he774522_0 libvorbis 1.3.7 he774522_0 libxml2 2.9.10 hb89e7f3_3 libxslt 1.1.34 he774522_0 libzopfli 1.0.3 ha925a31_0 llvmlite 0.35.0 py37_0 numba locket 0.2.1 py37haa95532_1 lxml 4.6.2 py37h9b66d53_0 lz4-c 1.9.3 h2bbff1b_0 lzo 2.10 he774522_2 m2w64-gcc-libgfortran 5.3.0 6 m2w64-gcc-libs 5.3.0 7 m2w64-gcc-libs-core 5.3.0 7 m2w64-gmp 6.1.0 2 m2w64-libwinpthread-git 5.0.0.4634.697f757 2 mako 1.1.4 pypi_0 pypi markdown 3.2.2 pypi_0 pypi markupsafe 1.1.1 py37hfa6e2cd_1 matplotlib 3.3.2 haa95532_0 matplotlib-base 3.3.2 py37hba9282a_0 mccabe 0.6.1 py37_1 menuinst 1.4.16 py37he774522_1 mistune 0.8.4 py37hfa6e2cd_1001 mkl 2020.2 256 mkl-service 2.3.0 py37h196d8e1_0 mkl_fft 1.2.0 py37h45dec08_0 mkl_random 1.1.1 py37h47e9c7a_0 mock 4.0.3 pyhd3eb1b0_0 more-itertools 8.6.0 pyhd3eb1b0_0 mpc 1.1.0 h7edee0f_1 mpfr 4.0.2 h62dcd97_1 mpir 3.0.0 hec2e145_1 mpmath 1.1.0 py37_0 msgpack-python 1.0.2 py37h59b6b97_1 msys2-conda-epoch 20160418 1 multipledispatch 0.6.0 py37_0 mypy_extensions 0.4.3 py37_0 navigator-updater 0.2.1 py37_0 nbclient 0.5.3 pyhd3eb1b0_0 nbconvert 6.0.7 py37_0 nbformat 5.1.2 pyhd3eb1b0_1 ndim 0.1.4 pypi_0 pypi nest-asyncio 1.5.1 pyhd3eb1b0_0 networkx 2.5 py_0 ninja 1.10.2 py37h6d14046_0 nltk 3.5 py_0 nose 1.3.7 pyhd3eb1b0_1006 notebook 6.2.0 py37haa95532_0 numba 0.52.0 np1.11py3.7hf9181ef_g18825058a_0 numba numexpr 2.7.2 py37hcbcaa1e_0 numpy 1.20.1 py37hd20adf4_0 conda-forge numpy-base 1.18.5 py37hc3f5095_0 numpydoc 1.1.0 pyhd3eb1b0_1 oauthlib 3.1.0 pypi_0 pypi olefile 0.46 py37_0 openjpeg 2.3.0 h5ec785f_1 openpyxl 3.0.6 pyhd3eb1b0_0 openssl 1.1.1j h2bbff1b_0 orthopy 0.8.4 pypi_0 pypi packaging 20.9 pyhd3eb1b0_0 pandas 1.2.1 py37hf11a4ad_0 pandoc 2.11 h9490d1a_0 pandocfilters 1.4.3 py37haa95532_1 paramiko 2.7.2 py_0 parso 0.7.0 py_0 partd 1.1.0 py_0 path 15.1.0 py37haa95532_0 path.py 12.5.0 0 pathlib2 2.3.5 py37haa95532_2 pathspec 0.7.0 py_0 pathtools 0.1.2 py_1 patsy 0.5.1 py37_0 pep8 1.7.1 py37_0 pexpect 4.8.0 pyhd3eb1b0_3 pickleshare 0.7.5 pyhd3eb1b0_1003 pillow 8.1.0 py37h4fa10fc_0 pip 20.3.3 pypi_0 pypi pkginfo 1.7.0 py37haa95532_0 plotly 4.9.0 pypi_0 pypi pluggy 0.13.1 py37_0 ply 3.11 py37_0 pooch 1.2.0 py_0 conda-forge powershell_shortcut 0.0.1 3 prometheus_client 0.9.0 pyhd3eb1b0_0 prompt-toolkit 3.0.8 py_0 prompt_toolkit 3.0.8 0 protobuf 3.13.0 pypi_0 pypi psutil 5.8.0 py37h2bbff1b_1 ptyprocess 0.7.0 pyhd3eb1b0_2 py 1.10.0 pyhd3eb1b0_0 py-lief 0.10.1 py37ha925a31_0 py-lz4framed 0.14.0 pypi_0 pypi pyasn1 0.4.8 pypi_0 pypi pyasn1-modules 0.2.8 pypi_0 pypi pycodestyle 2.6.0 pyhd3eb1b0_0 pycosat 0.6.3 py37h2bbff1b_0 pycparser 2.20 py_2 pycrypto 2.6.1 py37he774522_10 pycurl 7.43.0.6 py37h7a1dbc1_0 pydocstyle 5.1.1 py_0 pyerfa 1.7.2 py37h2bbff1b_0 pyfftw 0.12.0 py37hac947ee_2 conda-forge pyflakes 2.2.0 pyhd3eb1b0_0 pygments 2.7.4 pyhd3eb1b0_0 pylint 2.6.0 py37_0 pyls-black 0.4.6 hd3eb1b0_0 pyls-spyder 0.3.2 pyhd3eb1b0_0 pynacl 1.4.0 py37h62dcd97_1 pyodbc 4.0.30 py37ha925a31_0 pyopenssl 20.0.1 pyhd3eb1b0_1 pyparsing 2.4.7 pyhd3eb1b0_0 pyqt 5.9.2 py37h6538335_2 pyreadline 2.1 py37_1 pyrsistent 0.17.3 py37he774522_0 pysocks 1.7.1 py37_1 pysoundfile 0.10.2 py_1001 conda-forge pytables 3.6.1 py37h1da0976_0 pytest 6.2.2 py37haa95532_2 pytest-arraydiff 0.3 py37h39e3cac_0 pytest-astropy 0.8.0 pyhd3eb1b0_0 pytest-astropy-header 0.1.2 pyhd3eb1b0_0 pytest-doctestplus 0.9.0 pyhd3eb1b0_0 pytest-openfiles 0.5.0 pyhd3eb1b0_0 pytest-remotedata 0.3.2 py37_0 python 3.7.9 h60c2a47_0 python-dateutil 2.8.1 pyhd3eb1b0_0 python-jsonrpc-server 0.4.0 py_0 python-language-server 0.36.2 pyhd3eb1b0_0 python-libarchive-c 2.9 pyhd3eb1b0_0 python_abi 3.7 1_cp37m conda-forge pytools 2021.1 pypi_0 pypi pytorch 1.7.1 py3.7_cuda101_cudnn7_0 pytorch pytorch-lightning 0.9.0 pypi_0 pypi pytorch-memlab 0.2.3 pypi_0 pypi pytz 2021.1 pyhd3eb1b0_0 pywavelets 1.1.1 py37he774522_2 pywin32 227 py37he774522_1 pywin32-ctypes 0.2.0 py37_1001 pywinpty 0.5.7 py37_0 pyyaml 5.4.1 py37h2bbff1b_1 pyzmq 20.0.0 py37hd77b12b_1 qdarkstyle 2.8.1 py_0 qt 5.9.7 vc14h73c81de_0 qtawesome 1.0.1 py_0 qtconsole 5.0.2 pyhd3eb1b0_0 qtpy 1.9.0 py_0 quadpy 0.16.3 pypi_0 pypi regex 2020.11.13 py37h2bbff1b_0 requests 2.25.1 pyhd3eb1b0_0 requests-oauthlib 1.3.0 pypi_0 pypi resampy 0.2.2 py_0 conda-forge retrying 1.3.3 py37_2 rope 0.18.0 py_0 rsa 4.6 pypi_0 pypi rtree 0.9.4 py37h21ff451_1 ruamel_yaml 0.15.87 py37he774522_1 scikit-image 0.17.2 py37h1e1f486_0 scikit-learn 0.23.2 py37h47e9c7a_0 scipy 1.6.0 py37h14eb087_0 seaborn 0.11.1 pyhd3eb1b0_0 see-rnn 1.15.1 pypi_0 pypi send2trash 1.5.0 pyhd3eb1b0_1 setuptools 54.0.0 pypi_0 pypi simplegeneric 0.8.1 py37_2 simpleitk 2.0.1 py37ha925a31_0 simpleitk singledispatch 3.4.0.3 py_1001 sip 4.19.8 py37h6538335_0 six 1.15.0 py37haa95532_0 snappy 1.1.8 h33f27b4_0 snowballstemmer 2.1.0 pyhd3eb1b0_0 sortedcollections 2.1.0 pyhd3eb1b0_0 sortedcontainers 2.3.0 pyhd3eb1b0_0 soupsieve 2.1 pyhd3eb1b0_0 sphinx 3.4.3 pyhd3eb1b0_0 sphinxcontrib 1.0 py37_1 sphinxcontrib-applehelp 1.0.2 pyhd3eb1b0_0 sphinxcontrib-devhelp 1.0.2 pyhd3eb1b0_0 sphinxcontrib-htmlhelp 1.0.3 pyhd3eb1b0_0 sphinxcontrib-jsmath 1.0.1 pyhd3eb1b0_0 sphinxcontrib-qthelp 1.0.3 pyhd3eb1b0_0 sphinxcontrib-serializinghtml 1.1.4 pyhd3eb1b0_0 sphinxcontrib-websupport 1.2.4 py_0 spyder 4.2.3 py37h03978a9_0 conda-forge spyder-kernels 1.10.2 py37haa95532_0 sqlalchemy 1.3.23 py37h2bbff1b_0 sqlite 3.33.0 h2a8f88b_0 statsmodels 0.12.1 py37h2bbff1b_0 sympy 1.7.1 py37haa95532_0 tbb 2020.3 h74a9793_0 tblib 1.7.0 py_0 tensorboard 2.2.0 pypi_0 pypi tensorboard-plugin-wit 1.7.0 pypi_0 pypi termcolor 1.1.0 py37_1 terminado 0.9.2 py37haa95532_0 testpath 0.4.4 pyhd3eb1b0_0 textdistance 4.2.1 pyhd3eb1b0_0 threadpoolctl 2.1.0 pyh5ca1d4c_0 three-merge 0.1.1 pyhd3eb1b0_0 tifffile 2021.1.14 pyhd3eb1b0_1 tk 8.6.10 he774522_0 toml 0.10.1 py_0 toolz 0.11.1 pyhd3eb1b0_0 torchvision 0.8.2 py37_cu101 pytorch tornado 6.1 py37h2bbff1b_0 tqdm 4.56.0 pyhd3eb1b0_0 traitlets 5.0.5 pyhd3eb1b0_0 typed-ast 1.4.2 py37h2bbff1b_1 typing_extensions 3.7.4.3 pyha847dfd_0 ujson 4.0.2 py37hd77b12b_0 unicodecsv 0.14.1 py37_0 urllib3 1.26.3 pyhd3eb1b0_0 vc 14.2 h21ff451_1 vs2015_runtime 14.27.29016 h5e58377_2 watchdog 1.0.2 py37haa95532_1 wcwidth 0.2.5 py_0 webencodings 0.5.1 py37_1 werkzeug 1.0.1 pyhd3eb1b0_0 wheel 0.36.2 pyhd3eb1b0_0 widgetsnbextension 3.5.1 py37_0 win_inet_pton 1.1.0 py37haa95532_0 win_unicode_console 0.5 py37_0 wincertstore 0.2 py37_0 winpty 0.4.3 4 wrapt 1.11.2 py37he774522_0 xlrd 2.0.1 pyhd3eb1b0_0 xlsxwriter 1.3.7 pyhd3eb1b0_0 xlwings 0.22.0 py37haa95532_0 xlwt 1.3.0 py37_0 xmltodict 0.12.0 py_0 xz 5.2.5 h62dcd97_0 yaml 0.2.5 he774522_0 yapf 0.30.0 py_0 zeromq 4.3.3 ha925a31_3 zfp 0.5.5 hd77b12b_4 zict 2.0.0 pyhd3eb1b0_0 zipp 3.4.0 pyhd3eb1b0_0 zlib 1.2.11 h62dcd97_4 zope 1.0 py37_1 zope.event 4.5.0 py37_0 zope.interface 5.2.0 py37h2bbff1b_0 zstd 1.4.5 h04227a9_0 ```

CAM-Gerlach commented 3 years ago

Thanks for the detailed information, @OverLordGoldDragon . What about runfile (F5 by default)? Also, is the environment you've provided your Spyder environment (the environment from which you've launched Spyder), your working environment (the environment in which your code runs in the IPython Console), or both? Also, since we have not been able to reproduce it ourselves, could you test it in a clean working environment, i.e. one created with conda create -n test-env-name spyder-kernels=1 numpy python=3?

The above environment has many critical packages installed from the defaults Anaconda stack (mkl, python, spyder_kernels, etc.), others from the conda-forge stack (including Spyder, Numpy and supporting libraries), and still others from PyPI (standard library backports, other assorted packages), plus a few from independent channels (that should be fine). While this can sometimes work if you're very careful, it is not supported by Anaconda/CF as they are not fully ABI-compatible and numerous tricky errors can result, especially when it comes to low-level interactions like this. This may or may not be the direct cause of the problem, but this will allow us to eliminate most of the variability between your setup and ours, to maximize the chances of reproducing the problem on our end so it can be fixed, and if we're still unable, narrow down what could be the cause. Thanks.

Also, @bcolsen , as you implemented the runcell function in question, any insight here?

OverLordGoldDragon commented 3 years ago

Both @ envs. Ran conda create -n test-env-name spyder-kernels=1 numpy python=3, conda install spyder, same results. This time I went ahead and interrupted it mid-delay:

Traceback (most recent call last):

  File "<ipython-input-3-fa3bc9be62af>", line 1, in <module>
    runcell(2, 'C:/Desktop/School/Deep Learning/DL_Code/signals/untitled0.py')

  File "D:\Anaconda\envs\test-env-name\lib\site-packages\spyder_kernels\customize\spydercustomize.py", line 634, in runcell
    cell_code = frontend_request().run_cell(cellname, filename)

  File "D:\Anaconda\envs\test-env-name\lib\site-packages\spyder_kernels\comms\commbase.py", line 554, in __call__
    return self._comms_wrapper._get_call_return_value(

  File "D:\Anaconda\envs\test-env-name\lib\site-packages\spyder_kernels\comms\commbase.py", line 432, in _get_call_return_value
    self._wait_reply(call_id, call_name, timeout)

  File "D:\Anaconda\envs\test-env-name\lib\site-packages\spyder_kernels\comms\frontendcomm.py", line 181, in _wait_reply
    if not self.wait_until(reply_received):

  File "D:\Anaconda\envs\test-env-name\lib\site-packages\spyder_kernels\comms\frontendcomm.py", line 172, in wait_until
    time.sleep(0.01)

KeyboardInterrupt

conda list

``` # packages in environment at D:\Anaconda\envs\test-env-name: # # Name Version Build Channel alabaster 0.7.12 pyhd3eb1b0_0 appdirs 1.4.4 py_0 argh 0.26.2 py38_0 astroid 2.5 py38haa95532_1 async_generator 1.10 pyhd3eb1b0_0 atomicwrites 1.4.0 py_0 attrs 20.3.0 pyhd3eb1b0_0 autopep8 1.5.5 pyhd3eb1b0_0 babel 2.9.0 pyhd3eb1b0_0 backcall 0.2.0 pyhd3eb1b0_0 bcrypt 3.2.0 py38he774522_0 black 19.10b0 py_0 blas 1.0 mkl bleach 3.3.0 pyhd3eb1b0_0 brotlipy 0.7.0 py38h2bbff1b_1003 ca-certificates 2021.1.19 haa95532_0 certifi 2020.12.5 py38haa95532_0 cffi 1.14.5 py38hcd4344a_0 chardet 4.0.0 py38haa95532_1003 click 7.1.2 pyhd3eb1b0_0 cloudpickle 1.6.0 py_0 colorama 0.4.4 pyhd3eb1b0_0 cryptography 3.3.1 py38hcd4344a_1 decorator 4.4.2 pyhd3eb1b0_0 defusedxml 0.7.0 pyhd3eb1b0_0 diff-match-patch 20200713 py_0 docutils 0.16 py38_1 entrypoints 0.3 py38_0 flake8 3.8.4 py_0 future 0.18.2 py38_1 icu 58.2 ha925a31_3 idna 2.10 pyhd3eb1b0_0 imagesize 1.2.0 pyhd3eb1b0_0 importlib-metadata 2.0.0 py_1 importlib_metadata 2.0.0 1 intel-openmp 2020.2 254 intervaltree 3.1.0 py_0 ipykernel 5.3.4 py38h5ca1d4c_0 ipython 7.21.0 py38hd4e2768_0 ipython_genutils 0.2.0 pyhd3eb1b0_1 isort 5.7.0 pyhd3eb1b0_0 jedi 0.17.2 py38haa95532_1 jinja2 2.11.3 pyhd3eb1b0_0 jpeg 9b hb83a4c4_2 jsonschema 3.2.0 py_2 jupyter_client 6.1.7 py_0 jupyter_core 4.7.1 py38haa95532_0 jupyterlab_pygments 0.1.2 py_0 keyring 22.3.0 py38haa95532_0 lazy-object-proxy 1.5.2 py38h2bbff1b_0 libpng 1.6.37 h2a8f88b_0 libsodium 1.0.18 h62dcd97_0 libspatialindex 1.9.3 h33f27b4_0 markupsafe 1.1.1 py38he774522_0 mccabe 0.6.1 py38_1 mistune 0.8.4 py38he774522_1000 mkl 2020.2 256 mkl-service 2.3.0 py38h196d8e1_0 mkl_fft 1.3.0 py38h46781fe_0 mkl_random 1.1.1 py38h47e9c7a_0 mypy_extensions 0.4.3 py38_0 nbclient 0.5.3 pyhd3eb1b0_0 nbconvert 6.0.7 py38_0 nbformat 5.1.2 pyhd3eb1b0_1 nest-asyncio 1.5.1 pyhd3eb1b0_0 numpy 1.19.2 py38hadc3359_0 numpy-base 1.19.2 py38ha3acd2a_0 numpydoc 1.1.0 pyhd3eb1b0_1 openssl 1.1.1j h2bbff1b_0 packaging 20.9 pyhd3eb1b0_0 pandoc 2.11 h9490d1a_0 pandocfilters 1.4.3 py38haa95532_1 paramiko 2.7.2 py_0 parso 0.7.0 py_0 pathspec 0.7.0 py_0 pexpect 4.8.0 pyhd3eb1b0_3 pickleshare 0.7.5 pyhd3eb1b0_1003 pip 21.0.1 py38haa95532_0 pluggy 0.13.1 py38_0 prompt-toolkit 3.0.8 py_0 psutil 5.8.0 py38h2bbff1b_1 ptyprocess 0.7.0 pyhd3eb1b0_2 pycodestyle 2.6.0 pyhd3eb1b0_0 pycparser 2.20 py_2 pydocstyle 5.1.1 py_0 pyflakes 2.2.0 pyhd3eb1b0_0 pygments 2.8.0 pyhd3eb1b0_0 pylint 2.7.2 py38haa95532_1 pyls-black 0.4.6 hd3eb1b0_0 pyls-spyder 0.3.2 pyhd3eb1b0_0 pynacl 1.4.0 py38h62dcd97_1 pyopenssl 20.0.1 pyhd3eb1b0_1 pyparsing 2.4.7 pyhd3eb1b0_0 pyqt 5.9.2 py38ha925a31_4 pyrsistent 0.17.3 py38he774522_0 pysocks 1.7.1 py38haa95532_0 python 3.8.8 hdbf39b2_4 python-dateutil 2.8.1 pyhd3eb1b0_0 python-jsonrpc-server 0.4.0 py_0 python-language-server 0.36.2 pyhd3eb1b0_0 pytz 2021.1 pyhd3eb1b0_0 pywin32 227 py38he774522_1 pywin32-ctypes 0.2.0 py38_1000 pyyaml 5.4.1 py38h2bbff1b_1 pyzmq 20.0.0 py38hd77b12b_1 qdarkstyle 2.8.1 py_0 qt 5.9.7 vc14h73c81de_0 qtawesome 1.0.1 py_0 qtconsole 5.0.2 pyhd3eb1b0_0 qtpy 1.9.0 py_0 regex 2020.11.13 py38h2bbff1b_0 requests 2.25.1 pyhd3eb1b0_0 rope 0.18.0 py_0 rtree 0.9.4 py38h21ff451_1 setuptools 52.0.0 py38haa95532_0 sip 4.19.13 py38ha925a31_0 six 1.15.0 py38haa95532_0 snowballstemmer 2.1.0 pyhd3eb1b0_0 sortedcontainers 2.3.0 pyhd3eb1b0_0 sphinx 3.5.1 pyhd3eb1b0_0 sphinxcontrib-applehelp 1.0.2 pyhd3eb1b0_0 sphinxcontrib-devhelp 1.0.2 pyhd3eb1b0_0 sphinxcontrib-htmlhelp 1.0.3 pyhd3eb1b0_0 sphinxcontrib-jsmath 1.0.1 pyhd3eb1b0_0 sphinxcontrib-qthelp 1.0.3 pyhd3eb1b0_0 sphinxcontrib-serializinghtml 1.1.4 pyhd3eb1b0_0 spyder 4.2.1 py38haa95532_1 spyder-kernels 1.10.2 py38haa95532_0 sqlite 3.33.0 h2a8f88b_0 testpath 0.4.4 pyhd3eb1b0_0 textdistance 4.2.1 pyhd3eb1b0_0 three-merge 0.1.1 pyhd3eb1b0_0 toml 0.10.1 py_0 tornado 6.1 py38h2bbff1b_0 traitlets 5.0.5 pyhd3eb1b0_0 typed-ast 1.4.2 py38h2bbff1b_1 typing_extensions 3.7.4.3 pyha847dfd_0 tzdata 2020f h52ac0ba_0 ujson 4.0.2 py38hd77b12b_0 urllib3 1.26.3 pyhd3eb1b0_0 vc 14.2 h21ff451_1 vs2015_runtime 14.27.29016 h5e58377_2 watchdog 1.0.2 py38haa95532_1 wcwidth 0.2.5 py_0 webencodings 0.5.1 py38_1 wheel 0.36.2 pyhd3eb1b0_0 win_inet_pton 1.1.0 py38haa95532_0 wincertstore 0.2 py38_0 wrapt 1.12.1 py38he774522_1 yaml 0.2.5 he774522_0 yapf 0.30.0 py_0 zeromq 4.3.3 ha925a31_3 zipp 3.4.0 pyhd3eb1b0_0 zlib 1.2.11 h62dcd97_4 ```

CAM-Gerlach commented 3 years ago

Okay, thanks so much for your help trying to narrow this down. BTW, it wasn't actually necessary to install Spyder in the new environment, but all the better I guess to ensure everything was clean Spyder-side too. I tested an identical environment following the procedure shown in your video, and could still not reproduce the error, the cells have the expected runtime.

I do note that g. for me, the first cell takes around a minute to run and the second several seconds, while the remaining are instant, while for you, the third cell takes very long, and the fourth a much shorter but still non-trivial amount of time, similar to the behavior I'm seeing for my first and second. Are you verifying, e.g. in the Variable Explorer, that the first and cell are actually getting executed when you run them? The wrong cells being sent to the console would certainly explain this behavior.

Also, can you try enabling Copy full cell contents to the console when running code cells under Editor ---> Run Code in Spyder's preferences?

Other than that, if none of these provide any further clues, it is difficult for me to do much more from a troubleshooting perspective if I cannot reproduce the problem, so I would defer to @bcolsen who is most familiar with the code in question and may be able to infer better what is happening. Thanks!

bcolsen commented 3 years ago

This seem tricky to reproduce. I am seeing about 30 sec on cell one and the rest are instantaneous.

I made the original attempt at runcell() but it's been re-implemented since then the right way :-)

@impact27 Any ideas?

sawtw commented 3 years ago

Hey guys, I can reproduce this behavior if "Show arrays min/max" in variable explorer is active - no matter if variable explorer is shown or not. So it seems that whenever statististics updates are triggered for large arrays the whole program gets irresponsive. I had the same problem a little while ago and worked around it by using a variable name that was not shown in variable explorer (e.g. "__variable" with "Exclude private references" active) or by just deactivating statistics. Hope this helps?! (Win 10, Spyder 4.2.1)

impact27 commented 3 years ago

(16, 16, 240, 24000) is a large size, maybe it is coputing the min/max at each step when it sends the namespace view to the frontend? It wouldn't be related to runcell then.

OverLordGoldDragon commented 3 years ago

It takes much less time to compute .min(), .max(), .mean() than however long Spyder is taking. And the behavior is exclusive to runcell; code ran in IPython console, whether pasted, or F9'd, or typed, is fine. And again, this concerns float16; float64, which is 4x the size, doesn't affect runcell.

CAM-Gerlach commented 3 years ago

@OverLordGoldDragon Can you confirm whether the option @sawtw mentions affects whether this slowdown occurs for you?

It takes much less time to compute .min(), .max(), .mean() than however long Spyder is taking.

Yes, but it could be computing it at individual substeps, it could be due to I/O serializing and deserializing the large array, there could be resource contention issues going on during the computation, it could be recomputing the whole array, etc.

And again, this concerns float16; float64, which is 4x the size, doesn't affect runcell.

As discussed above, float16 (IEEE Half Precision Float) is a far more recent standard than the others, and could be affected greatly by incomplete, buggy or not present support in hardware or the software toolchain. On a 64 bit CPU, without specific packing optimizations, vectorization, etc, typically only found on the very latest/high end processors these could easily perform at the same speed or much slower than their larger counterparts, depending on whether on what resources bound the operation and other complex factors.

OverLordGoldDragon commented 3 years ago

enabling Copy full cell contents to the console when running code cells under Editor ---> Run Code

I misunderstood this suggestion at first; so both run via "runcell" commands, but enabling this simply pastes to IPython rather than executing runcell; I confirm the slowdown disappears with this option.

it could be recomputing the whole array

This sounds... excessive, and not what Spyder ever seems to do as I regularly work with arrays that occupy 80%+ RAM. I also don't even have the Variable Explorer pane opened.

affected greatly by incomplete, buggy or not present support in hardware or the software toolchain

But it runs fine in IPython; if runcell is taking some extra steps, like computing stats for panes that aren't even opened, those could be looked into.

impact27 commented 3 years ago

One solution would be to profile the kernel. Create a file called kernel.py:

from spyder_kernels.console import start
start.main()

And run it from a terminal: python -m cProfile -o out.txt "kernel.py" This will give you a text like:

NOTE: When using the `ipython kernel` entry point, Ctrl-C will not work.

To exit, you will have to explicitly quit this process, by either sending
"quit" from a client, or using Ctrl-\ in UNIX-like environments.

To read more about this, see https://github.com/ipython/ipython/issues/2049

To connect another client to this kernel, use:
    --existing kernel-904.json

Copy kernel-904.json and paste it in "Consoles > Connect to an existing kernel"
Run whatever takes time several times, so that most of the kernel lifetime is spent computing the slow thing.
Run quit() to quit the kernel
Now you should have the information about the heaviest trace in out.txt

sawtw commented 3 years ago

One solution would be to profile the kernel. Create a file called kernel.py: [...]

I tried this, it worked as you described, however, the lagging is gone in this scenario.

bcolsen commented 3 years ago

I can confirm that this is due to min max in the variable explorer. X takes 30 seconds to compute on my box and X.max() takes about 13 seconds. It seems that variable explorer is recomputing the min max of every variable in the explorer when it gets the call to refresh after runcell or runfile. If the variable explorer is busy when runcell or runfile is

@OverLordGoldDragon @sawtw thanks for helping get to the bottom of this! Here is a work around: Open variable explorer, right click on the table and uncheck "show arrays min/max" wait for a while for the explorer to refresh and then it should be speedy again.

Debugging

Issue 1: Varible Exporer updates every variable regardless of change

With one array in the variable explorer and min/max enabled, it takes about 26 seconds to refresh the variable explorer. This is regardless of whether the array has changed. Just just running t0 = time() in either IPython directly of through runcell it takes ~26 s for the variable explorer to update.

I don't know if there is much to be done here. Perhaps we check the array size and don't give min/max past a certain size.

Issue 2: `Runcell` and `runfile` seem to wait for comms from variable explorer.

The issue for this bug is that runcell gets stuck in comms if variable explorer is already updating. If you use runcell and variable explorer is finished updating, runcell work just fine. I only gets stuck when you are running one cell right after the other. The first cell you run will return normally while the next cell waits until the update in the variable explorer to from the previous cell is finished.

Does the variable explorer need to respond to runcell or is it good enough to just assume it will update.

OverLordGoldDragon commented 3 years ago

@bcolsen Works. @CAM-Gerlach 's intuition was correct, the max() and min() take much longer with 'float16' than 'float64', which I wouldn't expect. An obvious improvement to keeping min/max is to only recompute if the variable is modified - as to how doable it is, no clue.

Thanks to all who contributed; feel free to close the issue.

OverLordGoldDragon commented 3 years ago

Unsure if related but long delays in IPdb on every step are also gone after disabling min/max in variable explorer.

CAM-Gerlach commented 3 years ago

Seems probable that after every IPdb step the min/max of all arrays gets recomputed as well, thus causing similar delays.

impact27 commented 3 years ago

Maybe we should add a message saying: "Computing min/max for the current variables took more than 2 seconds. Do you want to disable automatic variable explorer refreshing?"

impact27 commented 3 years ago

Minimum code to reproduce: Run in the console:

class A():
    def __len__(self):
        import time
        time.sleep(10)
        return 10
a = A()

Any call to runcell or runfile will be super slow after that.

impact27 commented 3 years ago

The best solution is likely that get_namespace_view should be run in a thread?

spyder-ide / spyder