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

[Dask] Socket recv error, code: 54 on macOS #4116

Closed
StrikerRUS opened this issue Mar 26, 2021 · 11 comments
Closed

[Dask] Socket recv error, code: 54 on macOS #4116

StrikerRUS opened this issue Mar 26, 2021 · 11 comments

Comments

@StrikerRUS
Copy link
Collaborator

Just saw this error in master for macOS in one of the examples.

Full logs:
2021-03-26T14:01:26.3975170Z ##[section]Starting: Test
2021-03-26T14:01:26.3985600Z ==============================================================================
2021-03-26T14:01:26.3986300Z Task         : Bash
2021-03-26T14:01:26.3986870Z Description  : Run a Bash script on macOS, Linux, or Windows
2021-03-26T14:01:26.3987370Z Version      : 3.182.0
2021-03-26T14:01:26.3987880Z Author       : Microsoft Corporation
2021-03-26T14:01:26.3988470Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/bash
2021-03-26T14:01:26.3989140Z ==============================================================================
2021-03-26T14:01:26.5576860Z Generating script.
2021-03-26T14:01:26.5595040Z Script contents:
2021-03-26T14:01:26.5595790Z /Users/runner/work/1/s/.ci/test.sh
2021-03-26T14:01:26.5614560Z ========================== Starting Command Output ===========================
2021-03-26T14:01:26.5632050Z [command]/bin/bash --noprofile --norc /Users/runner/work/_temp/8c363f33-9ab1-462d-b935-85a147934d98.sh
2021-03-26T14:01:27.2162380Z Collecting package metadata (current_repodata.json): ...working... done
2021-03-26T14:01:27.2748030Z Solving environment: ...working... done
2021-03-26T14:01:29.7398890Z 
2021-03-26T14:01:29.7500430Z ## Package Plan ##
2021-03-26T14:01:29.7601600Z 
2021-03-26T14:01:29.7689070Z   environment location: /Users/runner/runners/2.183.1/miniconda/envs/test-env
2021-03-26T14:01:29.7790470Z 
2021-03-26T14:01:29.7874990Z   added / updated specs:
2021-03-26T14:01:29.7899320Z     - python=3.7
2021-03-26T14:01:29.7909240Z 
2021-03-26T14:01:29.7916600Z 
2021-03-26T14:01:29.7933680Z The following packages will be downloaded:
2021-03-26T14:01:29.7934760Z 
2021-03-26T14:01:29.7935940Z     package                    |            build
2021-03-26T14:01:29.7937740Z     ---------------------------|-----------------
2021-03-26T14:01:29.7939410Z     certifi-2020.12.5          |   py37hecd8cb5_0         140 KB
2021-03-26T14:01:29.7941240Z     pip-21.0.1                 |   py37hecd8cb5_0         1.8 MB
2021-03-26T14:01:29.7942970Z     python-3.7.10              |       h88f2d9e_0        18.2 MB
2021-03-26T14:01:29.7944640Z     setuptools-52.0.0          |   py37hecd8cb5_0         721 KB
2021-03-26T14:01:29.7946270Z     ------------------------------------------------------------
2021-03-26T14:01:29.8048070Z                                            Total:        20.8 MB
2021-03-26T14:01:29.8049240Z 
2021-03-26T14:01:29.8150120Z The following NEW packages will be INSTALLED:
2021-03-26T14:01:29.8250280Z 
2021-03-26T14:01:29.8352470Z   ca-certificates    pkgs/main/osx-64::ca-certificates-2021.1.19-hecd8cb5_1
2021-03-26T14:01:29.8453020Z   certifi            pkgs/main/osx-64::certifi-2020.12.5-py37hecd8cb5_0
2021-03-26T14:01:29.8554810Z   libcxx             pkgs/main/osx-64::libcxx-10.0.0-1
2021-03-26T14:01:29.8655680Z   libffi             pkgs/main/osx-64::libffi-3.3-hb1e8313_2
2021-03-26T14:01:29.8757130Z   ncurses            pkgs/main/osx-64::ncurses-6.2-h0a44026_1
2021-03-26T14:01:29.8858480Z   openssl            pkgs/main/osx-64::openssl-1.1.1k-h9ed2024_0
2021-03-26T14:01:29.8928950Z   pip                pkgs/main/osx-64::pip-21.0.1-py37hecd8cb5_0
2021-03-26T14:01:29.8931310Z   python             pkgs/main/osx-64::python-3.7.10-h88f2d9e_0
2021-03-26T14:01:29.8933040Z   readline           pkgs/main/osx-64::readline-8.1-h9ed2024_0
2021-03-26T14:01:29.8934820Z   setuptools         pkgs/main/osx-64::setuptools-52.0.0-py37hecd8cb5_0
2021-03-26T14:01:29.8936540Z   sqlite             pkgs/main/osx-64::sqlite-3.35.2-hce871da_0
2021-03-26T14:01:29.8938860Z   tk                 pkgs/main/osx-64::tk-8.6.10-hb0a8c7a_0
2021-03-26T14:01:29.8940670Z   wheel              pkgs/main/noarch::wheel-0.36.2-pyhd3eb1b0_0
2021-03-26T14:01:29.8942290Z   xz                 pkgs/main/osx-64::xz-5.2.5-h1de35cc_0
2021-03-26T14:01:29.8943990Z   zlib               pkgs/main/osx-64::zlib-1.2.11-h1de35cc_3
2021-03-26T14:01:29.8944970Z 
2021-03-26T14:01:29.8945780Z 
2021-03-26T14:01:30.1775800Z Preparing transaction: ...working... done
2021-03-26T14:01:32.0640780Z Verifying transaction: ...working... done
2021-03-26T14:01:35.0788680Z Executing transaction: ...working... done
2021-03-26T14:01:36.6419560Z Collecting package metadata (current_repodata.json): ...working... done
2021-03-26T14:01:37.9047100Z Solving environment: ...working... done
2021-03-26T14:01:38.0192700Z 
2021-03-26T14:01:38.0194570Z ## Package Plan ##
2021-03-26T14:01:38.0195250Z 
2021-03-26T14:01:38.0196900Z   environment location: /Users/runner/runners/2.183.1/miniconda/envs/test-env
2021-03-26T14:01:38.0197740Z 
2021-03-26T14:01:38.0198800Z   added / updated specs:
2021-03-26T14:01:38.0200490Z     - cloudpickle
2021-03-26T14:01:38.0201890Z     - dask
2021-03-26T14:01:38.0203690Z     - distributed
2021-03-26T14:01:38.0204980Z     - joblib
2021-03-26T14:01:38.0207000Z     - matplotlib
2021-03-26T14:01:38.0208370Z     - numpy
2021-03-26T14:01:38.0209930Z     - pandas
2021-03-26T14:01:38.0211280Z     - psutil
2021-03-26T14:01:38.0212550Z     - pytest
2021-03-26T14:01:38.0214710Z     - scikit-learn
2021-03-26T14:01:38.0216010Z     - scipy
2021-03-26T14:01:38.0216770Z 
2021-03-26T14:01:38.0224960Z 
2021-03-26T14:01:38.0227330Z The following packages will be downloaded:
2021-03-26T14:01:38.0230750Z 
2021-03-26T14:01:38.0231800Z     package                    |            build
2021-03-26T14:01:38.0233610Z     ---------------------------|-----------------
2021-03-26T14:01:38.0235230Z     attrs-20.3.0               |     pyhd3eb1b0_0          43 KB
2021-03-26T14:01:38.0236740Z     blas-1.0                   |              mkl           6 KB
2021-03-26T14:01:38.0251780Z     bokeh-2.3.0                |   py37hecd8cb5_0         5.8 MB
2021-03-26T14:01:38.0257580Z     click-7.1.2                |     pyhd3eb1b0_0          64 KB
2021-03-26T14:01:38.0259470Z     cloudpickle-1.6.0          |             py_0          30 KB
2021-03-26T14:01:38.0262370Z     cycler-0.10.0              |           py37_0          14 KB
2021-03-26T14:01:38.0271430Z     cytoolz-0.11.0             |   py37haf1e3a3_0         289 KB
2021-03-26T14:01:38.0273220Z     dask-2021.3.0              |     pyhd3eb1b0_0           5 KB
2021-03-26T14:01:38.0275660Z     dask-core-2021.3.0         |     pyhd3eb1b0_0         659 KB
2021-03-26T14:01:38.0277220Z     distributed-2021.3.0       |   py37hecd8cb5_0         1.0 MB
2021-03-26T14:01:38.0285200Z     freetype-2.10.4            |       ha233b18_0         564 KB
2021-03-26T14:01:38.0287170Z     fsspec-0.8.7               |     pyhd3eb1b0_0          81 KB
2021-03-26T14:01:38.0288820Z     heapdict-1.0.1             |             py_0           9 KB
2021-03-26T14:01:38.0292430Z     importlib-metadata-3.7.3   |   py37hecd8cb5_1          31 KB
2021-03-26T14:01:38.0294080Z     importlib_metadata-3.7.3   |       hd3eb1b0_1          11 KB
2021-03-26T14:01:38.0295720Z     iniconfig-1.1.1            |     pyhd3eb1b0_0           8 KB
2021-03-26T14:01:38.0297870Z     intel-openmp-2019.4        |              233         887 KB
2021-03-26T14:01:38.0300060Z     jinja2-2.11.3              |     pyhd3eb1b0_0         101 KB
2021-03-26T14:01:38.0301470Z     joblib-1.0.1               |     pyhd3eb1b0_0         208 KB
2021-03-26T14:01:38.0303520Z     jpeg-9b                    |       he5867d9_2         201 KB
2021-03-26T14:01:38.0306030Z     kiwisolver-1.3.1           |   py37h23ab428_0          52 KB
2021-03-26T14:01:38.0307790Z     lcms2-2.11                 |       h92f6f08_0         278 KB
2021-03-26T14:01:38.0310270Z     libgfortran-3.0.1          |       h93005f0_2         426 KB
2021-03-26T14:01:38.0311910Z     libpng-1.6.37              |       ha441bb4_0         262 KB
2021-03-26T14:01:38.0313380Z     libtiff-4.2.0              |       h87d7836_0         462 KB
2021-03-26T14:01:38.0314440Z     libwebp-base-1.2.0         |       h9ed2024_0         389 KB
2021-03-26T14:01:38.0315540Z     llvm-openmp-10.0.0         |       h28b9765_0         236 KB
2021-03-26T14:01:38.0316760Z     locket-0.2.1               |   py37hecd8cb5_1          10 KB
2021-03-26T14:01:38.0317780Z     lz4-c-1.9.3                |       h23ab428_0         140 KB
2021-03-26T14:01:38.0319500Z     markupsafe-1.1.1           |   py37h1de35cc_0          27 KB
2021-03-26T14:01:38.0321100Z     matplotlib-3.3.4           |   py37hecd8cb5_0          26 KB
2021-03-26T14:01:38.0322200Z     matplotlib-base-3.3.4      |   py37h8b3ea08_0         5.1 MB
2021-03-26T14:01:38.0323220Z     mkl-2019.4                 |              233       101.9 MB
2021-03-26T14:01:38.0324540Z     mkl-service-2.3.0          |   py37h9ed2024_0          40 KB
2021-03-26T14:01:38.0325680Z     mkl_fft-1.3.0              |   py37ha059aab_0         157 KB
2021-03-26T14:01:38.0326750Z     mkl_random-1.1.1           |   py37h959d312_0         284 KB
2021-03-26T14:01:38.0328170Z     more-itertools-8.7.0       |     pyhd3eb1b0_0          42 KB
2021-03-26T14:01:38.0329250Z     msgpack-python-1.0.2       |   py37hf7b0b51_1          74 KB
2021-03-26T14:01:38.0330430Z     numpy-1.19.2               |   py37h456fd55_0          21 KB
2021-03-26T14:01:38.0331510Z     numpy-base-1.19.2          |   py37hcfb5961_0         4.0 MB
2021-03-26T14:01:38.0332660Z     olefile-0.46               |           py37_0          49 KB
2021-03-26T14:01:38.0333750Z     packaging-20.9             |     pyhd3eb1b0_0          37 KB
2021-03-26T14:01:38.0334830Z     pandas-1.2.3               |   py37hb2f4e1b_0         8.1 MB
2021-03-26T14:01:38.0336040Z     partd-1.1.0                |             py_0          20 KB
2021-03-26T14:01:38.0337040Z     pillow-8.1.2               |   py37h5270095_0         588 KB
2021-03-26T14:01:38.0338120Z     pluggy-0.13.1              |   py37hecd8cb5_0          33 KB
2021-03-26T14:01:38.0339880Z     psutil-5.8.0               |   py37h9ed2024_1         336 KB
2021-03-26T14:01:38.0340940Z     py-1.10.0                  |     pyhd3eb1b0_0          76 KB
2021-03-26T14:01:38.0341940Z     pyparsing-2.4.7            |     pyhd3eb1b0_0          59 KB
2021-03-26T14:01:38.0343020Z     pytest-6.2.2               |   py37hecd8cb5_2         435 KB
2021-03-26T14:01:38.0344080Z     python-dateutil-2.8.1      |     pyhd3eb1b0_0         221 KB
2021-03-26T14:01:38.0345150Z     pytz-2021.1                |     pyhd3eb1b0_0         181 KB
2021-03-26T14:01:38.0346160Z     pyyaml-5.4.1               |   py37h9ed2024_1         162 KB
2021-03-26T14:01:38.0347620Z     scikit-learn-0.24.1        |   py37hb2f4e1b_0         4.8 MB
2021-03-26T14:01:38.0348900Z     scipy-1.6.1                |   py37h2515648_0        14.4 MB
2021-03-26T14:01:38.0349970Z     six-1.15.0                 |   py37hecd8cb5_0          27 KB
2021-03-26T14:01:38.0351460Z     sortedcontainers-2.3.0     |     pyhd3eb1b0_0          26 KB
2021-03-26T14:01:38.0352650Z     tblib-1.7.0                |             py_0          16 KB
2021-03-26T14:01:38.0353750Z     threadpoolctl-2.1.0        |     pyh5ca1d4c_0          17 KB
2021-03-26T14:01:38.0354820Z     toml-0.10.2                |     pyhd3eb1b0_0          20 KB
2021-03-26T14:01:38.0355840Z     toolz-0.11.1               |     pyhd3eb1b0_0          46 KB
2021-03-26T14:01:38.0356910Z     tornado-6.1                |   py37h9ed2024_0         588 KB
2021-03-26T14:01:38.0358070Z     typing_extensions-3.7.4.3  |     pyha847dfd_0          25 KB
2021-03-26T14:01:38.0359130Z     zict-2.0.0                 |     pyhd3eb1b0_0          10 KB
2021-03-26T14:01:38.0360180Z     zipp-3.4.1                 |     pyhd3eb1b0_0          15 KB
2021-03-26T14:01:38.0361250Z     zstd-1.4.5                 |       h41d2c2f_0         442 KB
2021-03-26T14:01:38.0362310Z     ------------------------------------------------------------
2021-03-26T14:01:38.0363050Z                                            Total:       154.5 MB
2021-03-26T14:01:38.0363430Z 
2021-03-26T14:01:38.0363940Z The following NEW packages will be INSTALLED:
2021-03-26T14:01:38.0364270Z 
2021-03-26T14:01:38.0365150Z   attrs              pkgs/main/noarch::attrs-20.3.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0366190Z   blas               pkgs/main/osx-64::blas-1.0-mkl
2021-03-26T14:01:38.0367200Z   bokeh              pkgs/main/osx-64::bokeh-2.3.0-py37hecd8cb5_0
2021-03-26T14:01:38.0368680Z   click              pkgs/main/noarch::click-7.1.2-pyhd3eb1b0_0
2021-03-26T14:01:38.0369760Z   cloudpickle        pkgs/main/noarch::cloudpickle-1.6.0-py_0
2021-03-26T14:01:38.0370810Z   cycler             pkgs/main/osx-64::cycler-0.10.0-py37_0
2021-03-26T14:01:38.0371850Z   cytoolz            pkgs/main/osx-64::cytoolz-0.11.0-py37haf1e3a3_0
2021-03-26T14:01:38.0372940Z   dask               pkgs/main/noarch::dask-2021.3.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0374030Z   dask-core          pkgs/main/noarch::dask-core-2021.3.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0375140Z   distributed        pkgs/main/osx-64::distributed-2021.3.0-py37hecd8cb5_0
2021-03-26T14:01:38.0376200Z   freetype           pkgs/main/osx-64::freetype-2.10.4-ha233b18_0
2021-03-26T14:01:38.0377280Z   fsspec             pkgs/main/noarch::fsspec-0.8.7-pyhd3eb1b0_0
2021-03-26T14:01:38.0378340Z   heapdict           pkgs/main/noarch::heapdict-1.0.1-py_0
2021-03-26T14:01:38.0379430Z   importlib-metadata pkgs/main/osx-64::importlib-metadata-3.7.3-py37hecd8cb5_1
2021-03-26T14:01:38.0380520Z   importlib_metadata pkgs/main/noarch::importlib_metadata-3.7.3-hd3eb1b0_1
2021-03-26T14:01:38.0381620Z   iniconfig          pkgs/main/noarch::iniconfig-1.1.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0382690Z   intel-openmp       pkgs/main/osx-64::intel-openmp-2019.4-233
2021-03-26T14:01:38.0383780Z   jinja2             pkgs/main/noarch::jinja2-2.11.3-pyhd3eb1b0_0
2021-03-26T14:01:38.0384860Z   joblib             pkgs/main/noarch::joblib-1.0.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0385920Z   jpeg               pkgs/main/osx-64::jpeg-9b-he5867d9_2
2021-03-26T14:01:38.0386990Z   kiwisolver         pkgs/main/osx-64::kiwisolver-1.3.1-py37h23ab428_0
2021-03-26T14:01:38.0388150Z   lcms2              pkgs/main/osx-64::lcms2-2.11-h92f6f08_0
2021-03-26T14:01:38.0389180Z   libgfortran        pkgs/main/osx-64::libgfortran-3.0.1-h93005f0_2
2021-03-26T14:01:38.0390260Z   libpng             pkgs/main/osx-64::libpng-1.6.37-ha441bb4_0
2021-03-26T14:01:38.0391330Z   libtiff            pkgs/main/osx-64::libtiff-4.2.0-h87d7836_0
2021-03-26T14:01:38.0392420Z   libwebp-base       pkgs/main/osx-64::libwebp-base-1.2.0-h9ed2024_0
2021-03-26T14:01:38.0393460Z   llvm-openmp        pkgs/main/osx-64::llvm-openmp-10.0.0-h28b9765_0
2021-03-26T14:01:38.0394920Z   locket             pkgs/main/osx-64::locket-0.2.1-py37hecd8cb5_1
2021-03-26T14:01:38.0396010Z   lz4-c              pkgs/main/osx-64::lz4-c-1.9.3-h23ab428_0
2021-03-26T14:01:38.0397090Z   markupsafe         pkgs/main/osx-64::markupsafe-1.1.1-py37h1de35cc_0
2021-03-26T14:01:38.0398140Z   matplotlib         pkgs/main/osx-64::matplotlib-3.3.4-py37hecd8cb5_0
2021-03-26T14:01:38.0399250Z   matplotlib-base    pkgs/main/osx-64::matplotlib-base-3.3.4-py37h8b3ea08_0
2021-03-26T14:01:38.0400360Z   mkl                pkgs/main/osx-64::mkl-2019.4-233
2021-03-26T14:01:38.0401450Z   mkl-service        pkgs/main/osx-64::mkl-service-2.3.0-py37h9ed2024_0
2021-03-26T14:01:38.0402450Z   mkl_fft            pkgs/main/osx-64::mkl_fft-1.3.0-py37ha059aab_0
2021-03-26T14:01:38.0403550Z   mkl_random         pkgs/main/osx-64::mkl_random-1.1.1-py37h959d312_0
2021-03-26T14:01:38.0404660Z   more-itertools     pkgs/main/noarch::more-itertools-8.7.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0405760Z   msgpack-python     pkgs/main/osx-64::msgpack-python-1.0.2-py37hf7b0b51_1
2021-03-26T14:01:38.0406820Z   numpy              pkgs/main/osx-64::numpy-1.19.2-py37h456fd55_0
2021-03-26T14:01:38.0407990Z   numpy-base         pkgs/main/osx-64::numpy-base-1.19.2-py37hcfb5961_0
2021-03-26T14:01:38.0409070Z   olefile            pkgs/main/osx-64::olefile-0.46-py37_0
2021-03-26T14:01:38.0410130Z   packaging          pkgs/main/noarch::packaging-20.9-pyhd3eb1b0_0
2021-03-26T14:01:38.0411160Z   pandas             pkgs/main/osx-64::pandas-1.2.3-py37hb2f4e1b_0
2021-03-26T14:01:38.0412290Z   partd              pkgs/main/noarch::partd-1.1.0-py_0
2021-03-26T14:01:38.0413360Z   pillow             pkgs/main/osx-64::pillow-8.1.2-py37h5270095_0
2021-03-26T14:01:38.0414440Z   pluggy             pkgs/main/osx-64::pluggy-0.13.1-py37hecd8cb5_0
2021-03-26T14:01:38.0415800Z   psutil             pkgs/main/osx-64::psutil-5.8.0-py37h9ed2024_1
2021-03-26T14:01:38.0416890Z   py                 pkgs/main/noarch::py-1.10.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0418060Z   pyparsing          pkgs/main/noarch::pyparsing-2.4.7-pyhd3eb1b0_0
2021-03-26T14:01:38.0419140Z   pytest             pkgs/main/osx-64::pytest-6.2.2-py37hecd8cb5_2
2021-03-26T14:01:38.0420580Z   python-dateutil    pkgs/main/noarch::python-dateutil-2.8.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0421800Z   pytz               pkgs/main/noarch::pytz-2021.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0422940Z   pyyaml             pkgs/main/osx-64::pyyaml-5.4.1-py37h9ed2024_1
2021-03-26T14:01:38.0424060Z   scikit-learn       pkgs/main/osx-64::scikit-learn-0.24.1-py37hb2f4e1b_0
2021-03-26T14:01:38.0425310Z   scipy              pkgs/main/osx-64::scipy-1.6.1-py37h2515648_0
2021-03-26T14:01:38.0426400Z   six                pkgs/main/osx-64::six-1.15.0-py37hecd8cb5_0
2021-03-26T14:01:38.0427980Z   sortedcontainers   pkgs/main/noarch::sortedcontainers-2.3.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0429130Z   tblib              pkgs/main/noarch::tblib-1.7.0-py_0
2021-03-26T14:01:38.0430180Z   threadpoolctl      pkgs/main/noarch::threadpoolctl-2.1.0-pyh5ca1d4c_0
2021-03-26T14:01:38.0431290Z   toml               pkgs/main/noarch::toml-0.10.2-pyhd3eb1b0_0
2021-03-26T14:01:38.0432360Z   toolz              pkgs/main/noarch::toolz-0.11.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0433450Z   tornado            pkgs/main/osx-64::tornado-6.1-py37h9ed2024_0
2021-03-26T14:01:38.0434570Z   typing_extensions  pkgs/main/noarch::typing_extensions-3.7.4.3-pyha847dfd_0
2021-03-26T14:01:38.0435660Z   yaml               pkgs/main/osx-64::yaml-0.2.5-haf1e3a3_0
2021-03-26T14:01:38.0436720Z   zict               pkgs/main/noarch::zict-2.0.0-pyhd3eb1b0_0
2021-03-26T14:01:38.0437790Z   zipp               pkgs/main/noarch::zipp-3.4.1-pyhd3eb1b0_0
2021-03-26T14:01:38.0438800Z   zstd               pkgs/main/osx-64::zstd-1.4.5-h41d2c2f_0
2021-03-26T14:01:38.0439250Z 
2021-03-26T14:01:55.1235650Z 
2021-03-26T14:01:56.0094450Z Preparing transaction: ...working... done
2021-03-26T14:01:58.6879480Z Verifying transaction: ...working... done
2021-03-26T14:02:05.9459990Z Executing transaction: ...working... done
2021-03-26T14:02:16.9783720Z Collecting package metadata (current_repodata.json): ...working... done
2021-03-26T14:02:22.9084530Z Solving environment: ...working... done
2021-03-26T14:02:36.3996060Z 
2021-03-26T14:02:36.4028950Z ## Package Plan ##
2021-03-26T14:02:36.4061620Z 
2021-03-26T14:02:36.4091960Z   environment location: /Users/runner/runners/2.183.1/miniconda/envs/test-env
2021-03-26T14:02:36.4193370Z 
2021-03-26T14:02:36.4295430Z   added / updated specs:
2021-03-26T14:02:36.4397830Z     - python-graphviz
2021-03-26T14:02:36.4498900Z 
2021-03-26T14:02:36.4600120Z 
2021-03-26T14:02:36.4644780Z The following packages will be downloaded:
2021-03-26T14:02:36.4647340Z 
2021-03-26T14:02:36.4648490Z     package                    |            build
2021-03-26T14:02:36.4650350Z     ---------------------------|-----------------
2021-03-26T14:02:36.4652070Z     atk-1.0-2.36.0             |       he69c4ee_4         359 KB  conda-forge
2021-03-26T14:02:36.4653770Z     ca-certificates-2020.12.5  |       h033912b_0         138 KB  conda-forge
2021-03-26T14:02:36.4655440Z     cairo-1.16.0               |    he43a7df_1008         1.3 MB  conda-forge
2021-03-26T14:02:36.4657100Z     certifi-2020.12.5          |   py37hf985489_1         143 KB  conda-forge
2021-03-26T14:02:36.4658690Z     expat-2.2.10               |       h1c7c35f_0         128 KB  conda-forge
2021-03-26T14:02:36.4660350Z     font-ttf-dejavu-sans-mono-2.37|       hab24e00_0         388 KB  conda-forge
2021-03-26T14:02:36.4662030Z     font-ttf-inconsolata-2.001 |       hab24e00_0          97 KB  conda-forge
2021-03-26T14:02:36.4663530Z     font-ttf-source-code-pro-2.030|       hab24e00_0         927 KB  conda-forge
2021-03-26T14:02:36.4665150Z     font-ttf-ubuntu-0.83       |       hab24e00_0         1.9 MB  conda-forge
2021-03-26T14:02:36.4667360Z     fontconfig-2.13.1          |    hd23ceaa_1004         270 KB  conda-forge
2021-03-26T14:02:36.4669490Z     fonts-conda-ecosystem-1    |                0           4 KB  conda-forge
2021-03-26T14:02:36.4671240Z     fonts-conda-forge-1        |                0           4 KB  conda-forge
2021-03-26T14:02:36.4672770Z     fribidi-1.0.10             |       hbcb3906_0          64 KB  conda-forge
2021-03-26T14:02:36.4674450Z     gdk-pixbuf-2.42.4          |       h2e6141f_2         577 KB  conda-forge
2021-03-26T14:02:36.4676090Z     gettext-0.19.8.1           |    h7937167_1005         3.3 MB  conda-forge
2021-03-26T14:02:36.4677690Z     giflib-5.2.1               |       hbcb3906_2          71 KB  conda-forge
2021-03-26T14:02:36.4679320Z     graphite2-1.3.13           |    h2e338ed_1001          85 KB  conda-forge
2021-03-26T14:02:36.4681040Z     graphviz-2.47.0            |       ha2e93d9_0         5.2 MB  conda-forge
2021-03-26T14:02:36.4682660Z     gtk2-2.24.33               |       h55c0dba_0         7.0 MB  conda-forge
2021-03-26T14:02:36.4684310Z     gts-0.7.6                  |       hccb3bdf_2         327 KB  conda-forge
2021-03-26T14:02:36.4685860Z     harfbuzz-2.8.0             |       h159f659_1         1.6 MB  conda-forge
2021-03-26T14:02:36.4687450Z     icu-68.1                   |       h74dc148_0        12.7 MB  conda-forge
2021-03-26T14:02:36.4689070Z     jpeg-9d                    |       hbcb3906_0         250 KB  conda-forge
2021-03-26T14:02:36.4690690Z     libcxx-11.1.0              |       habf9029_0         1.0 MB  conda-forge
2021-03-26T14:02:36.4692300Z     libgd-2.3.0                |       h55673e3_1         238 KB  conda-forge
2021-03-26T14:02:36.4693860Z     libglib-2.68.0             |       hd556434_2         2.8 MB  conda-forge
2021-03-26T14:02:36.4695500Z     libiconv-1.16              |       haf1e3a3_0         1.3 MB  conda-forge
2021-03-26T14:02:36.4697120Z     librsvg-2.50.3             |       hd4300c0_1         4.3 MB  conda-forge
2021-03-26T14:02:36.4698710Z     libtool-2.4.6              |    h2e338ed_1007         528 KB  conda-forge
2021-03-26T14:02:36.4701350Z     libwebp-1.2.0              |       h1648767_0          78 KB  conda-forge
2021-03-26T14:02:36.4703490Z     libxml2-2.9.10             |       h802ca4f_3         1.2 MB  conda-forge
2021-03-26T14:02:36.4705130Z     openssl-1.1.1k             |       h0d85af4_0         1.9 MB  conda-forge
2021-03-26T14:02:36.4706860Z     pango-1.42.4               |       ha86e081_5         526 KB  conda-forge
2021-03-26T14:02:36.4708510Z     pcre-8.44                  |       hb1e8313_0         220 KB  conda-forge
2021-03-26T14:02:36.4710180Z     pixman-0.40.0              |       hbcb3906_0         615 KB  conda-forge
2021-03-26T14:02:36.4711900Z     python-graphviz-0.16       |     pyh243d235_2          20 KB  conda-forge
2021-03-26T14:02:36.4713520Z     python_abi-3.7             |          1_cp37m           4 KB  conda-forge
2021-03-26T14:02:36.4715190Z     ------------------------------------------------------------
2021-03-26T14:02:36.4716450Z                                            Total:        51.5 MB
2021-03-26T14:02:36.4717310Z 
2021-03-26T14:02:36.4718410Z The following NEW packages will be INSTALLED:
2021-03-26T14:02:36.4719180Z 
2021-03-26T14:02:36.4720600Z   atk-1.0            conda-forge/osx-64::atk-1.0-2.36.0-he69c4ee_4
2021-03-26T14:02:36.4722270Z   cairo              conda-forge/osx-64::cairo-1.16.0-he43a7df_1008
2021-03-26T14:02:36.4723750Z   expat              conda-forge/osx-64::expat-2.2.10-h1c7c35f_0
2021-03-26T14:02:36.4725420Z   font-ttf-dejavu-s~ conda-forge/noarch::font-ttf-dejavu-sans-mono-2.37-hab24e00_0
2021-03-26T14:02:36.4727100Z   font-ttf-inconsol~ conda-forge/noarch::font-ttf-inconsolata-2.001-hab24e00_0
2021-03-26T14:02:36.4728750Z   font-ttf-source-c~ conda-forge/noarch::font-ttf-source-code-pro-2.030-hab24e00_0
2021-03-26T14:02:36.4730460Z   font-ttf-ubuntu    conda-forge/noarch::font-ttf-ubuntu-0.83-hab24e00_0
2021-03-26T14:02:36.4731970Z   fontconfig         conda-forge/osx-64::fontconfig-2.13.1-hd23ceaa_1004
2021-03-26T14:02:36.4734090Z   fonts-conda-ecosy~ conda-forge/noarch::fonts-conda-ecosystem-1-0
2021-03-26T14:02:36.4735700Z   fonts-conda-forge  conda-forge/noarch::fonts-conda-forge-1-0
2021-03-26T14:02:36.4737500Z   fribidi            conda-forge/osx-64::fribidi-1.0.10-hbcb3906_0
2021-03-26T14:02:36.4739130Z   gdk-pixbuf         conda-forge/osx-64::gdk-pixbuf-2.42.4-h2e6141f_2
2021-03-26T14:02:36.4740610Z   gettext            conda-forge/osx-64::gettext-0.19.8.1-h7937167_1005
2021-03-26T14:02:36.4742490Z   giflib             conda-forge/osx-64::giflib-5.2.1-hbcb3906_2
2021-03-26T14:02:36.4744210Z   graphite2          conda-forge/osx-64::graphite2-1.3.13-h2e338ed_1001
2021-03-26T14:02:36.4745800Z   graphviz           conda-forge/osx-64::graphviz-2.47.0-ha2e93d9_0
2021-03-26T14:02:36.4747450Z   gtk2               conda-forge/osx-64::gtk2-2.24.33-h55c0dba_0
2021-03-26T14:02:36.4748910Z   gts                conda-forge/osx-64::gts-0.7.6-hccb3bdf_2
2021-03-26T14:02:36.4750450Z   harfbuzz           conda-forge/osx-64::harfbuzz-2.8.0-h159f659_1
2021-03-26T14:02:36.4752040Z   icu                conda-forge/osx-64::icu-68.1-h74dc148_0
2021-03-26T14:02:36.4753560Z   libgd              conda-forge/osx-64::libgd-2.3.0-h55673e3_1
2021-03-26T14:02:36.4755160Z   libglib            conda-forge/osx-64::libglib-2.68.0-hd556434_2
2021-03-26T14:02:36.4756600Z   libiconv           conda-forge/osx-64::libiconv-1.16-haf1e3a3_0
2021-03-26T14:02:36.4758170Z   librsvg            conda-forge/osx-64::librsvg-2.50.3-hd4300c0_1
2021-03-26T14:02:36.4759770Z   libtool            conda-forge/osx-64::libtool-2.4.6-h2e338ed_1007
2021-03-26T14:02:36.4761310Z   libwebp            conda-forge/osx-64::libwebp-1.2.0-h1648767_0
2021-03-26T14:02:36.4764210Z   libxml2            conda-forge/osx-64::libxml2-2.9.10-h802ca4f_3
2021-03-26T14:02:36.4765700Z   pango              conda-forge/osx-64::pango-1.42.4-ha86e081_5
2021-03-26T14:02:36.4767820Z   pcre               conda-forge/osx-64::pcre-8.44-hb1e8313_0
2021-03-26T14:02:36.4769460Z   pixman             conda-forge/osx-64::pixman-0.40.0-hbcb3906_0
2021-03-26T14:02:36.4771140Z   python-graphviz    conda-forge/noarch::python-graphviz-0.16-pyh243d235_2
2021-03-26T14:02:36.4773070Z   python_abi         conda-forge/osx-64::python_abi-3.7-1_cp37m
2021-03-26T14:02:36.4773840Z 
2021-03-26T14:02:36.4774760Z The following packages will be UPDATED:
2021-03-26T14:02:36.4775590Z 
2021-03-26T14:02:36.4777130Z   certifi            pkgs/main::certifi-2020.12.5-py37hecd~ --> conda-forge::certifi-2020.12.5-py37hf985489_1
2021-03-26T14:02:36.4778960Z   jpeg                        pkgs/main::jpeg-9b-he5867d9_2 --> conda-forge::jpeg-9d-hbcb3906_0
2021-03-26T14:02:36.4780720Z   libcxx                         pkgs/main::libcxx-10.0.0-1 --> conda-forge::libcxx-11.1.0-habf9029_0
2021-03-26T14:02:36.4781680Z 
2021-03-26T14:02:36.4783090Z The following packages will be SUPERSEDED by a higher-priority channel:
2021-03-26T14:02:36.4784840Z 
2021-03-26T14:02:36.4786550Z   ca-certificates    pkgs/main::ca-certificates-2021.1.19-~ --> conda-forge::ca-certificates-2020.12.5-h033912b_0
2021-03-26T14:02:36.4788390Z   openssl              pkgs/main::openssl-1.1.1k-h9ed2024_0 --> conda-forge::openssl-1.1.1k-h0d85af4_0
2021-03-26T14:02:36.4789380Z 
2021-03-26T14:02:36.4790070Z 
2021-03-26T14:02:36.9203830Z Preparing transaction: ...working... done
2021-03-26T14:02:38.4650340Z Verifying transaction: ...working... done
2021-03-26T14:02:42.9167890Z Executing transaction: ...working... 
2021-03-26T14:02:42.9227910Z 
2021-03-26T14:02:42.9280100Z done
2021-03-26T14:02:54.3845280Z -- The C compiler identification is AppleClang 9.1.0.9020039
2021-03-26T14:02:54.4862700Z -- The CXX compiler identification is AppleClang 9.1.0.9020039
2021-03-26T14:02:54.5211310Z -- Detecting C compiler ABI info
2021-03-26T14:02:55.3717440Z -- Detecting C compiler ABI info - done
2021-03-26T14:02:55.3811530Z -- Check for working C compiler: /Applications/Xcode_9.4.1.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/cc - skipped
2021-03-26T14:02:55.3819330Z -- Detecting C compile features
2021-03-26T14:02:55.3831040Z -- Detecting C compile features - done
2021-03-26T14:02:55.3919580Z -- Detecting CXX compiler ABI info
2021-03-26T14:02:55.5886620Z -- Detecting CXX compiler ABI info - done
2021-03-26T14:02:55.5988250Z -- Check for working CXX compiler: /Applications/Xcode_9.4.1.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/c++ - skipped
2021-03-26T14:02:55.5990500Z -- Detecting CXX compile features
2021-03-26T14:02:55.5998710Z -- Detecting CXX compile features - done
2021-03-26T14:02:59.1815780Z -- Found OpenMP_C: -Xclang -fopenmp (found version "3.1") 
2021-03-26T14:02:59.4454650Z -- Found OpenMP_CXX: -Xclang -fopenmp (found version "3.1") 
2021-03-26T14:02:59.4488560Z -- Found OpenMP: TRUE (found version "3.1")  
2021-03-26T14:02:59.4503410Z -- Performing Test MM_PREFETCH
2021-03-26T14:02:59.7909210Z -- Performing Test MM_PREFETCH - Success
2021-03-26T14:02:59.7946470Z -- Using _mm_prefetch
2021-03-26T14:02:59.7981670Z -- Performing Test MM_MALLOC
2021-03-26T14:03:00.0854370Z -- Performing Test MM_MALLOC - Success
2021-03-26T14:03:00.0859280Z -- Using _mm_malloc
2021-03-26T14:03:00.0903410Z -- Configuring done
2021-03-26T14:03:00.1571760Z -- Generating done
2021-03-26T14:03:00.1758660Z -- Build files have been written to: /Users/runner/work/1/s/build
2021-03-26T14:03:00.3991990Z Scanning dependencies of target _lightgbm
2021-03-26T14:03:00.4374380Z [  2%] Building CXX object CMakeFiles/_lightgbm.dir/src/boosting/gbdt.cpp.o
2021-03-26T14:03:00.4476380Z [  8%] Building CXX object CMakeFiles/_lightgbm.dir/src/boosting/boosting.cpp.o
2021-03-26T14:03:00.4513280Z [  8%] Building CXX object CMakeFiles/_lightgbm.dir/src/boosting/gbdt_model_text.cpp.o
2021-03-26T14:03:00.4788790Z [ 11%] Building CXX object CMakeFiles/_lightgbm.dir/src/boosting/gbdt_prediction.cpp.o
2021-03-26T14:03:05.9237030Z [ 14%] Building CXX object CMakeFiles/_lightgbm.dir/src/boosting/prediction_early_stop.cpp.o
2021-03-26T14:03:08.1070100Z [ 17%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/bin.cpp.o
2021-03-26T14:03:09.7846190Z [ 20%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/config.cpp.o
2021-03-26T14:03:10.9949500Z [ 23%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/config_auto.cpp.o
2021-03-26T14:03:11.4205210Z [ 26%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/dataset.cpp.o
2021-03-26T14:03:15.4275640Z [ 29%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/dataset_loader.cpp.o
2021-03-26T14:03:17.2683920Z [ 32%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/file_io.cpp.o
2021-03-26T14:03:18.6537710Z [ 35%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/json11.cpp.o
2021-03-26T14:03:23.3338590Z [ 38%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/metadata.cpp.o
2021-03-26T14:03:23.4386640Z [ 41%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/parser.cpp.o
2021-03-26T14:03:27.6897730Z [ 44%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/train_share_states.cpp.o
2021-03-26T14:03:28.9619340Z [ 47%] Building CXX object CMakeFiles/_lightgbm.dir/src/io/tree.cpp.o
2021-03-26T14:03:29.9726040Z [ 50%] Building CXX object CMakeFiles/_lightgbm.dir/src/metric/dcg_calculator.cpp.o
2021-03-26T14:03:31.9828230Z [ 52%] Building CXX object CMakeFiles/_lightgbm.dir/src/metric/metric.cpp.o
2021-03-26T14:03:32.5382930Z [ 55%] Building CXX object CMakeFiles/_lightgbm.dir/src/network/ifaddrs_patch.cpp.o
2021-03-26T14:03:32.5784830Z [ 58%] Building CXX object CMakeFiles/_lightgbm.dir/src/network/linker_topo.cpp.o
2021-03-26T14:03:35.8380520Z [ 61%] Building CXX object CMakeFiles/_lightgbm.dir/src/network/linkers_mpi.cpp.o
2021-03-26T14:03:35.8681880Z [ 64%] Building CXX object CMakeFiles/_lightgbm.dir/src/network/linkers_socket.cpp.o
2021-03-26T14:03:36.4823400Z [ 67%] Building CXX object CMakeFiles/_lightgbm.dir/src/network/network.cpp.o
2021-03-26T14:03:42.3805930Z [ 70%] Building CXX object CMakeFiles/_lightgbm.dir/src/objective/objective_function.cpp.o
2021-03-26T14:03:44.3745420Z [ 73%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/cuda_tree_learner.cpp.o
2021-03-26T14:03:44.4117800Z [ 76%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/data_parallel_tree_learner.cpp.o
2021-03-26T14:03:46.6469830Z [ 79%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/feature_parallel_tree_learner.cpp.o
2021-03-26T14:03:53.4194970Z [ 82%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/gpu_tree_learner.cpp.o
2021-03-26T14:03:53.4595820Z [ 85%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/linear_tree_learner.cpp.o
2021-03-26T14:03:56.7869430Z [ 88%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/serial_tree_learner.cpp.o
2021-03-26T14:04:09.6072310Z [ 91%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/tree_learner.cpp.o
2021-03-26T14:04:09.7055000Z [ 94%] Building CXX object CMakeFiles/_lightgbm.dir/src/treelearner/voting_parallel_tree_learner.cpp.o
2021-03-26T14:04:30.5271690Z [ 97%] Building CXX object CMakeFiles/_lightgbm.dir/src/c_api.cpp.o
2021-03-26T14:05:07.9427190Z [100%] Linking CXX shared library ../lib_lightgbm.so
2021-03-26T14:05:08.1630120Z [100%] Built target _lightgbm
2021-03-26T14:05:08.6041790Z running install
2021-03-26T14:05:08.6514720Z running build
2021-03-26T14:05:08.6515720Z running build_py
2021-03-26T14:05:08.6761960Z creating build
2021-03-26T14:05:08.6762680Z creating build/lib
2021-03-26T14:05:08.6764670Z creating build/lib/lightgbm
2021-03-26T14:05:08.6766060Z copying lightgbm/callback.py -> build/lib/lightgbm
2021-03-26T14:05:08.6770270Z copying lightgbm/compat.py -> build/lib/lightgbm
2021-03-26T14:05:08.6774500Z copying lightgbm/plotting.py -> build/lib/lightgbm
2021-03-26T14:05:08.6779890Z copying lightgbm/__init__.py -> build/lib/lightgbm
2021-03-26T14:05:08.6784140Z copying lightgbm/engine.py -> build/lib/lightgbm
2021-03-26T14:05:08.6790220Z copying lightgbm/dask.py -> build/lib/lightgbm
2021-03-26T14:05:08.6796850Z copying lightgbm/basic.py -> build/lib/lightgbm
2021-03-26T14:05:08.6900800Z copying lightgbm/libpath.py -> build/lib/lightgbm
2021-03-26T14:05:08.7003560Z copying lightgbm/sklearn.py -> build/lib/lightgbm
2021-03-26T14:05:08.7005140Z running egg_info
2021-03-26T14:05:08.7107770Z creating lightgbm.egg-info
2021-03-26T14:05:08.7211730Z writing lightgbm.egg-info/PKG-INFO
2021-03-26T14:05:08.7314550Z writing dependency_links to lightgbm.egg-info/dependency_links.txt
2021-03-26T14:05:08.7387320Z writing requirements to lightgbm.egg-info/requires.txt
2021-03-26T14:05:08.7389380Z writing top-level names to lightgbm.egg-info/top_level.txt
2021-03-26T14:05:08.7391020Z writing manifest file 'lightgbm.egg-info/SOURCES.txt'
2021-03-26T14:05:08.7392520Z reading manifest file 'lightgbm.egg-info/SOURCES.txt'
2021-03-26T14:05:08.7393960Z reading manifest template 'MANIFEST.in'
2021-03-26T14:05:08.7395410Z no previously-included directories found matching 'build'
2021-03-26T14:05:08.7396990Z warning: no files found matching 'LICENSE'
2021-03-26T14:05:08.7399060Z warning: no files found matching '*.txt'
2021-03-26T14:05:08.7400510Z warning: no files found matching '*.so' under directory 'lightgbm'
2021-03-26T14:05:08.7402070Z warning: no files found matching 'compile/CMakeLists.txt'
2021-03-26T14:05:08.7403650Z warning: no files found matching 'compile/cmake/IntegratedOpenCL.cmake'
2021-03-26T14:05:08.7405210Z warning: no files found matching '*.so' under directory 'compile'
2021-03-26T14:05:08.7406800Z warning: no files found matching '*.dll' under directory 'compile/Release'
2021-03-26T14:05:08.7409510Z warning: no files found matching 'compile/external_libs/compute/CMakeLists.txt'
2021-03-26T14:05:08.7411800Z warning: no files found matching '*' under directory 'compile/external_libs/compute/cmake'
2021-03-26T14:05:08.7413610Z warning: no files found matching '*' under directory 'compile/external_libs/compute/include'
2021-03-26T14:05:08.7415690Z warning: no files found matching '*' under directory 'compile/external_libs/compute/meta'
2021-03-26T14:05:08.7417280Z warning: no files found matching 'compile/external_libs/eigen/CMakeLists.txt'
2021-03-26T14:05:08.7427200Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Cholesky'
2021-03-26T14:05:08.7428310Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Core'
2021-03-26T14:05:08.7429410Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Dense'
2021-03-26T14:05:08.7430470Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Eigenvalues'
2021-03-26T14:05:08.7431560Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Geometry'
2021-03-26T14:05:08.7432650Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Householder'
2021-03-26T14:05:08.7433710Z warning: no files found matching 'compile/external_libs/eigen/Eigen/Jacobi'
2021-03-26T14:05:08.7434770Z warning: no files found matching 'compile/external_libs/eigen/Eigen/LU'
2021-03-26T14:05:08.7435820Z warning: no files found matching 'compile/external_libs/eigen/Eigen/QR'
2021-03-26T14:05:08.7438140Z warning: no files found matching 'compile/external_libs/eigen/Eigen/SVD'
2021-03-26T14:05:08.7439510Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Cholesky'
2021-03-26T14:05:08.7440730Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Core'
2021-03-26T14:05:08.7441930Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Eigenvalues'
2021-03-26T14:05:08.7443130Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Geometry'
2021-03-26T14:05:08.7444330Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Householder'
2021-03-26T14:05:08.7445490Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/Jacobi'
2021-03-26T14:05:08.7446760Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/LU'
2021-03-26T14:05:08.7447980Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/misc'
2021-03-26T14:05:08.7449180Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/plugins'
2021-03-26T14:05:08.7450670Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/QR'
2021-03-26T14:05:08.7451890Z warning: no files found matching '*' under directory 'compile/external_libs/eigen/Eigen/src/SVD'
2021-03-26T14:05:08.7453080Z warning: no files found matching 'compile/external_libs/fast_double_parser/CMakeLists.txt'
2021-03-26T14:05:08.7454210Z warning: no files found matching 'compile/external_libs/fast_double_parser/LICENSE'
2021-03-26T14:05:08.7455320Z warning: no files found matching 'compile/external_libs/fast_double_parser/LICENSE.BSL'
2021-03-26T14:05:08.7456570Z warning: no files found matching '*' under directory 'compile/external_libs/fast_double_parser/include'
2021-03-26T14:05:08.7457700Z warning: no files found matching 'compile/external_libs/fmt/CMakeLists.txt'
2021-03-26T14:05:08.7458780Z warning: no files found matching 'compile/external_libs/fmt/LICENSE.rst'
2021-03-26T14:05:08.7459870Z warning: no files found matching '*' under directory 'compile/external_libs/fmt/include'
2021-03-26T14:05:08.7460950Z warning: no files found matching '*' under directory 'compile/include'
2021-03-26T14:05:08.7461990Z warning: no files found matching '*' under directory 'compile/src'
2021-03-26T14:05:08.7463060Z warning: no files found matching 'LightGBM.sln' under directory 'compile/windows'
2021-03-26T14:05:08.7464110Z warning: no files found matching 'LightGBM.vcxproj' under directory 'compile/windows'
2021-03-26T14:05:08.7465210Z warning: no files found matching '*.dll' under directory 'compile/windows/x64/DLL'
2021-03-26T14:05:08.7466330Z warning: no previously-included files matching '*.py[co]' found anywhere in distribution
2021-03-26T14:05:08.7467460Z warning: no previously-included files found matching 'compile/external_libs/compute/.git'
2021-03-26T14:05:08.7468950Z writing manifest file 'lightgbm.egg-info/SOURCES.txt'
2021-03-26T14:05:08.7469910Z copying lightgbm/VERSION.txt -> build/lib/lightgbm
2021-03-26T14:05:08.7470470Z running install_lib
2021-03-26T14:05:08.7471380Z creating /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7472490Z copying build/lib/lightgbm/callback.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7473640Z copying build/lib/lightgbm/compat.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7474800Z copying build/lib/lightgbm/plotting.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7475970Z copying build/lib/lightgbm/__init__.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7477130Z copying build/lib/lightgbm/engine.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7478290Z copying build/lib/lightgbm/dask.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7479440Z copying build/lib/lightgbm/basic.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7480600Z copying build/lib/lightgbm/libpath.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7481770Z copying build/lib/lightgbm/sklearn.py -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7483000Z copying build/lib/lightgbm/VERSION.txt -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7484080Z INFO:LightGBM:Installing lib_lightgbm from: ['../lib_lightgbm.so']
2021-03-26T14:05:08.7485240Z copying ../lib_lightgbm.so -> /Users/runner/.local/lib/python3.7/site-packages/lightgbm
2021-03-26T14:05:08.7486610Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/callback.py to callback.cpython-37.pyc
2021-03-26T14:05:08.7487990Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/compat.py to compat.cpython-37.pyc
2021-03-26T14:05:08.7489270Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/plotting.py to plotting.cpython-37.pyc
2021-03-26T14:05:08.7490480Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/__init__.py to __init__.cpython-37.pyc
2021-03-26T14:05:08.7492090Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/engine.py to engine.cpython-37.pyc
2021-03-26T14:05:08.7493340Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py to dask.cpython-37.pyc
2021-03-26T14:05:08.7494590Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py to basic.cpython-37.pyc
2021-03-26T14:05:08.7562330Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/libpath.py to libpath.cpython-37.pyc
2021-03-26T14:05:08.7572950Z byte-compiling /Users/runner/.local/lib/python3.7/site-packages/lightgbm/sklearn.py to sklearn.cpython-37.pyc
2021-03-26T14:05:08.7619070Z running install_egg_info
2021-03-26T14:05:08.7649450Z Copying lightgbm.egg-info to /Users/runner/.local/lib/python3.7/site-packages/lightgbm-3.2.0.99-py3.7.egg-info
2021-03-26T14:05:08.7681110Z running install_scripts
2021-03-26T14:05:12.3799100Z ============================= test session starts ==============================
2021-03-26T14:05:12.3802720Z platform darwin -- Python 3.7.10, pytest-6.2.2, py-1.10.0, pluggy-0.13.1
2021-03-26T14:05:12.3803890Z rootdir: /Users/runner/work/1/s
2021-03-26T14:05:12.3805950Z collected 236 items / 1 skipped / 235 selected
2021-03-26T14:05:12.3807030Z 
2021-03-26T14:05:14.3397750Z ../tests/c_api_test/test_.py ..                                          [  0%]
2021-03-26T14:05:14.8324010Z ../tests/python_package_test/test_basic.py .........................     [ 11%]
2021-03-26T14:05:27.0417990Z ../tests/python_package_test/test_consistency.py ......                  [ 13%]
2021-03-26T14:05:27.0431920Z ../tests/python_package_test/test_dual.py s                              [ 14%]
2021-03-26T14:05:31.4597530Z ../tests/python_package_test/test_engine.py ............................ [ 26%]
2021-03-26T14:06:42.0056070Z .........................................                                [ 43%]
2021-03-26T14:06:46.7716300Z ../tests/python_package_test/test_plotting.py .....                      [ 45%]
2021-03-26T14:06:49.1691570Z ../tests/python_package_test/test_sklearn.py ........................... [ 57%]
2021-03-26T14:06:56.8664370Z ......x.............................................x................... [ 87%]
2021-03-26T14:06:58.2323190Z .......................ss...                                             [ 99%]
2021-03-26T14:06:58.2712150Z ../tests/python_package_test/test_utilities.py .                         [100%]
2021-03-26T14:06:58.2713530Z 
2021-03-26T14:06:58.2714660Z =============================== warnings summary ===============================
2021-03-26T14:06:58.2715450Z tests/python_package_test/test_basic.py::test_basic
2021-03-26T14:06:58.2716540Z tests/python_package_test/test_engine.py::test_reference_chain
2021-03-26T14:06:58.2717690Z tests/python_package_test/test_engine.py::test_init_with_subset
2021-03-26T14:06:58.2718340Z tests/python_package_test/test_engine.py::test_fpreproc
2021-03-26T14:06:58.2719150Z tests/python_package_test/test_engine.py::test_dataset_params_with_reference
2021-03-26T14:06:58.2720820Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1433: UserWarning: Overriding the parameters from Reference Dataset.
2021-03-26T14:06:58.2722110Z     _log_warning('Overriding the parameters from Reference Dataset.')
2021-03-26T14:06:58.2722500Z 
2021-03-26T14:06:58.2723070Z tests/python_package_test/test_basic.py::test_add_features_equal_data_on_alternating_used_unused
2021-03-26T14:06:58.2723800Z tests/python_package_test/test_basic.py::test_add_features_same_booster_behaviour
2021-03-26T14:06:58.2724430Z tests/python_package_test/test_engine.py::test_sliced_data
2021-03-26T14:06:58.2725010Z tests/python_package_test/test_engine.py::test_monotone_penalty_max
2021-03-26T14:06:58.2726790Z tests/python_package_test/test_engine.py::test_forced_bins
2021-03-26T14:06:58.2728210Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:448: UserWarning: Usage of np.ndarray subset (sliced data) is not recommended due to it will double the peak memory cost in LightGBM.
2021-03-26T14:06:58.2729880Z     _log_warning("Usage of np.ndarray subset (sliced data) is not recommended "
2021-03-26T14:06:58.2730310Z 
2021-03-26T14:06:58.2730870Z tests/python_package_test/test_basic.py::test_add_features_equal_data_on_alternating_used_unused
2021-03-26T14:06:58.2731580Z tests/python_package_test/test_basic.py::test_add_features_same_booster_behaviour
2021-03-26T14:06:58.2732280Z tests/python_package_test/test_basic.py::test_add_features_from_different_sources
2021-03-26T14:06:58.2733620Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:2129: UserWarning: Cannot add features from NoneType type of raw data to NoneType type of raw data.
2021-03-26T14:06:58.2734520Z   Set free_raw_data=False when construct Dataset to avoid this
2021-03-26T14:06:58.2735080Z     _log_warning(err_msg)
2021-03-26T14:06:58.2735360Z 
2021-03-26T14:06:58.2735920Z tests/python_package_test/test_basic.py::test_add_features_equal_data_on_alternating_used_unused
2021-03-26T14:06:58.2736630Z tests/python_package_test/test_basic.py::test_add_features_same_booster_behaviour
2021-03-26T14:06:58.2737330Z tests/python_package_test/test_basic.py::test_add_features_from_different_sources
2021-03-26T14:06:58.2738510Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:2131: UserWarning: Reseting categorical features.
2021-03-26T14:06:58.2739320Z   You can set new categorical features via ``set_categorical_feature`` method
2021-03-26T14:06:58.2740050Z     _log_warning("Reseting categorical features.\n"
2021-03-26T14:06:58.2740540Z 
2021-03-26T14:06:58.2741110Z tests/python_package_test/test_basic.py::test_add_features_from_different_sources
2021-03-26T14:06:58.2754520Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:2129: UserWarning: Cannot add features from list type of raw data to ndarray type of raw data.
2021-03-26T14:06:58.2755470Z   Freeing raw data
2021-03-26T14:06:58.2756090Z     _log_warning(err_msg)
2021-03-26T14:06:58.2757260Z 
2021-03-26T14:06:58.2757930Z tests/python_package_test/test_basic.py::test_add_features_from_different_sources
2021-03-26T14:06:58.2759820Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:2129: UserWarning: Cannot add features from list type of raw data to csr_matrix type of raw data.
2021-03-26T14:06:58.2760650Z   Freeing raw data
2021-03-26T14:06:58.2761120Z     _log_warning(err_msg)
2021-03-26T14:06:58.2761410Z 
2021-03-26T14:06:58.2761930Z tests/python_package_test/test_basic.py::test_add_features_from_different_sources
2021-03-26T14:06:58.2763250Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:2129: UserWarning: Cannot add features from list type of raw data to DataFrame type of raw data.
2021-03-26T14:06:58.2764050Z   Freeing raw data
2021-03-26T14:06:58.2764520Z     _log_warning(err_msg)
2021-03-26T14:06:58.2764810Z 
2021-03-26T14:06:58.2765250Z tests/python_package_test/test_consistency.py: 10 warnings
2021-03-26T14:06:58.2766410Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/engine.py:148: UserWarning: Found `num_trees` in params. Will use it instead of argument
2021-03-26T14:06:58.2767380Z     _log_warning("Found `{}` in params. Will use it instead of argument".format(alias))
2021-03-26T14:06:58.2767840Z 
2021-03-26T14:06:58.2768380Z tests/python_package_test/test_consistency.py: 10 warnings
2021-03-26T14:06:58.2769650Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1224: UserWarning: data keyword has been found in `params` and will be ignored.
2021-03-26T14:06:58.2770570Z   Please use data argument of the Dataset constructor to pass this parameter.
2021-03-26T14:06:58.2771190Z     .format(key))
2021-03-26T14:06:58.2771500Z 
2021-03-26T14:06:58.2772040Z tests/python_package_test/test_engine.py::test_binary
2021-03-26T14:06:58.2773290Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/engine.py:148: UserWarning: Found `num_iteration` in params. Will use it instead of argument
2021-03-26T14:06:58.2774640Z     _log_warning("Found `{}` in params. Will use it instead of argument".format(alias))
2021-03-26T14:06:58.2775110Z 
2021-03-26T14:06:58.2775660Z tests/python_package_test/test_engine.py::test_pandas_categorical
2021-03-26T14:06:58.2776350Z tests/python_package_test/test_engine.py::test_linear_trees
2021-03-26T14:06:58.2777030Z tests/python_package_test/test_engine.py::test_save_and_load_linear
2021-03-26T14:06:58.2778290Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:06:58.2779090Z   New categorical_feature is [0]
2021-03-26T14:06:58.2780110Z     'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:06:58.2780590Z 
2021-03-26T14:06:58.2781150Z tests/python_package_test/test_engine.py::test_pandas_categorical
2021-03-26T14:06:58.2782390Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:06:58.2783660Z   New categorical_feature is ['A']
2021-03-26T14:06:58.2784690Z     'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:06:58.2785260Z 
2021-03-26T14:06:58.2785820Z tests/python_package_test/test_engine.py::test_pandas_categorical
2021-03-26T14:06:58.2787040Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:06:58.2788210Z   New categorical_feature is ['A', 'B', 'C', 'D']
2021-03-26T14:06:58.2789280Z     'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:06:58.2789740Z 
2021-03-26T14:06:58.2790940Z tests/python_package_test/test_engine.py::test_pandas_categorical
2021-03-26T14:06:58.2792200Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:06:58.2793390Z   New categorical_feature is ['A', 'B', 'C', 'D', 'E']
2021-03-26T14:06:58.2794460Z     'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:06:58.2794930Z 
2021-03-26T14:06:58.2795490Z tests/python_package_test/test_engine.py::test_pandas_categorical
2021-03-26T14:06:58.2796730Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:06:58.2797520Z   New categorical_feature is []
2021-03-26T14:06:58.2798580Z     'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:06:58.2799050Z 
2021-03-26T14:06:58.2799720Z tests/python_package_test/test_engine.py::test_pandas_sparse
2021-03-26T14:06:58.2800410Z tests/python_package_test/test_sklearn.py::test_pandas_sparse
2021-03-26T14:06:58.2802000Z   /Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/pandas/core/generic.py:5673: PerformanceWarning: Concatenating sparse arrays with multiple fill values: '[0, nan, False]'. Picking the first and converting the rest.
2021-03-26T14:06:58.2803620Z     return self._mgr.as_array(transpose=self._AXIS_REVERSED)
2021-03-26T14:06:58.2804160Z 
2021-03-26T14:06:58.2804640Z tests/python_package_test/test_engine.py::test_int32_max_sparse_contribs
2021-03-26T14:06:58.2806150Z   /Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/scipy/sparse/_index.py:82: SparseEfficiencyWarning: Changing the sparsity structure of a csr_matrix is expensive. lil_matrix is more efficient.
2021-03-26T14:06:58.2807150Z     self._set_intXint(row, col, x.flat[0])
2021-03-26T14:06:58.2807580Z 
2021-03-26T14:06:58.2808140Z tests/python_package_test/test_engine.py::test_init_with_subset
2021-03-26T14:06:58.2809410Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1960: UserWarning: Cannot subset str type of raw data.
2021-03-26T14:06:58.2810240Z   Returning original raw data
2021-03-26T14:06:58.2811250Z     "Returning original raw data".format(type(self.data).__name__))
2021-03-26T14:06:58.2811720Z 
2021-03-26T14:06:58.2812330Z tests/python_package_test/test_engine.py::test_monotone_constraints
2021-03-26T14:06:58.2813020Z tests/python_package_test/test_engine.py::test_monotone_penalty
2021-03-26T14:06:58.2813720Z tests/python_package_test/test_engine.py::test_monotone_penalty_max
2021-03-26T14:06:58.2814460Z tests/python_package_test/test_engine.py::test_get_split_value_histogram
2021-03-26T14:06:58.2815220Z tests/python_package_test/test_sklearn.py::test_pandas_categorical
2021-03-26T14:06:58.2815910Z tests/python_package_test/test_sklearn.py::test_pandas_categorical
2021-03-26T14:06:58.2816660Z tests/python_package_test/test_sklearn.py::test_pandas_categorical
2021-03-26T14:06:58.2817420Z tests/python_package_test/test_sklearn.py::test_pandas_categorical
2021-03-26T14:06:58.2818160Z tests/python_package_test/test_sklearn.py::test_pandas_categorical
2021-03-26T14:06:58.2819470Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1702: UserWarning: Using categorical_feature in Dataset.
2021-03-26T14:06:58.2820710Z     _log_warning('Using categorical_feature in Dataset.')
2021-03-26T14:06:58.2821180Z 
2021-03-26T14:06:58.2821760Z tests/python_package_test/test_engine.py::test_dataset_update_params
2021-03-26T14:06:58.2823080Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1224: UserWarning: categorical_feature keyword has been found in `params` and will be ignored.
2021-03-26T14:06:58.2824050Z   Please use categorical_feature argument of the Dataset constructor to pass this parameter.
2021-03-26T14:06:58.2824700Z     .format(key))
2021-03-26T14:06:58.2825010Z 
2021-03-26T14:06:58.2825560Z tests/python_package_test/test_plotting.py::test_plot_metrics
2021-03-26T14:06:58.2827260Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/plotting.py:328: UserWarning: More than one metric available, picking one to plot.
2021-03-26T14:06:58.2828220Z     _log_warning("More than one metric available, picking one to plot.")
2021-03-26T14:06:58.2828670Z 
2021-03-26T14:06:58.2829280Z tests/python_package_test/test_sklearn.py::test_binary_classification_with_custom_objective
2021-03-26T14:06:58.2830700Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/sklearn.py:922: UserWarning: Cannot compute class probabilities or labels due to the usage of customized objective function.
2021-03-26T14:06:58.2831600Z   Returning raw scores instead.
2021-03-26T14:06:58.2832220Z     _log_warning("Cannot compute class probabilities or labels "
2021-03-26T14:06:58.2832610Z 
2021-03-26T14:06:58.2833160Z tests/python_package_test/test_sklearn.py: 12 warnings
2021-03-26T14:06:58.2834350Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:739: UserWarning: Converting data to scipy sparse matrix.
2021-03-26T14:06:58.2835520Z     _log_warning('Converting data to scipy sparse matrix.')
2021-03-26T14:06:58.2835960Z 
2021-03-26T14:06:58.2836520Z tests/python_package_test/test_utilities.py::test_register_logger
2021-03-26T14:06:58.2837930Z   /Users/runner/.local/lib/python3.7/site-packages/lightgbm/plotting.py:357: UserWarning: Attempting to set identical bottom == top == 1.0 results in singular transformations; automatically expanding.
2021-03-26T14:06:58.2838840Z     ax.set_ylim(ylim)
2021-03-26T14:06:58.2839160Z 
2021-03-26T14:06:58.2840060Z -- Docs: https://docs.pytest.org/en/stable/warnings.html
2021-03-26T14:06:58.2840840Z ====== 231 passed, 4 skipped, 2 xfailed, 76 warnings in 109.12s (0:01:49) ======
2021-03-26T14:07:00.9259080Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:07:00.9260190Z New categorical_feature is [21]
2021-03-26T14:07:00.9261170Z   'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:07:00.9262400Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1702: UserWarning: Using categorical_feature in Dataset.
2021-03-26T14:07:00.9264000Z   _log_warning('Using categorical_feature in Dataset.')
2021-03-26T14:07:00.9265220Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:07:00.9265970Z New categorical_feature is [21]
2021-03-26T14:07:00.9266910Z   'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:07:00.9268160Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1433: UserWarning: Overriding the parameters from Reference Dataset.
2021-03-26T14:07:00.9269340Z   _log_warning('Overriding the parameters from Reference Dataset.')
2021-03-26T14:07:00.9270560Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1245: UserWarning: categorical_column in param dict is overridden.
2021-03-26T14:07:00.9271730Z   _log_warning('{} in param dict is overridden.'.format(cat_alias))
2021-03-26T14:07:00.9272990Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1702: UserWarning: Using categorical_feature in Dataset.
2021-03-26T14:07:00.9274110Z   _log_warning('Using categorical_feature in Dataset.')
2021-03-26T14:07:00.9275330Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1433: UserWarning: Overriding the parameters from Reference Dataset.
2021-03-26T14:07:00.9276500Z   _log_warning('Overriding the parameters from Reference Dataset.')
2021-03-26T14:07:00.9277700Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1245: UserWarning: categorical_column in param dict is overridden.
2021-03-26T14:07:00.9278950Z   _log_warning('{} in param dict is overridden.'.format(cat_alias))
2021-03-26T14:07:00.9279550Z Loading data...
2021-03-26T14:07:00.9280000Z Starting training...
2021-03-26T14:07:00.9280990Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001074 seconds.
2021-03-26T14:07:00.9282300Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9283390Z [1]	training's binary_logloss: 0.682311
2021-03-26T14:07:00.9284370Z [2]	training's binary_logloss: 0.674204
2021-03-26T14:07:00.9285250Z [3]	training's binary_logloss: 0.664662
2021-03-26T14:07:00.9286190Z [4]	training's binary_logloss: 0.655524
2021-03-26T14:07:00.9287140Z [5]	training's binary_logloss: 0.648385
2021-03-26T14:07:00.9288070Z [6]	training's binary_logloss: 0.64227
2021-03-26T14:07:00.9288990Z [7]	training's binary_logloss: 0.63507
2021-03-26T14:07:00.9289930Z [8]	training's binary_logloss: 0.628378
2021-03-26T14:07:00.9291180Z [9]	training's binary_logloss: 0.621862
2021-03-26T14:07:00.9292110Z [10]	training's binary_logloss: 0.615907
2021-03-26T14:07:00.9292690Z Finished first 10 rounds...
2021-03-26T14:07:00.9293210Z 7th feature name is: feature_6
2021-03-26T14:07:00.9293690Z Saving model...
2021-03-26T14:07:00.9294130Z Dumping model to JSON...
2021-03-26T14:07:00.9295960Z Feature names: ['feature_0', 'feature_1', 'feature_2', 'feature_3', 'feature_4', 'feature_5', 'feature_6', 'feature_7', 'feature_8', 'feature_9', 'feature_10', 'feature_11', 'feature_12', 'feature_13', 'feature_14', 'feature_15', 'feature_16', 'feature_17', 'feature_18', 'feature_19', 'feature_20', 'feature_21', 'feature_22', 'feature_23', 'feature_24', 'feature_25', 'feature_26', 'feature_27']
2021-03-26T14:07:00.9297390Z Feature importances: [7, 1, 1, 21, 5, 30, 2, 1, 1, 18, 7, 0, 1, 8, 2, 1, 0, 7, 3, 3, 0, 0, 36, 5, 32, 52, 28, 28]
2021-03-26T14:07:00.9298060Z Loading model to predict...
2021-03-26T14:07:00.9299000Z The rmse of loaded model's prediction is: 0.4624446334710637
2021-03-26T14:07:00.9299640Z Dumping and loading model with pickle...
2021-03-26T14:07:00.9300570Z The rmse of pickled model's prediction is: 0.471743247991725
2021-03-26T14:07:00.9301720Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.000955 seconds.
2021-03-26T14:07:00.9302480Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9303360Z [11]	valid_0's binary_logloss: 0.615668
2021-03-26T14:07:00.9304620Z [12]	valid_0's binary_logloss: 0.61131
2021-03-26T14:07:00.9305570Z [13]	valid_0's binary_logloss: 0.607092
2021-03-26T14:07:00.9306520Z [14]	valid_0's binary_logloss: 0.603532
2021-03-26T14:07:00.9307460Z [15]	valid_0's binary_logloss: 0.600335
2021-03-26T14:07:00.9308450Z [16]	valid_0's binary_logloss: 0.596209
2021-03-26T14:07:00.9309560Z [17]	valid_0's binary_logloss: 0.592408
2021-03-26T14:07:00.9310590Z [18]	valid_0's binary_logloss: 0.588936
2021-03-26T14:07:00.9311530Z [19]	valid_0's binary_logloss: 0.585849
2021-03-26T14:07:00.9312490Z [20]	valid_0's binary_logloss: 0.582769
2021-03-26T14:07:00.9313430Z Finished 10 - 20 rounds with model file...
2021-03-26T14:07:00.9314570Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001076 seconds.
2021-03-26T14:07:00.9315300Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9316230Z [21]	valid_0's binary_logloss: 0.580061
2021-03-26T14:07:00.9317230Z [22]	valid_0's binary_logloss: 0.576959
2021-03-26T14:07:00.9318260Z [23]	valid_0's binary_logloss: 0.575347
2021-03-26T14:07:00.9319190Z [24]	valid_0's binary_logloss: 0.573232
2021-03-26T14:07:00.9320220Z [25]	valid_0's binary_logloss: 0.571052
2021-03-26T14:07:00.9321260Z [26]	valid_0's binary_logloss: 0.568534
2021-03-26T14:07:00.9322280Z [27]	valid_0's binary_logloss: 0.567642
2021-03-26T14:07:00.9323220Z [28]	valid_0's binary_logloss: 0.565333
2021-03-26T14:07:00.9324250Z [29]	valid_0's binary_logloss: 0.562915
2021-03-26T14:07:00.9325200Z [30]	valid_0's binary_logloss: 0.560932
2021-03-26T14:07:00.9326130Z Finished 20 - 30 rounds with decay learning rates...
2021-03-26T14:07:00.9327250Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.000996 seconds.
2021-03-26T14:07:00.9328440Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9329380Z [31]	valid_0's binary_logloss: 0.559653
2021-03-26T14:07:00.9330350Z [32]	valid_0's binary_logloss: 0.557064
2021-03-26T14:07:00.9331300Z [33]	valid_0's binary_logloss: 0.556072
2021-03-26T14:07:00.9332240Z [34]	valid_0's binary_logloss: 0.554828
2021-03-26T14:07:00.9333180Z [35]	valid_0's binary_logloss: 0.552499
2021-03-26T14:07:00.9334100Z [36]	valid_0's binary_logloss: 0.550979
2021-03-26T14:07:00.9335040Z [37]	valid_0's binary_logloss: 0.550261
2021-03-26T14:07:00.9335970Z [38]	valid_0's binary_logloss: 0.549716
2021-03-26T14:07:00.9336910Z [39]	valid_0's binary_logloss: 0.549701
2021-03-26T14:07:00.9337820Z [40]	valid_0's binary_logloss: 0.547916
2021-03-26T14:07:00.9338800Z Finished 30 - 40 rounds with changing bagging_fraction...
2021-03-26T14:07:00.9339790Z [LightGBM] [Warning] Using self-defined objective function
2021-03-26T14:07:00.9340890Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001393 seconds.
2021-03-26T14:07:00.9341630Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9342590Z [LightGBM] [Warning] Using self-defined objective function
2021-03-26T14:07:00.9343590Z [41]	valid_0's binary_logloss: 5.66637	valid_0's error: 0.266
2021-03-26T14:07:00.9344630Z [42]	valid_0's binary_logloss: 5.65626	valid_0's error: 0.266
2021-03-26T14:07:00.9345690Z [43]	valid_0's binary_logloss: 5.5941	valid_0's error: 0.266
2021-03-26T14:07:00.9346750Z [44]	valid_0's binary_logloss: 5.64484	valid_0's error: 0.266
2021-03-26T14:07:00.9347880Z [45]	valid_0's binary_logloss: 5.70959	valid_0's error: 0.266
2021-03-26T14:07:00.9348940Z [46]	valid_0's binary_logloss: 5.70899	valid_0's error: 0.266
2021-03-26T14:07:00.9350000Z [47]	valid_0's binary_logloss: 5.69902	valid_0's error: 0.266
2021-03-26T14:07:00.9351060Z [48]	valid_0's binary_logloss: 5.56464	valid_0's error: 0.26
2021-03-26T14:07:00.9352110Z [49]	valid_0's binary_logloss: 5.55423	valid_0's error: 0.26
2021-03-26T14:07:00.9353150Z [50]	valid_0's binary_logloss: 5.55071	valid_0's error: 0.26
2021-03-26T14:07:00.9354530Z Finished 40 - 50 rounds with self-defined objective function and eval metric...
2021-03-26T14:07:00.9356020Z [LightGBM] [Warning] Using self-defined objective function
2021-03-26T14:07:00.9357210Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001145 seconds.
2021-03-26T14:07:00.9357990Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9359090Z [LightGBM] [Warning] Using self-defined objective function
2021-03-26T14:07:00.9360320Z [51]	valid_0's binary_logloss: 5.60932	valid_0's error: 0.26	valid_0's accuracy: 0.74
2021-03-26T14:07:00.9361620Z [52]	valid_0's binary_logloss: 5.60455	valid_0's error: 0.26	valid_0's accuracy: 0.74
2021-03-26T14:07:00.9362840Z [53]	valid_0's binary_logloss: 5.60467	valid_0's error: 0.26	valid_0's accuracy: 0.74
2021-03-26T14:07:00.9364020Z [54]	valid_0's binary_logloss: 5.59937	valid_0's error: 0.254	valid_0's accuracy: 0.746
2021-03-26T14:07:00.9365230Z [55]	valid_0's binary_logloss: 5.60542	valid_0's error: 0.256	valid_0's accuracy: 0.744
2021-03-26T14:07:00.9366420Z [56]	valid_0's binary_logloss: 5.65317	valid_0's error: 0.256	valid_0's accuracy: 0.744
2021-03-26T14:07:00.9367630Z [57]	valid_0's binary_logloss: 5.70391	valid_0's error: 0.256	valid_0's accuracy: 0.744
2021-03-26T14:07:00.9368800Z [58]	valid_0's binary_logloss: 5.70311	valid_0's error: 0.26	valid_0's accuracy: 0.74
2021-03-26T14:07:00.9370000Z [59]	valid_0's binary_logloss: 5.63744	valid_0's error: 0.258	valid_0's accuracy: 0.742
2021-03-26T14:07:00.9371200Z [60]	valid_0's binary_logloss: 5.63782	valid_0's error: 0.262	valid_0's accuracy: 0.738
2021-03-26T14:07:00.9372390Z Finished 50 - 60 rounds with self-defined objective function and multiple self-defined eval metrics...
2021-03-26T14:07:00.9373050Z Starting a new training job...
2021-03-26T14:07:00.9374390Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.000983 seconds.
2021-03-26T14:07:00.9375670Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:00.9376580Z [1]	training's binary_logloss: 0.68406
2021-03-26T14:07:00.9377510Z [2]	training's binary_logloss: 0.675795
2021-03-26T14:07:00.9378450Z [3]	training's binary_logloss: 0.666132
2021-03-26T14:07:00.9379390Z [4]	training's binary_logloss: 0.656879
2021-03-26T14:07:00.9380320Z [5]	training's binary_logloss: 0.649644
2021-03-26T14:07:00.9380940Z Add a new valid dataset at iteration 5...
2021-03-26T14:07:00.9381950Z [6]	training's binary_logloss: 0.643427	new_valid's binary_logloss: 0.647428
2021-03-26T14:07:00.9383090Z [7]	training's binary_logloss: 0.636159	new_valid's binary_logloss: 0.640079
2021-03-26T14:07:00.9384220Z [8]	training's binary_logloss: 0.629416	new_valid's binary_logloss: 0.633583
2021-03-26T14:07:00.9385330Z [9]	training's binary_logloss: 0.62285	new_valid's binary_logloss: 0.627219
2021-03-26T14:07:00.9386620Z [10]	training's binary_logloss: 0.616906	new_valid's binary_logloss: 0.621691
2021-03-26T14:07:00.9387420Z Finished first 10 rounds with callback function...
2021-03-26T14:07:02.9333060Z Performance of `binary` objective with binary labels:
2021-03-26T14:07:02.9335080Z {'time': 0.00988006591796875, 'correlation': 0.6012584922759887, 'logloss': 0.15545640415178236}
2021-03-26T14:07:02.9335950Z Performance of `xentropy` objective with binary labels:
2021-03-26T14:07:02.9337130Z {'time': 0.00510096549987793, 'correlation': 0.6012584922759887, 'logloss': 0.15545640415178236}
2021-03-26T14:07:02.9337970Z Performance of `xentropy` objective with probability labels:
2021-03-26T14:07:02.9339700Z {'time': 0.007288217544555664, 'correlation': 0.8841891508165868, 'logloss': 0.1551448517607808}
2021-03-26T14:07:02.9340580Z Best `binary` time: 0.004233837127685547
2021-03-26T14:07:02.9341210Z Best `xentropy` time: 0.0042498111724853516
2021-03-26T14:07:06.4941590Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1706: UserWarning: categorical_feature in Dataset is overridden.
2021-03-26T14:07:06.4942980Z New categorical_feature is [21]
2021-03-26T14:07:06.4944250Z   'New categorical_feature is {}'.format(sorted(list(categorical_feature))))
2021-03-26T14:07:06.4949850Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1433: UserWarning: Overriding the parameters from Reference Dataset.
2021-03-26T14:07:06.4951370Z   _log_warning('Overriding the parameters from Reference Dataset.')
2021-03-26T14:07:06.4952930Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py:1245: UserWarning: categorical_column in param dict is overridden.
2021-03-26T14:07:06.4954330Z   _log_warning('{} in param dict is overridden.'.format(cat_alias))
2021-03-26T14:07:06.4955770Z plot_example.py:49: UserWarning: Matplotlib is currently using agg, which is a non-GUI backend, so cannot show the figure.
2021-03-26T14:07:06.4956770Z   plt.show()
2021-03-26T14:07:06.4958060Z plot_example.py:53: UserWarning: Matplotlib is currently using agg, which is a non-GUI backend, so cannot show the figure.
2021-03-26T14:07:06.4959020Z   plt.show()
2021-03-26T14:07:06.4961320Z plot_example.py:57: UserWarning: Matplotlib is currently using agg, which is a non-GUI backend, so cannot show the figure.
2021-03-26T14:07:06.4962180Z   plt.show()
2021-03-26T14:07:06.4969910Z plot_example.py:61: UserWarning: Matplotlib is currently using agg, which is a non-GUI backend, so cannot show the figure.
2021-03-26T14:07:06.4970990Z   plt.show()
2021-03-26T14:07:06.4972720Z Loading data...
2021-03-26T14:07:06.4974570Z Starting training...
2021-03-26T14:07:06.4977350Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001251 seconds.
2021-03-26T14:07:06.4979200Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:06.4981270Z [10]	training's l1: 0.457448	training's l2: 0.217995	valid_1's l1: 0.456464	valid_1's l2: 0.21641
2021-03-26T14:07:06.4983260Z [20]	training's l1: 0.436869	training's l2: 0.205099	valid_1's l1: 0.434057	valid_1's l2: 0.201616
2021-03-26T14:07:06.4985290Z [30]	training's l1: 0.421302	training's l2: 0.197421	valid_1's l1: 0.417019	valid_1's l2: 0.192514
2021-03-26T14:07:06.4988500Z [40]	training's l1: 0.411107	training's l2: 0.192856	valid_1's l1: 0.406303	valid_1's l2: 0.187258
2021-03-26T14:07:06.4990300Z [50]	training's l1: 0.403695	training's l2: 0.189593	valid_1's l1: 0.398997	valid_1's l2: 0.183688
2021-03-26T14:07:06.4992050Z [60]	training's l1: 0.398704	training's l2: 0.187043	valid_1's l1: 0.393977	valid_1's l2: 0.181009
2021-03-26T14:07:06.4993790Z [70]	training's l1: 0.394876	training's l2: 0.184982	valid_1's l1: 0.389805	valid_1's l2: 0.178803
2021-03-26T14:07:06.4995510Z [80]	training's l1: 0.391147	training's l2: 0.1828	valid_1's l1: 0.386476	valid_1's l2: 0.176799
2021-03-26T14:07:06.4997290Z [90]	training's l1: 0.388101	training's l2: 0.180817	valid_1's l1: 0.384404	valid_1's l2: 0.175775
2021-03-26T14:07:06.5000580Z [100]	training's l1: 0.385174	training's l2: 0.179171	valid_1's l1: 0.382929	valid_1's l2: 0.175321
2021-03-26T14:07:06.5001730Z Plotting metrics recorded during training...
2021-03-26T14:07:06.5003020Z Plotting feature importances...
2021-03-26T14:07:06.5003930Z Plotting split value histogram...
2021-03-26T14:07:06.5005260Z Plotting 54th tree...
2021-03-26T14:07:06.5006190Z Plotting 54th tree with graphviz...
2021-03-26T14:07:08.5541140Z Loading data...
2021-03-26T14:07:08.5542670Z Starting training...
2021-03-26T14:07:08.5545390Z [LightGBM] [Warning] Auto-choosing col-wise multi-threading, the overhead of testing was 0.001189 seconds.
2021-03-26T14:07:08.5546380Z You can set `force_col_wise=true` to remove the overhead.
2021-03-26T14:07:08.5547530Z [1]	valid_0's l2: 0.244076	valid_0's l1: 0.493018
2021-03-26T14:07:08.5548530Z Training until validation scores don't improve for 5 rounds
2021-03-26T14:07:08.5549790Z [2]	valid_0's l2: 0.240297	valid_0's l1: 0.489056
2021-03-26T14:07:08.5550890Z [3]	valid_0's l2: 0.235733	valid_0's l1: 0.484089
2021-03-26T14:07:08.5551920Z [4]	valid_0's l2: 0.231352	valid_0's l1: 0.479088
2021-03-26T14:07:08.5553390Z [5]	valid_0's l2: 0.228939	valid_0's l1: 0.476159
2021-03-26T14:07:08.5554460Z [6]	valid_0's l2: 0.22593	valid_0's l1: 0.472664
2021-03-26T14:07:08.5555920Z [7]	valid_0's l2: 0.222515	valid_0's l1: 0.468425
2021-03-26T14:07:08.5556980Z [8]	valid_0's l2: 0.219569	valid_0's l1: 0.464594
2021-03-26T14:07:08.5557960Z [9]	valid_0's l2: 0.2168	valid_0's l1: 0.460795
2021-03-26T14:07:08.5558970Z [10]	valid_0's l2: 0.214371	valid_0's l1: 0.457276
2021-03-26T14:07:08.5559970Z [11]	valid_0's l2: 0.211988	valid_0's l1: 0.453923
2021-03-26T14:07:08.5560960Z [12]	valid_0's l2: 0.210264	valid_0's l1: 0.451235
2021-03-26T14:07:08.5561970Z [13]	valid_0's l2: 0.208926	valid_0's l1: 0.448992
2021-03-26T14:07:08.5562980Z [14]	valid_0's l2: 0.207403	valid_0's l1: 0.44634
2021-03-26T14:07:08.5563930Z [15]	valid_0's l2: 0.20601	valid_0's l1: 0.444016
2021-03-26T14:07:08.5564910Z [16]	valid_0's l2: 0.204447	valid_0's l1: 0.441362
2021-03-26T14:07:08.5565910Z [17]	valid_0's l2: 0.202712	valid_0's l1: 0.43891
2021-03-26T14:07:08.5566900Z [18]	valid_0's l2: 0.201066	valid_0's l1: 0.436192
2021-03-26T14:07:08.5567880Z [19]	valid_0's l2: 0.1998	valid_0's l1: 0.433884
2021-03-26T14:07:08.5568860Z [20]	valid_0's l2: 0.198063	valid_0's l1: 0.431129
2021-03-26T14:07:08.5569510Z Did not meet early stopping. Best iteration is:
2021-03-26T14:07:08.5570480Z [20]	valid_0's l2: 0.198063	valid_0's l1: 0.431129
2021-03-26T14:07:08.5571040Z Saving model...
2021-03-26T14:07:08.5571440Z Starting predicting...
2021-03-26T14:07:08.5571960Z The rmse of prediction is: 0.4450426449744025
2021-03-26T14:07:12.2306820Z Loading data...
2021-03-26T14:07:12.2307730Z Starting training...
2021-03-26T14:07:12.2309270Z [1]	valid_0's l1: 0.491735	valid_0's l2: 0.242763
2021-03-26T14:07:12.2310420Z Training until validation scores don't improve for 5 rounds
2021-03-26T14:07:12.2311410Z [2]	valid_0's l1: 0.486563	valid_0's l2: 0.237895
2021-03-26T14:07:12.2312500Z [3]	valid_0's l1: 0.481489	valid_0's l2: 0.233277
2021-03-26T14:07:12.2314250Z [4]	valid_0's l1: 0.476848	valid_0's l2: 0.22925
2021-03-26T14:07:12.2315250Z [5]	valid_0's l1: 0.47305	valid_0's l2: 0.226155
2021-03-26T14:07:12.2316220Z [6]	valid_0's l1: 0.469049	valid_0's l2: 0.222963
2021-03-26T14:07:12.2317220Z [7]	valid_0's l1: 0.465556	valid_0's l2: 0.220364
2021-03-26T14:07:12.2318210Z [8]	valid_0's l1: 0.462208	valid_0's l2: 0.217872
2021-03-26T14:07:12.2319190Z [9]	valid_0's l1: 0.458676	valid_0's l2: 0.215328
2021-03-26T14:07:12.2320160Z [10]	valid_0's l1: 0.454998	valid_0's l2: 0.212743
2021-03-26T14:07:12.2321200Z [11]	valid_0's l1: 0.452047	valid_0's l2: 0.210805
2021-03-26T14:07:12.2322190Z [12]	valid_0's l1: 0.449158	valid_0's l2: 0.208945
2021-03-26T14:07:12.2323170Z [13]	valid_0's l1: 0.44608	valid_0's l2: 0.206986
2021-03-26T14:07:12.2324150Z [14]	valid_0's l1: 0.443554	valid_0's l2: 0.205513
2021-03-26T14:07:12.2325140Z [15]	valid_0's l1: 0.440643	valid_0's l2: 0.203728
2021-03-26T14:07:12.2326130Z [16]	valid_0's l1: 0.437687	valid_0's l2: 0.201865
2021-03-26T14:07:12.2327100Z [17]	valid_0's l1: 0.435454	valid_0's l2: 0.200639
2021-03-26T14:07:12.2328100Z [18]	valid_0's l1: 0.433288	valid_0's l2: 0.199522
2021-03-26T14:07:12.2329090Z [19]	valid_0's l1: 0.431297	valid_0's l2: 0.198552
2021-03-26T14:07:12.2330220Z [20]	valid_0's l1: 0.428946	valid_0's l2: 0.197238
2021-03-26T14:07:12.2330860Z Did not meet early stopping. Best iteration is:
2021-03-26T14:07:12.2331920Z [20]	valid_0's l1: 0.428946	valid_0's l2: 0.197238
2021-03-26T14:07:12.2332590Z Starting predicting...
2021-03-26T14:07:12.2333190Z The rmse of prediction is: 0.4441153344254208
2021-03-26T14:07:12.2334030Z Feature importances: [23, 7, 0, 33, 5, 56, 9, 1, 1, 21, 2, 5, 1, 19, 9, 6, 1, 10, 4, 10, 0, 31, 61, 4, 48, 102, 52, 79]
2021-03-26T14:07:12.2334740Z Starting training with custom eval function...
2021-03-26T14:07:12.2335980Z [1]	valid_0's l2: 0.242763	valid_0's RMSLE: 0.344957
2021-03-26T14:07:12.2336990Z Training until validation scores don't improve for 5 rounds
2021-03-26T14:07:12.2337990Z [2]	valid_0's l2: 0.237895	valid_0's RMSLE: 0.341693
2021-03-26T14:07:12.2338970Z [3]	valid_0's l2: 0.233277	valid_0's RMSLE: 0.338462
2021-03-26T14:07:12.2339970Z [4]	valid_0's l2: 0.22925	valid_0's RMSLE: 0.335656
2021-03-26T14:07:12.2341440Z [5]	valid_0's l2: 0.226155	valid_0's RMSLE: 0.333431
2021-03-26T14:07:12.2342450Z [6]	valid_0's l2: 0.222963	valid_0's RMSLE: 0.331104
2021-03-26T14:07:12.2343440Z [7]	valid_0's l2: 0.220364	valid_0's RMSLE: 0.329193
2021-03-26T14:07:12.2344430Z [8]	valid_0's l2: 0.217872	valid_0's RMSLE: 0.327337
2021-03-26T14:07:12.2345440Z [9]	valid_0's l2: 0.215328	valid_0's RMSLE: 0.325433
2021-03-26T14:07:12.2346420Z [10]	valid_0's l2: 0.212743	valid_0's RMSLE: 0.323523
2021-03-26T14:07:12.2347440Z [11]	valid_0's l2: 0.210805	valid_0's RMSLE: 0.321986
2021-03-26T14:07:12.2348450Z [12]	valid_0's l2: 0.208945	valid_0's RMSLE: 0.320523
2021-03-26T14:07:12.2349460Z [13]	valid_0's l2: 0.206986	valid_0's RMSLE: 0.319027
2021-03-26T14:07:12.2350440Z [14]	valid_0's l2: 0.205513	valid_0's RMSLE: 0.317796
2021-03-26T14:07:12.2351450Z [15]	valid_0's l2: 0.203728	valid_0's RMSLE: 0.316383
2021-03-26T14:07:12.2352450Z [16]	valid_0's l2: 0.201865	valid_0's RMSLE: 0.314827
2021-03-26T14:07:12.2353470Z [17]	valid_0's l2: 0.200639	valid_0's RMSLE: 0.313876
2021-03-26T14:07:12.2354740Z [18]	valid_0's l2: 0.199522	valid_0's RMSLE: 0.312948
2021-03-26T14:07:12.2355810Z [19]	valid_0's l2: 0.198552	valid_0's RMSLE: 0.312116
2021-03-26T14:07:12.2356810Z [20]	valid_0's l2: 0.197238	valid_0's RMSLE: 0.311032
2021-03-26T14:07:12.2357470Z Did not meet early stopping. Best iteration is:
2021-03-26T14:07:12.2358410Z [20]	valid_0's l2: 0.197238	valid_0's RMSLE: 0.311032
2021-03-26T14:07:12.2359160Z Starting training with multiple custom eval functions...
2021-03-26T14:07:12.2360280Z [1]	valid_0's l2: 0.242763	valid_0's RMSLE: 0.344957	valid_0's RAE: 0.991146
2021-03-26T14:07:12.2361390Z Training until validation scores don't improve for 5 rounds
2021-03-26T14:07:12.2383510Z [2]	valid_0's l2: 0.237895	valid_0's RMSLE: 0.341693	valid_0's RAE: 0.98072
2021-03-26T14:07:12.2384710Z [3]	valid_0's l2: 0.233277	valid_0's RMSLE: 0.338462	valid_0's RAE: 0.970493
2021-03-26T14:07:12.2385920Z [4]	valid_0's l2: 0.22925	valid_0's RMSLE: 0.335656	valid_0's RAE: 0.961139
2021-03-26T14:07:12.2387070Z [5]	valid_0's l2: 0.226155	valid_0's RMSLE: 0.333431	valid_0's RAE: 0.953484
2021-03-26T14:07:12.2388210Z [6]	valid_0's l2: 0.222963	valid_0's RMSLE: 0.331104	valid_0's RAE: 0.945419
2021-03-26T14:07:12.2389350Z [7]	valid_0's l2: 0.220364	valid_0's RMSLE: 0.329193	valid_0's RAE: 0.938379
2021-03-26T14:07:12.2390470Z [8]	valid_0's l2: 0.217872	valid_0's RMSLE: 0.327337	valid_0's RAE: 0.931632
2021-03-26T14:07:12.2391590Z [9]	valid_0's l2: 0.215328	valid_0's RMSLE: 0.325433	valid_0's RAE: 0.92451
2021-03-26T14:07:12.2392800Z [10]	valid_0's l2: 0.212743	valid_0's RMSLE: 0.323523	valid_0's RAE: 0.917099
2021-03-26T14:07:12.2393950Z [11]	valid_0's l2: 0.210805	valid_0's RMSLE: 0.321986	valid_0's RAE: 0.911151
2021-03-26T14:07:12.2395100Z [12]	valid_0's l2: 0.208945	valid_0's RMSLE: 0.320523	valid_0's RAE: 0.905328
2021-03-26T14:07:12.2396210Z [13]	valid_0's l2: 0.206986	valid_0's RMSLE: 0.319027	valid_0's RAE: 0.899123
2021-03-26T14:07:12.2397330Z [14]	valid_0's l2: 0.205513	valid_0's RMSLE: 0.317796	valid_0's RAE: 0.894031
2021-03-26T14:07:12.2398470Z [15]	valid_0's l2: 0.203728	valid_0's RMSLE: 0.316383	valid_0's RAE: 0.888164
2021-03-26T14:07:12.2399600Z [16]	valid_0's l2: 0.201865	valid_0's RMSLE: 0.314827	valid_0's RAE: 0.882206
2021-03-26T14:07:12.2400740Z [17]	valid_0's l2: 0.200639	valid_0's RMSLE: 0.313876	valid_0's RAE: 0.877704
2021-03-26T14:07:12.2401870Z [18]	valid_0's l2: 0.199522	valid_0's RMSLE: 0.312948	valid_0's RAE: 0.87334
2021-03-26T14:07:12.2402990Z [19]	valid_0's l2: 0.198552	valid_0's RMSLE: 0.312116	valid_0's RAE: 0.869327
2021-03-26T14:07:12.2404200Z [20]	valid_0's l2: 0.197238	valid_0's RMSLE: 0.311032	valid_0's RAE: 0.864588
2021-03-26T14:07:12.2404930Z Did not meet early stopping. Best iteration is:
2021-03-26T14:07:12.2405970Z [20]	valid_0's l2: 0.197238	valid_0's RMSLE: 0.311032	valid_0's RAE: 0.864588
2021-03-26T14:07:12.2406680Z Starting predicting...
2021-03-26T14:07:12.2407220Z The rmsle of prediction is: 0.3110323289863277
2021-03-26T14:07:12.2408520Z The rae of prediction is: 0.8645881044669875
2021-03-26T14:07:12.2409580Z Best parameters found by grid search are: {'learning_rate': 0.1, 'n_estimators': 40}
2021-03-26T14:07:14.6151350Z loading data
2021-03-26T14:07:14.6153190Z initializing a Dask cluster
2021-03-26T14:07:16.9338520Z [LightGBM] [Info] Trying to bind port 49593...
2021-03-26T14:07:16.9361050Z [LightGBM] [Info] Binding port 49593 succeeded
2021-03-26T14:07:16.9362420Z [LightGBM] [Info] Listening...
2021-03-26T14:07:16.9363600Z [LightGBM] [Info] Trying to bind port 49591...
2021-03-26T14:07:16.9364670Z [LightGBM] [Info] Binding port 49591 succeeded
2021-03-26T14:07:16.9365280Z [LightGBM] [Info] Trying to bind port 49592...
2021-03-26T14:07:16.9365900Z [LightGBM] [Info] Binding port 49592 succeeded
2021-03-26T14:07:16.9366440Z [LightGBM] [Info] Listening...
2021-03-26T14:07:16.9366990Z [LightGBM] [Info] Listening...
2021-03-26T14:07:16.9367490Z [LightGBM] [Info] Connected to rank 1
2021-03-26T14:07:16.9367980Z [LightGBM] [Info] Connected to rank 2
2021-03-26T14:07:16.9368450Z [LightGBM] [Info] Connected to rank 0
2021-03-26T14:07:16.9368900Z [LightGBM] [Info] Connected to rank 2
2021-03-26T14:07:16.9369370Z [LightGBM] [Info] Connected to rank 0
2021-03-26T14:07:16.9369840Z [LightGBM] [Info] Connected to rank 1
2021-03-26T14:07:16.9370370Z [LightGBM] [Info] Local rank: 0, total number of machines: 3
2021-03-26T14:07:16.9370960Z [LightGBM] [Info] Local rank: 1, total number of machines: 3
2021-03-26T14:07:16.9371560Z [LightGBM] [Info] Local rank: 2, total number of machines: 3
2021-03-26T14:07:16.9373270Z [LightGBM] [Warning] num_threads is set=1, n_jobs=-1 will be ignored. Current value: num_threads=1
2021-03-26T14:07:16.9374930Z [LightGBM] [Warning] num_threads is set=1, n_jobs=-1 will be ignored. Current value: num_threads=1
2021-03-26T14:07:16.9376810Z [LightGBM] [Warning] num_threads is set=1, n_jobs=-1 will be ignored. Current value: num_threads=1
2021-03-26T14:07:16.9754260Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py:285: UserWarning: Parameter n_jobs will be ignored.
2021-03-26T14:07:16.9755390Z   _log_warning(f"Parameter {param_alias} will be ignored.")
2021-03-26T14:07:16.9755970Z created a Dask LocalCluster
2021-03-26T14:07:16.9756500Z distributing training data on the Dask cluster
2021-03-26T14:07:16.9756990Z beginning training
2021-03-26T14:07:16.9757490Z Finding random open ports for workers
2021-03-26T14:07:16.9757960Z done training
2021-03-26T14:07:21.6593410Z loading data
2021-03-26T14:07:21.6595360Z initializing a Dask cluster
2021-03-26T14:07:23.7478020Z [LightGBM] [Info] Trying to bind port 49628...
2021-03-26T14:07:23.7479100Z [LightGBM] [Info] Binding port 49628 succeeded
2021-03-26T14:07:23.7479680Z [LightGBM] [Info] Listening...
2021-03-26T14:07:23.7495560Z [LightGBM] [Info] Trying to bind port 49627...
2021-03-26T14:07:23.7503360Z [LightGBM] [Info] Binding port 49627 succeeded
2021-03-26T14:07:23.7504590Z [LightGBM] [Info] Listening...
2021-03-26T14:07:23.7505630Z [LightGBM] [Info] Connected to rank 1
2021-03-26T14:07:23.7507440Z [LightGBM] [Info] Connected to rank 0
2021-03-26T14:07:23.7508630Z [LightGBM] [Info] Local rank: 1, total number of machines: 2
2021-03-26T14:07:23.7510570Z [LightGBM] [Info] Local rank: 0, total number of machines: 2
2021-03-26T14:07:23.7512940Z [LightGBM] [Warning] num_threads is set=2, n_jobs=-1 will be ignored. Current value: num_threads=2
2021-03-26T14:07:23.7514740Z [LightGBM] [Warning] num_threads is set=2, n_jobs=-1 will be ignored. Current value: num_threads=2
2021-03-26T14:07:23.8185090Z [LightGBM] [Fatal] Socket recv error, code: 54
2021-03-26T14:07:23.8255810Z /Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py:285: UserWarning: Parameter n_jobs will be ignored.
2021-03-26T14:07:23.8260710Z   _log_warning(f"Parameter {param_alias} will be ignored.")
2021-03-26T14:07:23.8270610Z distributed.nanny - WARNING - Restarting worker
2021-03-26T14:07:23.8273750Z created a Dask LocalCluster
2021-03-26T14:07:23.8275320Z distributing training data on the Dask cluster
2021-03-26T14:07:23.8277200Z beginning training
2021-03-26T14:07:23.8278310Z Finding random open ports for workers
2021-03-26T14:07:23.8297320Z distributed.worker - WARNING -  Compute Failed
2021-03-26T14:07:23.8302670Z Function:  _train_part
2021-03-26T14:07:23.8419590Z args:      ()
2021-03-26T14:07:23.8524840Z kwargs:    {'model_factory': <class 'lightgbm.sklearn.LGBMClassifier'>, 'params': {'boosting_type': 'gbdt', 'class_weight': None, 'colsample_bytree': 1.0, 'importance_type': 'split', 'learning_rate': 0.1, 'max_depth': -1, 'min_child_samples': 20, 'min_child_weight': 0.001, 'min_split_gain': 0.0, 'n_estimators': 10, 'num_leaves': 31, 'objective': None, 'random_state': None, 'reg_alpha': 0.0, 'reg_lambda': 0.0, 'silent': True, 'subsample': 1.0, 'subsample_for_bin': 200000, 'subsample_freq': 0, 'tree_learner': 'data', 'num_threads': 2, 'machines': '127.0.0.1:49627,127.0.0.1:49628', 'local_listen_port': 49627, 'time_out': 120, 'num_machines': 2}, 'list_of_parts': [{'data': array([[ -3.97108639,  -0.33676425,   7.00929092, ...,  -6.10549676,
2021-03-26T14:07:23.8528320Z           6.06043819, -10.69787404],
2021-03-26T14:07:23.8580300Z        [ -3.33161242,  -0.16417579,   8.78509788, ...,  -5.14702257,
2021-03-26T14:07:23.8583470Z           5.82124574,  -7.95230283],
2021-03-26T14:07:23.8585220Z        [ -6.8555776 ,   5.43201176,   5.66714544, ...,  -2.5101358 ,
2021-03-26T14:07:23.8586490Z           9.82746716,   4.16581462],
2021-03-26T14:07:23.8588770Z        ...,
2021-03-26T14:07:23.8589850Z    
2021-03-26T14:07:23.8591430Z Exception: LightGBMError('Socket recv error, code: 54')
2021-03-26T14:07:23.8591930Z 
2021-03-26T14:07:23.8592430Z [LightGBM] [Info] Trying to bind port 49628...
2021-03-26T14:07:23.8592980Z [LightGBM] [Info] Binding port 49628 succeeded
2021-03-26T14:07:23.8593880Z [LightGBM] [Info] Listening...
2021-03-26T14:07:29.0216560Z Traceback (most recent call last):
2021-03-26T14:07:29.0225170Z   File "dask/multiclass-classification.py", line 27, in <module>
2021-03-26T14:07:29.0226310Z     dask_model.fit(dX, dy)
2021-03-26T14:07:29.0227550Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py", line 689, in fit
2021-03-26T14:07:29.0228330Z     **kwargs
2021-03-26T14:07:29.0231580Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py", line 579, in _lgb_dask_fit
2021-03-26T14:07:29.0232280Z     **kwargs
2021-03-26T14:07:29.0233570Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py", line 399, in _train
2021-03-26T14:07:29.0234290Z     results = client.gather(futures_classifiers)
2021-03-26T14:07:29.0235680Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/distributed/client.py", line 1969, in gather
2021-03-26T14:07:29.0236460Z     asynchronous=asynchronous,
2021-03-26T14:07:29.0237530Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/distributed/client.py", line 838, in sync
2021-03-26T14:07:29.0238410Z     self.loop, func, *args, callback_timeout=callback_timeout, **kwargs
2021-03-26T14:07:29.0240110Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/distributed/utils.py", line 351, in sync
2021-03-26T14:07:29.0240940Z     raise exc.with_traceback(tb)
2021-03-26T14:07:29.0242620Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/distributed/utils.py", line 334, in f
2021-03-26T14:07:29.0243390Z     result[0] = yield future
2021-03-26T14:07:29.0244470Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/tornado/gen.py", line 762, in run
2021-03-26T14:07:29.0246180Z     value = future.result()
2021-03-26T14:07:29.0247340Z   File "/Users/runner/runners/2.183.1/miniconda/envs/test-env/lib/python3.7/site-packages/distributed/client.py", line 1828, in _gather
2021-03-26T14:07:29.0248090Z     raise exception.with_traceback(traceback)
2021-03-26T14:07:29.0249090Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/dask.py", line 118, in _train_part
2021-03-26T14:07:29.0250160Z     model.fit(data, label, sample_weight=weight, init_score=init_score, **kwargs)
2021-03-26T14:07:29.0251280Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/sklearn.py", line 895, in fit
2021-03-26T14:07:29.0251990Z     callbacks=callbacks, init_model=init_model)
2021-03-26T14:07:29.0253020Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/sklearn.py", line 688, in fit
2021-03-26T14:07:29.0253660Z     callbacks=callbacks, init_model=init_model)
2021-03-26T14:07:29.0254640Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/engine.py", line 249, in train
2021-03-26T14:07:29.0255260Z     booster.update(fobj=fobj)
2021-03-26T14:07:29.0256210Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py", line 2645, in update
2021-03-26T14:07:29.0256880Z     ctypes.byref(is_finished)))
2021-03-26T14:07:29.0257890Z   File "/Users/runner/.local/lib/python3.7/site-packages/lightgbm/basic.py", line 110, in _safe_call
2021-03-26T14:07:29.0258990Z     raise LightGBMError(_LIB.LGBM_GetLastError().decode('utf-8'))
2021-03-26T14:07:29.0259680Z lightgbm.basic.LightGBMError: Socket recv error, code: 54
2021-03-26T14:07:29.2720230Z ##[error]Bash exited with code '255'.
2021-03-26T14:07:29.2742390Z ##[section]Finishing: Test
@StrikerRUS
Copy link
Collaborator Author

Linking #3782 (comment) and #4064 (comment).

@jameslamb
Copy link
Collaborator

It has been about a month since we merged #4132, and since then I haven't seen this error in tests. Have you, @StrikerRUS ?

If not, I think this can be closed.

@StrikerRUS
Copy link
Collaborator Author

Yeah, seems that #4132 was great bug fix!

@orcahmlee
Copy link

Hi, I'm newbie of Dask.
I ran this regression example on Jupyter Lab on macOS(Big Sur 11.5.2), then I hit the error LightGBMError: Socket recv error, code: 54. But this error didn't rasied regularly, seems randomly.

Scenario 1: Jupyter Lab on macOS

Here is packages version.

# conda list
python                    3.8.10          h0e5c897_0_cpython    conda-forge
dask                      2021.9.0           pyhd8ed1ab_0    conda-forge
dask-core                 2021.9.0           pyhd8ed1ab_0    conda-forge
distributed               2021.9.0         py38h50d1736_0    conda-forge
lightgbm                  3.2.1            py38ha048514_0    conda-forge

When I ran the example code on jupyter lab as following, everythin went well in the beginning.

import dask.array as da
from distributed import Client, LocalCluster
from sklearn.datasets import make_regression

import lightgbm as lgb


cluster = LocalCluster(n_workers=2, dashboard_address=':9797')
client = Client(cluster)

X, y = make_regression(n_samples=7000, n_features=50)
dX = da.from_array(X, chunks=(100, 50))
dy = da.from_array(y, chunks=(100,))

print("beginning training")

dask_model = lgb.DaskLGBMRegressor(n_estimators=10)
dask_model.fit(dX, dy)
assert dask_model.fitted_

print("done training")

But when I start changing the n_estimators to 100, 1000, 10000, 1000000 in the same jupyter session, the error LightGBMError: Socket recv error, code: 54 would raised randomly.

This error would be raised when n_estimators=1000, sometime would be n_estimators=10000, sometime even raised when n_estimators=100, it's kind of weird. Also, the memory % was never higher than 10% on each worker. The full error log as following:

Finding random open ports for workers
[LightGBM] [Info] Listening...
[LightGBM] [Info] Trying to bind port 51608...
[LightGBM] [Info] Binding port 51608 succeeded
[LightGBM] [Info] Listening...

[LightGBM] [Fatal] Socket recv error, code: 54
distributed.nanny - WARNING - Restarting worker

[LightGBM] [Info] Connected to rank 0
[LightGBM] [Info] Local rank: 1, total number of machines: 2
[LightGBM] [Warning] num_threads is set=4, n_jobs=-1 will be ignored. Current value: num_threads=4

distributed.worker - WARNING - Compute Failed
Function:  _train_part
args:      ()
kwargs:    {'model_factory': <class 'lightgbm.sklearn.LGBMRegressor'>, 'params': {'boosting_type': 'gbdt', 'class_weight': None, 'colsample_bytree': 1.0, 'importance_type': 'split', 'learning_rate': 0.1, 'max_depth': -1, 'min_child_samples': 20, 'min_child_weight': 0.001, 'min_split_gain': 0.0, 'n_estimators': 10000, 'num_leaves': 31, 'objective': None, 'random_state': None, 'reg_alpha': 0.0, 'reg_lambda': 0.0, 'silent': True, 'subsample': 1.0, 'subsample_for_bin': 200000, 'subsample_freq': 0, 'tree_learner': 'data', 'num_threads': 4, 'machines': '192.168.16.136:51606,192.168.16.136:51608', 'local_listen_port': 51606, 'time_out': 120, 'num_machines': 2}, 'list_of_parts': [{'data': array([[ 0.78009344,  1.54505727, -0.09284188, ...,  0.25296354,
        -0.51492386, -0.8339314 ],
       [-0.70814669, -1.26873321,  1.16311847, ..., -0.73389737,
         0.0318654 ,  0.40117427],
       [ 0.19502484,  0.46833338,  0.64913442, ...,  0.3898734 ,
         0.03733873,  0.43668199],
       ...,
       [-
Exception: LightGBMError('Socket recv error, code: 54')

---------------------------------------------------------------------------
LightGBMError                             Traceback (most recent call last)
/var/folders/vv/s18mz7fj3pg2t9y0rvg_s6dw0000gq/T/ipykernel_93644/2905138063.py in <module>
      2 
      3 dask_model = lgb.DaskLGBMRegressor(n_estimators=10000)
----> 4 dask_model.fit(dX, dy)
      5 assert dask_model.fitted_
      6 

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/dask.py in fit(self, X, y, sample_weight, init_score, **kwargs)
    882     ) -> "DaskLGBMRegressor":
    883         """Docstring is inherited from the lightgbm.LGBMRegressor.fit."""
--> 884         return self._lgb_dask_fit(
    885             model_factory=LGBMRegressor,
    886             X=X,

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/dask.py in _lgb_dask_fit(self, model_factory, X, y, sample_weight, init_score, group, **kwargs)
    615         params.pop("client", None)
    616 
--> 617         model = _train(
    618             client=_get_dask_client(self.client),
    619             data=X,

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/dask.py in _train(client, data, label, params, model_factory, sample_weight, init_score, group, **kwargs)
    448     ]
    449 
--> 450     results = client.gather(futures_classifiers)
    451     results = [v for v in results if v]
    452     model = results[0]

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/distributed/client.py in gather(self, futures, errors, direct, asynchronous)
   1941             else:
   1942                 local_worker = None
-> 1943             return self.sync(
   1944                 self._gather,
   1945                 futures,

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/distributed/client.py in sync(self, func, asynchronous, callback_timeout, *args, **kwargs)
    838             return future
    839         else:
--> 840             return sync(
    841                 self.loop, func, *args, callback_timeout=callback_timeout, **kwargs
    842             )

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/distributed/utils.py in sync(loop, func, callback_timeout, *args, **kwargs)
    324     if error[0]:
    325         typ, exc, tb = error[0]
--> 326         raise exc.with_traceback(tb)
    327     else:
    328         return result[0]

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/distributed/utils.py in f()
    307             if callback_timeout is not None:
    308                 future = asyncio.wait_for(future, callback_timeout)
--> 309             result[0] = yield future
    310         except Exception:
    311             error[0] = sys.exc_info()

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/tornado/gen.py in run(self)
    760 
    761                     try:
--> 762                         value = future.result()
    763                     except Exception:
    764                         exc_info = sys.exc_info()

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/distributed/client.py in _gather(self, futures, errors, direct, local_worker)
   1806                             exc = CancelledError(key)
   1807                         else:
-> 1808                             raise exception.with_traceback(traceback)
   1809                         raise exc
   1810                     if errors == "skip":

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/dask.py in _train_part()
    116             model.fit(data, label, sample_weight=weight, init_score=init_score, group=group, **kwargs)
    117         else:
--> 118             model.fit(data, label, sample_weight=weight, init_score=init_score, **kwargs)
    119 
    120     finally:

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/sklearn.py in fit()
    816             callbacks=None, init_model=None):
    817         """Docstring is inherited from the LGBMModel."""
--> 818         super().fit(X, y, sample_weight=sample_weight, init_score=init_score,
    819                     eval_set=eval_set, eval_names=eval_names, eval_sample_weight=eval_sample_weight,
    820                     eval_init_score=eval_init_score, eval_metric=eval_metric,

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/sklearn.py in fit()
    681             init_model = init_model.booster_
    682 
--> 683         self._Booster = train(params, train_set,
    684                               self.n_estimators, valid_sets=valid_sets, valid_names=eval_names,
    685                               early_stopping_rounds=early_stopping_rounds,

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/engine.py in train()
    247                                     evaluation_result_list=None))
    248 
--> 249         booster.update(fobj=fobj)
    250 
    251         evaluation_result_list = []

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/basic.py in update()
   2641             if self.__set_objective_to_none:
   2642                 raise LightGBMError('Cannot update due to null objective function.')
-> 2643             _safe_call(_LIB.LGBM_BoosterUpdateOneIter(
   2644                 self.handle,
   2645                 ctypes.byref(is_finished)))

~/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/basic.py in _safe_call()
    108     """
    109     if ret != 0:
--> 110         raise LightGBMError(_LIB.LGBM_GetLastError().decode('utf-8'))
    111 
    112 

LightGBMError: Socket recv error, code: 54

Scenario 2: Jupyter Lab on Linux

I knew Dask integration is only tested on Linux., so I build a simple image usnig the following Dockerfile:

FROM continuumio/miniconda3

COPY . /app

WORKDIR /app
RUN conda install -c conda-forge jupyterlab pandas matplotlib -y && \ 
    conda install -c conda-forge lightgbm=3.2.1 -y && \
    conda install -c conda-forge dask -y && \
    conda install -c conda-forge graphviz python-graphviz -y

EXPOSE 8888

CMD ["/bin/bash"]

The packages version within container.

python                    3.9.5                h12debd9_4  
dask                      2021.9.0           pyhd8ed1ab_0    conda-forge
dask-core                 2021.9.0           pyhd8ed1ab_0    conda-forge
distributed               2021.9.0         py39hf3d152e_0    conda-forge
lightgbm                  3.2.1            py39he80948d_0    conda-forge

I ran the same example code on jupyter lab as I describe above. Also changing the n_estimators to 100, 1000, 10000, 1000000 in the same jupyter session. Everything went very well, there was no error raised.

The only warning only shows when I set n_estimators=1000000, but the training process was completed.

distributed.worker - WARNING - Unmanaged memory use is high. This may indicate a memory leak or the memory may not be released to the OS; see https://distributed.dask.org/en/latest/worker.html#memtrim for more information. -- Unmanaged memory: 1.51 GiB -- Worker memory limit: 1.92 GiB

However, the Dask integration on Linux is still benefits for me, I won't ran the cluster on macOS in production.

My question is this situation still kind of bug for macOS only?

@jameslamb
Copy link
Collaborator

@orcahmlee thanks very much for using LightGBM and the Dask interface!

I noticed you're using lightgbm==3.2.1. There have been many improvements to lightgbm since that version was released, including some critical bugfixes for lightgbm.dask (which you can see in the conversation on this issue, e.g. #4116 (comment)).

Please try installing from source and let us know whether or not that resolves the Socket recv error, code: 54 issue.

git clone --recursive https://github.com/microsoft/LightGBM.git
cd LightGBM/python-package
python setup.py install

For the warning Unmanaged memory use is high...you can safely ignore that warning when using lightgbm.dask. This can happen because of the architecture of lightgbm.dask. Basically, training involves one long-running Dask task per Dask worker, but then all of the logic of training is handled by processes created from those tasks, using LightGBM's C++ library. Dask cannot see what happens in those processes, and so it considers memory they allocated "unmanaged".

This warning is more likely to happen for a larger value of n_estimators because deeper models require more memory, and Dask is not involved in the process that's growing the LightGBM Booster.

To learn more about that, you might be interested in the my Dask Summit talk from earlier this year, "How Distributed LightGBM on Dask Works": https://github.com/jameslamb/talks/tree/main/how-distributed-lightgbm-on-dask-works.

@orcahmlee
Copy link

@jameslamb Thanks for the kindly and quickly reply. Sorry for my late reply, this my first time build from sources.

Now, my lightgbm version is 3.2.1.99.

# conda list
dask                      2021.9.0           pyhd8ed1ab_0    conda-forge
dask-core                 2021.9.0           pyhd8ed1ab_0    conda-forge
dask-kubernetes           2021.3.1           pyhd8ed1ab_0    conda-forge
distributed               2021.9.0         py38h50d1736_0    conda-forge
lightgbm                  3.2.1.99                 pypi_0    pypi

Howerver, when I ran the same code, I kept receiving the distributed.nanny - WARNING - Restarting worker . Then the Jupyter cell will running forever. The more detail show as below:

import dask.array as da
from distributed import Client, LocalCluster
from sklearn.datasets import make_regression

import lightgbm as lgb


cluster = LocalCluster(n_workers=2, dashboard_address=':9797')
client = Client(cluster)

X, y = make_regression(n_samples=7000, n_features=50)
dX = da.from_array(X, chunks=(100, 50))
dy = da.from_array(y, chunks=(100,))

print("beginning training")

dask_model = lgb.DaskLGBMRegressor(n_estimators=10)
dask_model.fit(dX, dy)
assert dask_model.fitted_

print("done training")

Output from Jupyter

/Users/andrew/miniconda3/envs/lightgbm/lib/python3.8/site-packages/lightgbm/dask.py:525: UserWarning: Parameter n_jobs will be ignored.
  _log_warning(f"Parameter {param_alias} will be ignored.")

Finding random open ports for workers
[LightGBM] [Info] Trying to bind port 51431...
[LightGBM] [Info] Binding port 51431 succeeded
[LightGBM] [Info] Listening...
[LightGBM] [Warning] Connecting to rank 1 failed, waiting for 200 milliseconds
[LightGBM] [Warning] Connecting to rank 1 failed, waiting for 260 milliseconds
[LightGBM] [Warning] Connecting to rank 1 failed, waiting for 338 milliseconds
[LightGBM] [Info] Trying to bind port 51432...
[LightGBM] [Info] Binding port 51432 succeeded
[LightGBM] [Info] Listening...

distributed.nanny - WARNING - Restarting worker

[LightGBM] [Info] Connected to rank 1
[LightGBM] [Info] Connected to rank 0
[LightGBM] [Info] Local rank: 0, total number of machines: 2
[LightGBM] [Info] Local rank: 1, total number of machines: 2
[LightGBM] [Warning] num_threads is set=4, n_jobs=-1 will be ignored. Current value: num_threads=4
[LightGBM] [Warning] num_threads is set=4, n_jobs=-1 will be ignored. Current value: num_threads=4

distributed.nanny - WARNING - Restarting worker

Did I miss something?

@jameslamb
Copy link
Collaborator

jameslamb commented Sep 17, 2021

No problem, we are here to help! Looks like you're running into a part of lightgbm.dask where the package doesn't raise clear errors to tell you what is happening.

One possibility is that your worker ran out of memory and was killed by Dask. You can try re-running training and watching the memory utilization in the Dask dashboard. If you do that and that doesn't seem to be the case, please report a new issue at https://github.com/microsoft/LightGBM/issues using the excellent example code in your post above, and we can work on it there (since you don't seem to be facing the Socket recv error, code: 54 issue any more).

LightGBM distributed training is not currently resilient to worker failures (partially documented in #3775, but we probably need another feature request for training being interrupted), and in the situation where a Dask worker dies you might not get an informative error.

@orcahmlee
Copy link

Yes, I do watching the Dask Dashboard.
I compared two version of LightGBM, 3.2.1 v.s. 3.2.1.99, using the same dataframe and same code. The dataframe's shape is only (7000, 28) is pretty small. There are not rich logs I can paste it, but I will describe what is happening.

3.2.1

  1. Summit the job from Jupyter client
  2. Progress shows: array -> dict -> _train_part
  3. Workers memory shows: only incress ~60 MiB per worker
  4. Receive the resulte on Jupyter client

圖片

3.2.1.99

  1. Summit the job from Jupyter client
  2. Progress shows: array -> dict -> _train_part
  3. Original workers were killed for some reason
    • I'm not sure is ran out of memory because the memory only incress ~60 MiB per worker
  4. deserialized_find_n_ports -> find_n_ports -> array -> dict
  5. Dask Task Graph shows: no-worker
  6. Jupyter client shows: distributed.nanny - WARNING - Restarting worker and wait forever

圖片

圖片

@jameslamb
Copy link
Collaborator

@orcahmlee I'd be happy to look into this when I have some availability today or tomorrow.

For now, can you please take this excellent writeup from your recent comment and open a new issue, as I requested in #4116 (comment)?

If you do that and that doesn't seem to be the case, please report a new issue at https://github.com/microsoft/LightGBM/issues

@orcahmlee
Copy link

@jameslamb Thanks for your help. I opened a new issue to trace this situation #4625.

@jameslamb
Copy link
Collaborator

thanks so much for the excellent write-up there! I'm going to lock discussion in this issue to encourage others to start new ones in the future.

@microsoft microsoft locked as resolved and limited conversation to collaborators Sep 27, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants