Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Some kernels do a lot of processing on start so appear to be slow to start running cells #7952

Closed
greazer opened this issue Oct 16, 2021 · 3 comments
Assignees
Labels
author-verification-requested Issues potentially verifiable by issue author bug Issue identified by VS Code Team member as probable bug notebook-execution Kernels issues (start/restart/switch/execution, install ipykernel) perf Performance issues
Milestone

Comments

@greazer
Copy link
Member

greazer commented Oct 16, 2021

I have a kernel on my Windows machine that I installed the deep learning keras api into. Keras seems to require some startup code to be run when the environment is activated. At minimum this takes a few seconds, even when activating from an anaconda prompt.

Within VS Code, it also takes a long time. Therefore, when I run the first cell for this environment, it appears to start very slowly.

Since we cannot speed up a process we have no control over, at minimum, it would help if the notification that tells me a kernel is starting, that it provides a link to the Jupyter output panel so I can see what's happening.

Here's a log with delays highlighted. This one took 26 seconds to start. I've seen it start slower than that though.

Info 2021-10-16 08:38:47: Execute Cells request 1 1
Info 2021-10-16 08:38:47: Execute Cell 1 file:///c%3A/Users/jimg/Repos/covid-19-data-1/SampleNbsAndScripts/myanalysis_plotly.ipynb
*******
DELAY 8 seconds. 
*******
Info 2021-10-16 08:38:55: Process Execution: > ~\anaconda3\envs\myenv\python.exe -c "import ipykernel"
> ~\anaconda3\envs\myenv\python.exe -c "import ipykernel"
Info 2021-10-16 08:38:55: Process Execution: > ~\anaconda3\envs\myenv\python.exe -c "import jupyter"
> ~\anaconda3\envs\myenv\python.exe -c "import jupyter"
Info 2021-10-16 08:38:55: Process Execution: > ~\anaconda3\envs\myenv\python.exe -c "import notebook"
> ~\anaconda3\envs\myenv\python.exe -c "import notebook"
Info 2021-10-16 08:38:55: Process Execution: > ~\anaconda3\envs\myenv\python.exe -m pip list
> ~\anaconda3\envs\myenv\python.exe -m pip list
Info 2021-10-16 08:38:56: Process Execution: > ~\anaconda3\envs\myenv\python.exe -m jupyter kernelspec --version
> ~\anaconda3\envs\myenv\python.exe -m jupyter kernelspec --version
Info 2021-10-16 08:38:56: Install Missing Dependencies, Class name = S, completed in 31169ms, has a falsy return value, Return Value: undefined
Info 2021-10-16 08:38:56: Kernel launching with ports 9000,9001,9002,9003,9004. Start port is 9000
Info 2021-10-16 08:38:56: Launching kernel daemon for Python 3.7.10 64-bit ('myenv': conda) # C:\Users\jimg\anaconda3\envs\myenv\python.exe
*******
DELAY 13 seconds
*******
Info 2021-10-16 08:39:09: Creating daemon process for C:\Users\jimg\anaconda3\envs\myenv\python.exe with env variables count 127
Info 2021-10-16 08:39:09: Process Execution: > ~\anaconda3\envs\myenv\python.exe -m vscode_datascience_helpers.daemon --daemon-module=vscode_datascience_helpers.kernel_launcher_daemon -v
> ~\anaconda3\envs\myenv\python.exe -m vscode_datascience_helpers.daemon --daemon-module=vscode_datascience_helpers.kernel_launcher_daemon -v
Info 2021-10-16 08:39:09: Starting kernel from scratch with options {"env":{"ALLUSERSPROFILE":"C:\\ProgramData","AML_EXTENSION_SHOWRUNS":"1","APPDATA":"C:\\Users\\jimg\\AppData\\Roaming","APPLICATION_INSIGHTS_NO_DIAGNOSTIC_CHANNEL":"true","CHROME_CRASHPAD_PIPE_NAME":"\\\\.\\pipe\\crashpad_11488_RLRLBFPIGSFSYZJD","CommonProgramFiles":"C:\\Program Files\\Common Files","CommonProgramFiles(x86)":"C:\\Program Files (x86)\\Common Files","CommonProgramW6432":"C:\\Program Files\\Common Files","COMPUTERNAME":"SURFACESTUDIO","ComSpec":"C:\\WINDOWS\\system32\\cmd.exe","CUDA_PATH":"C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3","CUDA_PATH_V11_3":"C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3","CUDA_VISIBLE_DEVICES":"-1","DriverData":"C:\\Windows\\System32\\Drivers\\DriverData","ELECTRON_RUN_AS_NODE":"1","FPS_BROWSER_APP_PROFILE_STRING":"Internet Explorer","FPS_BROWSER_USER_PROFILE_STRING":"Default","GIT_LFS_PATH":"C:\\Program Files\\Git LFS","HOMEDRIVE":"C:","HOMEPATH":"\\Users\\jimg","JUPYTER_CONFIG_DATA":"c:\\Users\\jimg\\.vscode-insiders\\extensions\\ms-toolsai.vscode-ai-remote-0.4.0\\jupyterConfigData.json","LOCALAPPDATA":"C:\\Users\\jimg\\AppData\\Local","LOGONSERVER":"\\\\SURFACESTUDIO","NUMBER_OF_PROCESSORS":"8","NVCUDASAMPLES11_3_ROOT":"C:\\ProgramData\\NVIDIA Corporation\\CUDA Samples\\v11.3","NVCUDASAMPLES_ROOT":"C:\\ProgramData\\NVIDIA Corporation\\CUDA Samples\\v11.3","NVTOOLSEXT_PATH":"C:\\Program Files\\NVIDIA Corporation\\NvToolsExt\\","OculusBase":"C:\\Program Files\\Oculus\\","OneDrive":"C:\\Users\\jimg\\OneDrive","OneDriveConsumer":"C:\\Users\\jimg\\OneDrive","ORIGINAL_XDG_CURRENT_DESKTOP":"undefined","OS":"Windows_NT","Path":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\bin\\HostX64\\x64;C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\MSBuild\\15.0\\bin\\Roslyn;C:\\Program Files (x86)\\Windows Kits\\10\\bin\\10.0.18362.0\\x64;C:\\Program Files (x86)\\Windows Kits\\10\\bin\\x64;C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\\\MSBuild\\15.0\\bin;C:\\Windows\\Microsoft.NET\\Framework64\\v4.0.30319;C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\Common7\\IDE\\;C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\Common7\\Tools\\;C:\\Users\\jimg\\anaconda3\\envs\\myenv;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\mingw-w64\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\usr\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Scripts;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\bin;C:\\Users\\jimg\\anaconda3\\condabin;C:\\Program Files (x86)\\Microsoft SDKs\\Azure\\CLI2\\wbin;C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3\\bin;C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3\\libnvvp;C:\\Program Files\\Oculus\\Support\\oculus-runtime;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0;C:\\WINDOWS\\System32\\OpenSSH;C:\\Program Files\\Git\\cmd;C:\\Program Files\\dotnet;C:\\Program Files\\Microsoft VS Code\\bin;C:\\Program Files (x86)\\NVIDIA Corporation\\PhysX\\Common;C:\\Program Files\\Docker\\Docker\\resources\\bin;C:\\ProgramData\\DockerDesktop\\version-bin;C:\\Program Files\\NVIDIA Corporation\\NVIDIA NvDLISR;C:\\Program Files\\NVIDIA Corporation\\Nsight Compute 2021.1.0;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\c\\bin;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\perl\\site\\bin;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\perl\\bin;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0;C:\\WINDOWS\\System32\\OpenSSH;C:\\Program Files\\Git LFS;C:\\Program Files\\Microsoft VS Code Insiders\\bin;C:\\Program Files\\nodejs;C:\\Users\\jimg\\.cargo\\bin;C:\\Users\\jimg\\AppData\\Local\\Mu\\bin;C:\\Users\\jimg\\.dotnet\\tools;C:\\Users\\jimg\\AppData\\Local\\Programs\\MiKTeX\\miktex\\bin\\x64;c:\\users\\jimg\\onedrive\\tools;C:\\Users\\jimg\\AppData\\Local\\Programs\\Microsoft VS Code Insiders\\bin;.;C:\\Users\\jimg\\AppData\\Local\\Microsoft\\WindowsApps;C:\\Users\\jimg\\AppData\\Roaming\\npm","PATHEXT":".COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC","PROCESSOR_ARCHITECTURE":"AMD64","PROCESSOR_IDENTIFIER":"Intel64 Family 6 Model 158 Stepping 9, GenuineIntel","PROCESSOR_LEVEL":"6","PROCESSOR_REVISION":"9e09","ProgramData":"C:\\ProgramData","ProgramFiles":"C:\\Program Files","ProgramFiles(x86)":"C:\\Program Files (x86)","ProgramW6432":"C:\\Program Files","PSModulePath":"C:\\Program Files\\WindowsPowerShell\\Modules;C:\\WINDOWS\\system32\\WindowsPowerShell\\v1.0\\Modules","PUBLIC":"C:\\Users\\Public","SESSIONNAME":"Console","SystemDrive":"C:","SystemRoot":"C:\\WINDOWS","TEMP":"C:\\Users\\jimg\\AppData\\Local\\Temp","TMP":"C:\\Users\\jimg\\AppData\\Local\\Temp","USERDOMAIN":"SURFACESTUDIO","USERDOMAIN_ROAMINGPROFILE":"SURFACESTUDIO","USERNAME":"jimg","USERPROFILE":"C:\\Users\\jimg","VSCODE_AMD_ENTRYPOINT":"vs/workbench/services/extensions/node/extensionHostProcess","VSCODE_CODE_CACHE_PATH":"C:\\Users\\jimg\\AppData\\Roaming\\Code - Insiders\\CachedData\\34eeebdd66033633ac22efd5fab928ae37916168","VSCODE_CWD":"C:\\Users\\jimg\\AppData\\Local\\Programs\\Microsoft VS Code Insiders","VSCODE_HANDLES_UNCAUGHT_ERRORS":"true","VSCODE_IPC_HOOK":"\\\\.\\pipe\\ef39a92ec8ae913a3a5a3febc81456b5-1.62.0-insider-main-sock","VSCODE_IPC_HOOK_EXTHOST":"\\\\.\\pipe\\vscode-ipc-d7af3804-ca0f-4658-af7d-49b111c534cc-sock","VSCODE_LOG_NATIVE":"false","VSCODE_LOG_STACK":"true","VSCODE_NLS_CONFIG":"{\"locale\":\"en-us\",\"availableLanguages\":{},\"_languagePackSupport\":true}","VSCODE_PID":"11488","VSCODE_PIPE_LOGGING":"true","VSCODE_VERBOSE_LOGGING":"true","windir":"C:\\WINDOWS","__COMPAT_LAYER":"DetectorsShimLog","BITS":"64","CC":"cl.exe","CMAKE_GEN":"Visual Studio 15 2017 Win64","CMAKE_GENERATOR":"Visual Studio 15 2017 Win64","COMMANDPROMPTTYPE":"Native","COMMONPROGRAMFILES":"C:\\Program Files\\Common Files","COMMONPROGRAMFILES(X86)":"C:\\Program Files (x86)\\Common Files","COMMONPROGRAMW6432":"C:\\Program Files\\Common Files","COMSPEC":"C:\\WINDOWS\\system32\\cmd.exe","CONDA_DEFAULT_ENV":"myenv","CONDA_EXE":"C:\\Users\\jimg\\anaconda3\\Scripts\\conda.exe","CONDA_PREFIX":"C:\\Users\\jimg\\anaconda3\\envs\\myenv","CONDA_PREFIX_1":"C:\\Users\\jimg\\anaconda3","CONDA_PROMPT_MODIFIER":"(myenv) ","CONDA_PYTHON_EXE":"C:\\Users\\jimg\\anaconda3\\python.exe","CONDA_SHLVL":"2","CXX":"cl.exe","DEVENVDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\Common7\\IDE\\","DISTUTILS_USE_SDK":"1","DRIVERDATA":"C:\\Windows\\System32\\Drivers\\DriverData","EXTENSIONSDKDIR":"C:\\Program Files (x86)\\Microsoft SDKs\\Windows Kits\\10\\ExtensionSDKs","FRAMEWORK40VERSION":"v4.0","FRAMEWORKDIR":"C:\\Windows\\Microsoft.NET\\Framework64\\","FRAMEWORKDIR64":"C:\\Windows\\Microsoft.NET\\Framework64\\","FRAMEWORKVERSION":"v4.0.30319","FRAMEWORKVERSION64":"v4.0.30319","INCLUDE":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\include;C:\\Program Files (x86)\\Windows Kits\\10\\include\\10.0.18362.0\\ucrt;C:\\Program Files (x86)\\Windows Kits\\10\\include\\10.0.18362.0\\shared;C:\\Program Files (x86)\\Windows Kits\\10\\include\\10.0.18362.0\\um;C:\\Program Files (x86)\\Windows Kits\\10\\include\\10.0.18362.0\\winrt;C:\\Program Files (x86)\\Windows Kits\\10\\include\\10.0.18362.0\\cppwinrt","LIB":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\lib\\x64;C:\\Program Files (x86)\\Windows Kits\\10\\lib\\10.0.18362.0\\ucrt\\x64;C:\\Program Files (x86)\\Windows Kits\\10\\lib\\10.0.18362.0\\um\\x64;","LIBPATH":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\lib\\x64;C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\lib\\x86\\store\\references;C:\\Program Files (x86)\\Windows Kits\\10\\UnionMetadata\\10.0.18362.0;C:\\Program Files (x86)\\Windows Kits\\10\\References\\10.0.18362.0;C:\\Windows\\Microsoft.NET\\Framework64\\v4.0.30319;","MSSDK":"1","MSYS2_ARG_CONV_EXCL":"/AI;/AL;/OUT;/out","MSYS2_ENV_CONV_EXCL":"CL","OCULUSBASE":"C:\\Program Files\\Oculus\\","ONEDRIVE":"C:\\Users\\jimg\\OneDrive","ONEDRIVECONSUMER":"C:\\Users\\jimg\\OneDrive","PLATFORM":"x64","PROGRAMDATA":"C:\\ProgramData","PROGRAMFILES":"C:\\Program Files","PROGRAMFILES(X86)":"C:\\Program Files (x86)","PROGRAMW6432":"C:\\Program Files","PROMPT":"(myenv) $P$G","PSMODULEPATH":"C:\\Program Files\\WindowsPowerShell\\Modules;C:\\WINDOWS\\system32\\WindowsPowerShell\\v1.0\\Modules","PYTHONIOENCODING":"utf-8","PYTHONUNBUFFERED":"1","PY_VCRUNTIME_REDIST":"\\bin\\vcruntime140.dll","SYSTEMDRIVE":"C:","SYSTEMROOT":"C:\\WINDOWS","UCRTVERSION":"10.0.18362.0","UNIVERSALCRTSDKDIR":"C:\\Program Files (x86)\\Windows Kits\\10\\","VCIDEINSTALLDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\Common7\\IDE\\VC\\","VCINSTALLDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\","VCTOOLSINSTALLDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Tools\\MSVC\\14.16.27023\\","VCTOOLSREDISTDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\VC\\Redist\\MSVC\\14.16.27012\\","VCTOOLSVERSION":"14.16.27023","VISUALSTUDIOVERSION":"15.0","VS150COMNTOOLS":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\Common7\\Tools\\","VSCMD_ARG_APP_PLAT":"Desktop","VSCMD_ARG_HOST_ARCH":"x64","VSCMD_ARG_TGT_ARCH":"x64","VSCMD_ARG_VCVARS_VER":"14.16","VSCMD_ARG_WINSDK":"10.0.18362.0","VSCMD_VER":"15.0","VSINSTALLDIR":"C:\\Program Files (x86)\\Microsoft Visual Studio\\2017\\BuildTools\\","VS_MAJOR":"15","VS_VERSION":"15.0","VS_YEAR":"2017","WINDIR":"C:\\WINDOWS","WINDOWSLIBPATH":"C:\\Program Files (x86)\\Windows Kits\\10\\UnionMetadata\\10.0.18362.0;C:\\Program Files (x86)\\Windows Kits\\10\\References\\10.0.18362.0","WINDOWSSDKBINPATH":"C:\\Program Files (x86)\\Windows Kits\\10\\bin\\","WINDOWSSDKDIR":"C:\\Program Files (x86)\\Windows Kits\\10\\","WINDOWSSDKLIBVERSION":"10.0.18362.0\\","WINDOWSSDKVER":"10.0.18362.0","WINDOWSSDKVERBINPATH":"C:\\Program Files (x86)\\Windows Kits\\10\\bin\\10.0.18362.0\\","WINDOWSSDKVERSION":"10.0.18362.0\\","__DOTNET_ADD_64BIT":"1","__DOTNET_PREFERRED_BITNESS":"64","__VSCMD_PREINIT_PATH":"C:\\Users\\jimg\\anaconda3\\envs\\myenv;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\mingw-w64\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\usr\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Library\\bin;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\Scripts;C:\\Users\\jimg\\anaconda3\\envs\\myenv\\bin;C:\\Users\\jimg\\anaconda3\\condabin;C:\\Program Files (x86)\\Microsoft SDKs\\Azure\\CLI2\\wbin;C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3\\bin;C:\\Program Files\\NVIDIA GPU Computing Toolkit\\CUDA\\v11.3\\libnvvp;C:\\Program Files\\Oculus\\Support\\oculus-runtime;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0;C:\\WINDOWS\\System32\\OpenSSH;C:\\Program Files\\Git\\cmd;C:\\Program Files\\dotnet;C:\\Program Files\\Microsoft VS Code\\bin;C:\\Program Files (x86)\\NVIDIA Corporation\\PhysX\\Common;C:\\Program Files\\Docker\\Docker\\resources\\bin;C:\\ProgramData\\DockerDesktop\\version-bin;C:\\Program Files\\NVIDIA Corporation\\NVIDIA NvDLISR;C:\\Program Files\\NVIDIA Corporation\\Nsight Compute 2021.1.0;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\c\\bin;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\perl\\site\\bin;C:\\users\\jimg\\OneDrive\\Tools\\StrawberryPerl\\perl\\bin;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0;C:\\WINDOWS\\System32\\OpenSSH;C:\\Program Files\\Git LFS;C:\\Program Files\\Microsoft VS Code Insiders\\bin;C:\\Program Files\\nodejs;C:\\Users\\jimg\\.cargo\\bin;C:\\Users\\jimg\\AppData\\Local\\Mu\\bin;C:\\Users\\jimg\\.dotnet\\tools;C:\\Users\\jimg\\AppData\\Local\\Programs\\MiKTeX\\miktex\\bin\\x64;c:\\users\\jimg\\onedrive\\tools;C:\\Users\\jimg\\AppData\\Local\\Programs\\Microsoft VS Code Insiders\\bin;.;C:\\Users\\jimg\\AppData\\Local\\Microsoft\\WindowsApps;C:\\Users\\jimg\\AppData\\Roaming\\npm"},"cwd":"c:\\Users\\jimg\\Repos\\covid-19-data-1\\SampleNbsAndScripts"}
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Execute rpc method exec_module in DS Daemon
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Execute rpc method exec_module from C:\Users\jimg\anaconda3\envs\myenv\python.exe
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Exec module in DS Kernel Launcher Daemon ipykernel_launcher with args ['--ip=127.0.0.1', '--stdin=9003', '--control=9001', '--hb=9000', '--Session.signature_scheme="hmac-sha256"', '--Session.key=b"1fd81654-1765-4d51-b71e-fe266761a250"', '--shell=9002', '--transport="tcp"', '--iopub=9004', '--f=C:\\Users\\jimg\\AppData\\Local\\Temp\\tmp-23880xgcMwuHZFyEa.json']
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Exec in DS Kernel Launcher Daemon (observable) ipykernel_launcher with args ['--ip=127.0.0.1', '--stdin=9003', '--control=9001', '--hb=9000', '--Session.signature_scheme="hmac-sha256"', '--Session.key=b"1fd81654-1765-4d51-b71e-fe266761a250"', '--shell=9002', '--transport="tcp"', '--iopub=9004', '--f=C:\\Users\\jimg\\AppData\\Local\\Temp\\tmp-23880xgcMwuHZFyEa.json']
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Exec in DS Kernel Launcher Daemon (observable) ['C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe', '-m', 'ipykernel_launcher', '--ip=127.0.0.1', '--stdin=9003', '--control=9001', '--hb=9000', '--Session.signature_scheme="hmac-sha256"', '--Session.key=b"1fd81654-1765-4d51-b71e-fe266761a250"', '--shell=9002', '--transport="tcp"', '--iopub=9004', '--f=C:\\Users\\jimg\\AppData\\Local\\Temp\\tmp-23880xgcMwuHZFyEa.json']
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Exec in DS Kernel Launcher Daemon (observable)
Info 2021-10-16 08:39:09: Python Daemon (pid: 5072): Kernel launched, with PID 23016
Warn 2021-10-16 08:39:09: Python Daemon (pid: 5072): Waiting for Kernel to die 23016
Info 2021-10-16 08:39:09: Launching kernel daemon, Class name = p, completed in 12653ms, has a truthy return value, Arg 1: <Uri:c:\Users\jimg\Repos\covid-19-data-1\SampleNbsAndScripts\myanalysis_plotly.ipynb>, Arg 2: "c:\\Users\\jimg\\Repos\\covid-19-data-1\\SampleNbsAndScripts", Arg 3: {"specFile":"C:\\Users\\jimg\\AppData\\Roaming\\jupyter\\kernels\\python3710jvsc74a57bd0b6d63190ba476f8db41d311553a07f932cc12a9b15fd1bbb24bb6575d9c2bce1\\kernel.json","interpreterPath":"C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe","name":"python3710jvsc74a57bd0b6d63190ba476f8db41d311553a07f932cc12a9b15fd1bbb24bb6575d9c2bce1","argv":["python","-m","ipykernel_launcher","--ip=127.0.0.1","--stdin=9003","--control=9001","--hb=9000","--Session.signature_scheme=\"hmac-sha256\"","--Session.key=b\"1fd81654-1765-4d51-b71e-fe266761a250\"","--shell=9002","--transport=\"tcp\"","--iopub=9004","--f=C:\\Users\\jimg\\AppData\\Local\\Temp\\tmp-23880xgcMwuHZFyEa.json"],"language":"python","path":"python","display_name":"Python 3.7.10 64-bit ('myenv': conda)","metadata":{"interpreter":{"sysPrefix":"C:\\Users\\jimg\\anaconda3\\envs\\myenv","envType":"Conda","envName":"myenv","envPath":"C:\\Users\\jimg\\anaconda3\\envs\\myenv","path":"C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe","architecture":3,"sysVersion":"3.7.10 | packaged by conda-forge | (default, Feb 19 2021, 15:37:01) [MSC v.1916 64 bit (AMD64)]","version":{"raw":"3.7.10","major":3,"minor":7,"patch":10,"build":[],"prerelease":["final","0"]},"companyDisplayName":"Anaconda, Inc.","displayName":"Python 3.7.10 64-bit ('myenv': conda)"}},"env":{}}, Arg 4: {"sysPrefix":"C:\\Users\\jimg\\anaconda3\\envs\\myenv","envType":"Conda","envName":"myenv","envPath":"C:\\Users\\jimg\\anaconda3\\envs\\myenv","path":"C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe","architecture":3,"sysVersion":"3.7.10 | packaged by conda-forge | (default, Feb 19 2021, 15:37:01) [MSC v.1916 64 bit (AMD64)]","version":{"raw":"3.7.10","major":3,"minor":7,"patch":10,"build":[],"prerelease":["final","0"]},"companyDisplayName":"Anaconda, Inc.","displayName":"Python 3.7.10 64-bit ('myenv': conda)"}, Return Value: <Return value cannot be serialized for logging>
Info 2021-10-16 08:39:09: Launching kernel in kernelProcess.ts, Class name = y, completed in 12654ms, has a truthy return value, Arg 1: "c:\\Users\\jimg\\Repos\\covid-19-data-1\\SampleNbsAndScripts", Return Value: {"proc":{"_events":{},"_eventsCount":2,"_closesNeeded":3,"_closesGot":0,"connected":false,"signalCode":null,"exitCode":null,"killed":false,"spawnfile":"C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe","_handle":{"pid":5072},"spawnargs":["C:\\Users\\jimg\\anaconda3\\envs\\myenv\\python.exe","-m","vscode_datascience_helpers.daemon","--daemon-module=vscode_datascience_helpers.kernel_launcher_daemon","-v"],"pid":5072,"stdin":{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":null,"ended":false,"endEmitted":false,"reading":false,"sync":true,"needReadable":false,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null,"readable":false},"_events":{},"_eventsCount":3,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":false,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null},"stdout":{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":true,"ended":false,"endEmitted":false,"reading":true,"sync":false,"needReadable":true,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null},"_events":{"close":[null,null]},"_eventsCount":4,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"writable":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null},"stderr":{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":true,"ended":false,"endEmitted":false,"reading":true,"sync":false,"needReadable":true,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null},"_events":{},"_eventsCount":3,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"writable":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null},"stdio":[{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":null,"ended":false,"endEmitted":false,"reading":false,"sync":true,"needReadable":false,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null,"readable":false},"_events":{},"_eventsCount":3,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":false,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null},{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":true,"ended":false,"endEmitted":false,"reading":true,"sync":false,"needReadable":true,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null},"_events":{"close":[null,null]},"_eventsCount":4,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"writable":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null},{"connecting":false,"_hadError":false,"_parent":null,"_host":null,"_readableState":{"objectMode":false,"highWaterMark":16384,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":true,"ended":false,"endEmitted":false,"reading":true,"sync":false,"needReadable":true,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"decoder":null,"encoding":null},"_events":{},"_eventsCount":3,"_writableState":{"objectMode":false,"highWaterMark":16384,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":false,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"prefinished":false,"errorEmitted":false,"emitClose":false,"autoDestroy":false,"errored":null,"closed":false,"writable":false,"closeEmitted":false},"allowHalfOpen":false,"_sockname":null,"_pendingData":null,"_pendingEncoding":"","server":null,"_server":null}]},"out":{"_isScalar":false,"observers":[],"closed":false,"isStopped":false,"hasError":false,"thrownError":null}}
*******
DELAY 3 seconds
*******
Info 2021-10-16 08:39:12: KernelProcess output: Content-Length: 370
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "log", "params": {"level": "INFO", "msg": "write to stderr: C:\\Users\\jimg\\anaconda3\\envs\\myenv\\lib\\site-packages\\traitlets\\traitlets.py:2205: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '\"hmac-sha256\"' if you require traitlets >=5.\r\n", "pid": 5072}}Content-Length: 346
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "output", "params": {"source": "stderr", "out": "C:\\Users\\jimg\\anaconda3\\envs\\myenv\\lib\\site-packages\\traitlets\\traitlets.py:2205: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '\"hmac-sha256\"' if you require traitlets >=5.\r\n"}}
Info 2021-10-16 08:39:12: Python Daemon (pid: 5072): write to stderr: C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2205: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '"hmac-sha256"' if you require traitlets >=5.

Info 2021-10-16 08:39:12: KernelProcess output: Content-Length: 125
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "log", "params": {"level": "INFO", "msg": "write to stderr:   FutureWarning)\r\n", "pid": 5072}}Content-Length: 101
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "output", "params": {"source": "stderr", "out": "  FutureWarning)\r\n"}}Content-Length: 382
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "log", "params": {"level": "INFO", "msg": "write to stderr: C:\\Users\\jimg\\anaconda3\\envs\\myenv\\lib\\site-packages\\traitlets\\traitlets.py:2160: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '1fd81654-1765-4d51-b71e-fe266761a250' instead of 'b\"1fd81654-1765-4d51-b71e-fe266761a250\"'.\r\n", "pid": 5072}}Content-Length: 358
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "output", "params": {"source": "stderr", "out": "C:\\Users\\jimg\\anaconda3\\envs\\myenv\\lib\\site-packages\\traitlets\\traitlets.py:2160: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '1fd81654-1765-4d51-b71e-fe266761a250' instead of 'b\"1fd81654-1765-4d51-b71e-fe266761a250\"'.\r\n"}}Content-Length: 125
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "log", "params": {"level": "INFO", "msg": "write to stderr:   FutureWarning)\r\n", "pid": 5072}}Content-Length: 101
Content-Type: application/vscode-jsonrpc; charset=utf8

{"jsonrpc": "2.0", "method": "output", "params": {"source": "stderr", "out": "  FutureWarning)\r\n"}}
Warn 2021-10-16 08:39:12: Kernel 5072 as possibly died, StdErr from Kernel Process C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2205: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '"hmac-sha256"' if you require traitlets >=5.

Warn 2021-10-16 08:39:12: StdErr from Kernel Process C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2205: FutureWarning: Supporting extra quotes around strings is deprecated in traitlets 5.0. You can use 'hmac-sha256' instead of '"hmac-sha256"' if you require traitlets >=5.

Info 2021-10-16 08:39:12: Python Daemon (pid: 5072): write to stderr:   FutureWarning)

Warn 2021-10-16 08:39:12: Kernel 5072 as possibly died, StdErr from Kernel Process   FutureWarning)

Warn 2021-10-16 08:39:12: StdErr from Kernel Process   FutureWarning)

Info 2021-10-16 08:39:12: Python Daemon (pid: 5072): write to stderr: C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2160: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '1fd81654-1765-4d51-b71e-fe266761a250' instead of 'b"1fd81654-1765-4d51-b71e-fe266761a250"'.

Warn 2021-10-16 08:39:12: Kernel 5072 as possibly died, StdErr from Kernel Process C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2160: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '1fd81654-1765-4d51-b71e-fe266761a250' instead of 'b"1fd81654-1765-4d51-b71e-fe266761a250"'.

Warn 2021-10-16 08:39:12: StdErr from Kernel Process C:\Users\jimg\anaconda3\envs\myenv\lib\site-packages\traitlets\traitlets.py:2160: FutureWarning: Supporting extra quotes around Bytes is deprecated in traitlets 5.0. Use '1fd81654-1765-4d51-b71e-fe266761a250' instead of 'b"1fd81654-1765-4d51-b71e-fe266761a250"'.

Info 2021-10-16 08:39:12: Python Daemon (pid: 5072): write to stderr:   FutureWarning)

Warn 2021-10-16 08:39:12: Kernel 5072 as possibly died, StdErr from Kernel Process   FutureWarning)

Warn 2021-10-16 08:39:12: StdErr from Kernel Process   FutureWarning)

Info 2021-10-16 08:39:12: Raw session started and connected
Started kernel Python 3.7.10 64-bit ('myenv': conda)
Info 2021-10-16 08:39:12: Finished connecting e6097784-3fac-4d1f-a6af-ae62fa003db2
Info 2021-10-16 08:39:12: Updating preferred kernel for remote notebook 25809248-e290-450c-a122-fd389763ff2e
Info 2021-10-16 08:39:12: Preferred kernel for file:///c%3A/Users/jimg/Repos/covid-19-data-1/SampleNbsAndScripts/myanalysis_plotly.ipynb is 25809248-e290-450c-a122-fd389763ff2e
Info 2021-10-16 08:39:12: UpdateWorkingDirectoryAndPath in Kernel
Info 2021-10-16 08:39:12: changeDirectoryIfPossible
Info 2021-10-16 08:39:12: Waiting for idle on (kernel): 25809248-e290-450c-a122-fd389763ff2e -> idle
Info 2021-10-16 08:39:12: Finished waiting for idle on (kernel): 25809248-e290-450c-a122-fd389763ff2e -> idle
Info 2021-10-16 08:39:12: Process Execution: > ~\anaconda3\envs\myenv\python.exe -m pip list
> ~\anaconda3\envs\myenv\python.exe -m pip list
Info 2021-10-16 08:39:13: Registering dummy command feature

@greazer greazer added the bug Issue identified by VS Code Team member as probable bug label Oct 16, 2021
@greazer greazer added notebook-execution Kernels issues (start/restart/switch/execution, install ipykernel) perf Performance issues and removed needs-triage labels Oct 16, 2021
@greazer greazer changed the title Some kernels do a lot of processing on start and appear to be slow to start. Some kernels do a lot of processing on start so appear to be slow to start running Oct 16, 2021
@greazer greazer changed the title Some kernels do a lot of processing on start so appear to be slow to start running Some kernels do a lot of processing on start so appear to be slow to start running cells Oct 16, 2021
@DonJayamanne
Copy link
Contributor

DonJayamanne commented Oct 16, 2021

Since we cannot speed up a process we have no control over

I believe we can improve it:
#6694
#7903
#5324

@DonJayamanne
Copy link
Contributor

Testing

@rchiodo rchiodo added the author-verification-requested Issues potentially verifiable by issue author label Dec 1, 2021
@rchiodo
Copy link
Contributor

rchiodo commented Dec 3, 2021

To be clear, there no new UI showing what's taking so long. Don just made it not take so dang long :)

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Mar 1, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
author-verification-requested Issues potentially verifiable by issue author bug Issue identified by VS Code Team member as probable bug notebook-execution Kernels issues (start/restart/switch/execution, install ipykernel) perf Performance issues
Projects
None yet
Development

No branches or pull requests

3 participants