Skip to content

Instantly share code, notes, and snippets.

@jjerphan

jjerphan/deadlock_dispatch

Last active May 22, 2019 13:53
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save jjerphan/70c105b314a7bbd777dab02bd7db36cc to your computer and use it in GitHub Desktop.
Save jjerphan/70c105b314a7bbd777dab02bd7db36cc to your computer and use it in GitHub Desktop.
Download ZIP
Deadlock on joblib.Parallel when using DaskDistributedBackEnd: state of the lock and race condition in 2 different threads
Raw
deadlock_dispatch
[2019-05-22 13:46:14,970] [22/MainThread] [INFO] [root] Building Gridsearcher for grid: {'reg_alpha': [0.0], 'colsample_bylevel': [1.0], 'learning_rate': [0.2, 0.4, 0.8], 'max_delta_step': [0.0], 'booster': ['gbtree'], 'colsample_bytree': [1.0], 'min_child_weight': [0.0], 'subsample': [1.0], 'reg_lambda': [1.0, 3.0, 5.0], 'objective': ['reg:linear'], 'max_depth': [3, 4, 5, 6, 7, 8], 'gamma': [0.0]}
[2019-05-22 13:46:14,971] [22/MainThread] [INFO] [root] Fitting 3 folds for each of 54 candidates, totalling 162 fits
[2019-05-22 13:46:14,974] [22/MainThread] [INFO] [root] Performing GridSearch with CVInterruptWatcherThread
[2019-05-22 13:46:14,974] [22/MainThread] [INFO] [root] Performing GridSearch with Dask
[2019-05-22 13:46:14,974] [22/MainThread] [INFO] [root] Creating Dask client
[2019-05-22 13:46:15,063] [22/MainThread] [INFO] [root] Client.__init__ called from get_best_estimator
[2019-05-22 13:46:15,064] [22/MainThread] [INFO] [root] Client.start called from __init__
[2019-05-22 13:46:15,068] [22/IO loop] [INFO] [root] Client._start called from wrapper
[2019-05-22 13:46:15,069] [22/IO loop] [INFO] [root] Client._ensure_connected called from wrapper
[2019-05-22 13:46:15,075] [22/IO loop] [INFO] [root] Client._update_scheduler_info called from wrapper
[2019-05-22 13:46:15,087] [22/Thread-1] [INFO] [root] Scheduler.add_client called from wrapper
[2019-05-22 13:46:15,087] [22/Thread-1] [INFO] [root] Receive client connection: Client-f7ca262b-7c97-11e9-8016-0a580a0c0350
distributed.core - INFO - Starting established connection
[2019-05-22 13:46:15,092] [22/IO loop] [INFO] [root] Client._handle_report called from wrapper
[2019-05-22 13:46:15,099] [22/MainThread] [INFO] [root] Entering Dask context
[2019-05-22 13:46:15,105] [22/MainThread] [INFO] [joblib.dask] _dask import (logger)
[2019-05-22 13:46:15,105] [22/MainThread] [INFO] [root] _dask import (logging)
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [joblib.parallel] register_parallel_backend called on ; name: dask ; factory: DaskDistributedBackend
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [root] Creating joblib.Parallel(n_jobs=4, verbose=100, pre_dispatch=n_jobs, backend=dask)
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [joblib.parallel] Parallel.__init__ called
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [joblib.parallel] Parallel.__init__: getting back_end from given string:'dask'
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [root] Worker.get_client called
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,106] [22/MainThread] [INFO] [joblib.parallel] Parallel.__init__: back_end=DaskDistributedBackend
[2019-05-22 13:46:15,107] [22/MainThread] [INFO] [root] Running _dku_fit_and_score with 4 jobs and dask as a parallel back-end
[2019-05-22 13:46:15,107] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ called
[2019-05-22 13:46:15,107] [22/MainThread] [INFO] [joblib.parallel] Parallel._initialize_backend called
[2019-05-22 13:46:15,107] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.configure called
[2019-05-22 13:46:15,107] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.effective_n_jobs called
[2019-05-22 13:46:15,127] [22/MainThread] [INFO] [joblib.parallel] Parallel._print called
[2019-05-22 13:46:15,127] [22/MainThread] [INFO] [joblib.parallel] [Parallel(n_jobs=4)]: Using backend DaskDistributedBackend with 24 concurrent workers.
[2019-05-22 13:46:15,127] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.start_call called
[2019-05-22 13:46:15,127] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__: iterator created
[2019-05-22 13:46:15,127] [22/MainThread] [INFO] [joblib.parallel] <generator object <genexpr> at 0x7fdf30119410>
[2019-05-22 13:46:15,128] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-22 13:46:15,128] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-22 13:46:15,128] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.get_nested_backend called
[2019-05-22 13:46:15,128] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:15,128] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ called
[2019-05-22 13:46:15,129] [22/MainThread] [INFO] [joblib.parallel] delayed called
[2019-05-22 13:46:15,130] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ : wraps 1 objects
[2019-05-22 13:46:15,130] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch: calling self._dispatch
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.parallel] BatchCompletionCallBack.__init__ called
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 0 to back-end of size 1
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async called
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args called
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.dask] Looping on func.items of len=1
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.dask] f: <function _dku_fit_and_score at 0x7fdf31833b18>
[2019-05-22 13:46:15,132] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:15,133] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:15,136] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:15,137] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,148] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:15,159] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:15,160] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:15,161] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:15,162] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,168] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:15,169] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:15,172] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:15,173] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,178] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:15,183] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:15,184] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:15,184] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:15,185] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,203] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:15,204] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:15,206] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:15,207] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,210] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:15,214] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:15,215] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:15,216] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:15,216] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,222] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:15,222] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:15,225] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:15,225] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,229] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:15,233] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:15,234] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:15,234] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:15,235] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,256] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args: appending tasks done
[2019-05-22 13:46:15,257] [22/MainThread] [INFO] [joblib.dask] Batch.__init__ called
[2019-05-22 13:46:15,257] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Submitting to Client
[2019-05-22 13:46:15,258] [22/MainThread] [INFO] [root] Client.submit called from apply_async
[2019-05-22 13:46:15,259] [22/MainThread] [INFO] [root] Client._graph_to_futures called from submit
[2019-05-22 13:46:15,259] [22/MainThread] [INFO] [joblib.dask] Batch.__reduce__ called
[2019-05-22 13:46:15,261] [22/MainThread] [INFO] [root] Client._send_to_scheduler called from _graph_to_futures
[2019-05-22 13:46:15,261] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Done submitting to the Client
[2019-05-22 13:46:15,261] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Added future to tasks
[2019-05-22 13:46:15,262] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-ebeae09947704c95845d464239ac6739>
[2019-05-22 13:46:15,264] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Returning future
[2019-05-22 13:46:15,264] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-ebeae09947704c95845d464239ac6739>
[2019-05-22 13:46:15,265] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 0 inserted to back-end
[2019-05-22 13:46:15,265] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-22 13:46:15,266] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-22 13:46:15,266] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:15,266] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-22 13:46:15,266] [22/IO loop] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Executing callback_wrapper
[2019-05-22 13:46:15,267] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-22 13:46:15,267] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched initial batch
[2019-05-22 13:46:15,271] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-22 13:46:15,272] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-22 13:46:15,272] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.get_nested_backend called
[2019-05-22 13:46:15,272] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:15,272] [22/Thread-1] [INFO] [root] Scheduler.update_graph called from handle_stream
[2019-05-22 13:46:15,272] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ called
[2019-05-22 13:46:15,274] [22/MainThread] [INFO] [joblib.parallel] delayed called
[2019-05-22 13:46:15,279] [22/Thread-1] [INFO] [root] Scheduler.transitions called from update_graph
[2019-05-22 13:46:15,280] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ : wraps 1 objects
[2019-05-22 13:46:15,280] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch: calling self._dispatch
[2019-05-22 13:46:15,283] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:15,286] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:15,288] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-22 13:46:15,289] [22/MainThread] [INFO] [joblib.parallel] BatchCompletionCallBack.__init__ called
[2019-05-22 13:46:15,289] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from transition_waiting_processing
[2019-05-22 13:46:15,290] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-22 13:46:15,290] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:15,290] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-22 13:46:15,291] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 1 to back-end of size 1
[2019-05-22 13:46:15,292] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async called
[2019-05-22 13:46:15,293] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args called
[2019-05-22 13:46:15,293] [22/MainThread] [INFO] [joblib.dask] Looping on func.items of len=1
[2019-05-22 13:46:15,294] [22/MainThread] [INFO] [joblib.dask] f: <function _dku_fit_and_score at 0x7fdf31833b18>
[2019-05-22 13:46:15,295] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:15,296] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:15,444] [22/Thread-1] [INFO] [root] Scheduler.valid_workers called from decide_worker
[2019-05-22 13:46:15,445] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:15,449] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from decide_worker
[2019-05-22 13:46:15,453] [22/Thread-1] [INFO] [root] Scheduler.consumre_resources called from transition_waiting_processing
[2019-05-22 13:46:15,454] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:15,454] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:15,458] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from transition_waiting_processing
[2019-05-22 13:46:15,459] [22/Thread-1] [INFO] [root] Scheduler.send_task_to_worker called from transition_waiting_processing
[2019-05-22 13:46:15,459] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from send_task_to_worker
[2019-05-22 13:46:15,460] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:15,461] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,461] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:15,462] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,462] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:15,463] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,463] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:15,464] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:15,465] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:15,465] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:15,471] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:15,570] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:15,671] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:15,773] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:15,874] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:15,975] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,077] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,178] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,281] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,382] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,484] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,585] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,686] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,718] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:16,744] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:16,788] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,889] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:16,990] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,093] [22/IO loop] [INFO] [root] Client._update_scheduler_info called from wrapper
[2019-05-22 13:46:17,094] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,225] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,236] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,237] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,237] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,238] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,274] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,276] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,277] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,278] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,281] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,285] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,287] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,287] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,288] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,292] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args: appending tasks done
[2019-05-22 13:46:17,293] [22/MainThread] [INFO] [joblib.dask] Batch.__init__ called
[2019-05-22 13:46:17,293] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Submitting to Client
[2019-05-22 13:46:17,295] [22/MainThread] [INFO] [root] Client.submit called from apply_async
[2019-05-22 13:46:17,296] [22/MainThread] [INFO] [root] Client._graph_to_futures called from submit
[2019-05-22 13:46:17,296] [22/MainThread] [INFO] [joblib.dask] Batch.__reduce__ called
[2019-05-22 13:46:17,297] [22/MainThread] [INFO] [root] Client._send_to_scheduler called from _graph_to_futures
[2019-05-22 13:46:17,298] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Done submitting to the Client
[2019-05-22 13:46:17,298] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Added future to tasks
[2019-05-22 13:46:17,298] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-e4f07f71ee244130aa5058ee010a9aeb>
[2019-05-22 13:46:17,298] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Returning future
[2019-05-22 13:46:17,298] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-e4f07f71ee244130aa5058ee010a9aeb>
[2019-05-22 13:46:17,299] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 1 inserted to back-end
[2019-05-22 13:46:17,299] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-22 13:46:17,299] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-22 13:46:17,299] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-22 13:46:17,300] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-22 13:46:17,300] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,300] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-22 13:46:17,300] [22/IO loop] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Executing callback_wrapper
[2019-05-22 13:46:17,304] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-22 13:46:17,305] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-22 13:46:17,305] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.get_nested_backend called
[2019-05-22 13:46:17,305] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:17,305] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ called
[2019-05-22 13:46:17,306] [22/Thread-1] [INFO] [root] Scheduler.update_graph called from handle_stream
[2019-05-22 13:46:17,307] [22/MainThread] [INFO] [joblib.parallel] delayed called
[2019-05-22 13:46:17,313] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ : wraps 1 objects
[2019-05-22 13:46:17,313] [22/Thread-1] [INFO] [root] Scheduler.transitions called from update_graph
[2019-05-22 13:46:17,313] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch: calling self._dispatch
[2019-05-22 13:46:17,314] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,316] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,315] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from transition_waiting_processing
[2019-05-22 13:46:17,315] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-22 13:46:17,317] [22/MainThread] [INFO] [joblib.parallel] BatchCompletionCallBack.__init__ called
[2019-05-22 13:46:17,317] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-22 13:46:17,318] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-22 13:46:17,318] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 2 to back-end of size 1
[2019-05-22 13:46:17,319] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async called
[2019-05-22 13:46:17,320] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args called
[2019-05-22 13:46:17,321] [22/MainThread] [INFO] [joblib.dask] Looping on func.items of len=1
[2019-05-22 13:46:17,321] [22/MainThread] [INFO] [joblib.dask] f: <function _dku_fit_and_score at 0x7fdf31833b18>
[2019-05-22 13:46:17,321] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,322] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,321] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,323] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,326] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,326] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,327] [22/Thread-1] [INFO] [root] Scheduler.valid_workers called from decide_worker
[2019-05-22 13:46:17,330] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from decide_worker
[2019-05-22 13:46:17,331] [22/Thread-1] [INFO] [root] Scheduler.consumre_resources called from transition_waiting_processing
[2019-05-22 13:46:17,332] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from transition_waiting_processing
[2019-05-22 13:46:17,332] [22/Thread-1] [INFO] [root] Scheduler.send_task_to_worker called from transition_waiting_processing
[2019-05-22 13:46:17,333] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from send_task_to_worker
[2019-05-22 13:46:17,334] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,335] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,337] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,338] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,338] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,339] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,340] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,341] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,342] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,343] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,348] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,354] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,355] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,355] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,356] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,378] [22/Thread-1] [INFO] [root] Scheduler.add_client called from wrapper
[2019-05-22 13:46:17,378] [22/Thread-1] [INFO] [root] Receive client connection: Client-worker-f927f628-7c97-11e9-8017-0a580a0c0353
distributed.core - INFO - Starting established connection
[2019-05-22 13:46:17,387] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,388] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,391] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,391] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,395] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,399] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,399] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,400] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,400] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,405] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args: appending tasks done
[2019-05-22 13:46:17,405] [22/MainThread] [INFO] [joblib.dask] Batch.__init__ called
[2019-05-22 13:46:17,405] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Submitting to Client
[2019-05-22 13:46:17,406] [22/MainThread] [INFO] [root] Client.submit called from apply_async
[2019-05-22 13:46:17,407] [22/MainThread] [INFO] [root] Client._graph_to_futures called from submit
[2019-05-22 13:46:17,407] [22/MainThread] [INFO] [joblib.dask] Batch.__reduce__ called
[2019-05-22 13:46:17,408] [22/MainThread] [INFO] [root] Client._send_to_scheduler called from _graph_to_futures
[2019-05-22 13:46:17,408] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Done submitting to the Client
[2019-05-22 13:46:17,409] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Added future to tasks
[2019-05-22 13:46:17,409] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-195ca9e1c7f74888885bd7ac3b839f6f>
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Returning future
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-195ca9e1c7f74888885bd7ac3b839f6f>
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 2 inserted to back-end
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-22 13:46:17,410] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-22 13:46:17,412] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,412] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-22 13:46:17,413] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-22 13:46:17,413] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.get_nested_backend called
[2019-05-22 13:46:17,413] [22/IO loop] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Executing callback_wrapper
[2019-05-22 13:46:17,413] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:17,414] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ called
[2019-05-22 13:46:17,417] [22/MainThread] [INFO] [joblib.parallel] delayed called
[2019-05-22 13:46:17,419] [22/Thread-1] [INFO] [root] Scheduler.update_graph called from handle_stream
[2019-05-22 13:46:17,424] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ : wraps 1 objects
[2019-05-22 13:46:17,424] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch: calling self._dispatch
[2019-05-22 13:46:17,426] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,427] [22/Thread-1] [INFO] [root] Scheduler.transitions called from update_graph
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.parallel] BatchCompletionCallBack.__init__ called
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 3 to back-end of size 1
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async called
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args called
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.dask] Looping on func.items of len=1
[2019-05-22 13:46:17,428] [22/MainThread] [INFO] [joblib.dask] f: <function _dku_fit_and_score at 0x7fdf31833b18>
[2019-05-22 13:46:17,429] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,429] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,431] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,431] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,433] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from transition_waiting_processing
[2019-05-22 13:46:17,433] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,434] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,435] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,437] [22/Thread-1] [INFO] [root] Scheduler.valid_workers called from decide_worker
[2019-05-22 13:46:17,438] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from decide_worker
[2019-05-22 13:46:17,439] [22/Thread-1] [INFO] [root] Scheduler.consumre_resources called from transition_waiting_processing
[2019-05-22 13:46:17,440] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from transition_waiting_processing
[2019-05-22 13:46:17,440] [22/Thread-1] [INFO] [root] Scheduler.send_task_to_worker called from transition_waiting_processing
[2019-05-22 13:46:17,441] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from send_task_to_worker
[2019-05-22 13:46:17,442] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,443] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,443] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,444] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,445] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,445] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,446] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,447] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,448] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,449] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,452] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,462] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,463] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,463] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,464] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,470] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,471] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,473] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,474] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,476] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,481] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,482] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,482] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,483] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,488] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args: appending tasks done
[2019-05-22 13:46:17,488] [22/MainThread] [INFO] [joblib.dask] Batch.__init__ called
[2019-05-22 13:46:17,488] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Submitting to Client
[2019-05-22 13:46:17,489] [22/MainThread] [INFO] [root] Client.submit called from apply_async
[2019-05-22 13:46:17,490] [22/MainThread] [INFO] [root] Client._graph_to_futures called from submit
[2019-05-22 13:46:17,490] [22/MainThread] [INFO] [joblib.dask] Batch.__reduce__ called
[2019-05-22 13:46:17,492] [22/MainThread] [INFO] [root] Client._send_to_scheduler called from _graph_to_futures
[2019-05-22 13:46:17,492] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Done submitting to the Client
[2019-05-22 13:46:17,492] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Added future to tasks
[2019-05-22 13:46:17,492] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-047ad29d547b4d5aad8794bec58191ed>
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Returning future
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.dask] <Future: status: pending, key: _dku_fit_and_score-batch-047ad29d547b4d5aad8794bec58191ed>
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 3 inserted to back-end
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-22 13:46:17,493] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.get_nested_backend called
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.__init__ called
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ called
[2019-05-22 13:46:17,494] [22/MainThread] [INFO] [joblib.parallel] delayed called
[2019-05-22 13:46:17,495] [22/MainThread] [INFO] [joblib.parallel] BatchedCalls.__init__ : wraps 1 objects
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch: calling self._dispatch
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] BatchCompletionCallBack.__init__ called
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 4 to back-end of size 1
[2019-05-22 13:46:17,496] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend.apply_async called
[2019-05-22 13:46:17,497] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args called
[2019-05-22 13:46:17,497] [22/MainThread] [INFO] [joblib.dask] Looping on func.items of len=1
[2019-05-22 13:46:17,497] [22/MainThread] [INFO] [joblib.dask] f: <function _dku_fit_and_score at 0x7fdf31833b18>
[2019-05-22 13:46:17,497] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,498] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,499] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,499] [22/IO loop] [INFO] [joblib.dask] DaskDistributedBackend.apply_async: Executing callback_wrapper
[2019-05-22 13:46:17,500] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,501] [22/IO loop] [INFO] [root] Client._send_to_scheduler called from _release_key
[2019-05-22 13:46:17,501] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,502] [22/IO loop] [INFO] [root] Client._send_to_scheduler_safe called from null_wrapper
[2019-05-22 13:46:17,503] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,503] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,509] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,512] [22/Thread-1] [INFO] [root] Scheduler.update_graph called from handle_stream
[2019-05-22 13:46:17,512] [22/Thread-1] [INFO] [root] Scheduler.transitions called from update_graph
[2019-05-22 13:46:17,513] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from transition_waiting_processing
[2019-05-22 13:46:17,514] [22/Thread-1] [INFO] [root] Scheduler.valid_workers called from decide_worker
[2019-05-22 13:46:17,516] [22/Thread-1] [INFO] [root] Scheduler.decide_worker called from decide_worker
[2019-05-22 13:46:17,517] [22/Thread-1] [INFO] [root] Scheduler.worker_objective called from decide_worker
[2019-05-22 13:46:17,518] [22/Thread-1] [INFO] [root] Scheduler.worker_objective called from decide_worker
[2019-05-22 13:46:17,519] [22/Thread-1] [INFO] [root] Scheduler.consumre_resources called from transition_waiting_processing
[2019-05-22 13:46:17,519] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from transition_waiting_processing
[2019-05-22 13:46:17,520] [22/Thread-1] [INFO] [root] Scheduler.send_task_to_worker called from transition_waiting_processing
[2019-05-22 13:46:17,520] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from send_task_to_worker
[2019-05-22 13:46:17,521] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,522] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,522] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,523] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,523] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,524] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,525] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from update_graph
[2019-05-22 13:46:17,526] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,526] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,527] [22/Thread-1] [INFO] [root] Scheduler.transitions called from client_releases_keys
[2019-05-22 13:46:17,529] [22/Thread-1] [INFO] [root] Scheduler.add_client called from wrapper
[2019-05-22 13:46:17,529] [22/Thread-1] [INFO] [root] Receive client connection: Client-worker-f93c3cfa-7c97-11e9-8017-0a580a0c0353
distributed.core - INFO - Starting established connection
[2019-05-22 13:46:17,531] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:17,534] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:17,535] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:17,536] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,567] [22/MainThread] [INFO] [joblib.dask] DaskDistributedBackend._to_func_args.maybe_to_future: scatter to Client
[2019-05-22 13:46:17,568] [22/MainThread] [INFO] [root] Client.scatter called from maybe_to_futures
[2019-05-22 13:46:17,570] [22/IO loop] [INFO] [root] Client._scatter called from wrapper
[2019-05-22 13:46:17,570] [22/IO loop] [INFO] [root] Worker.get_worker called
[2019-05-22 13:46:17,577] [22/Thread-1] [INFO] [root] Scheduler.scatter called from wrapper
[2019-05-22 13:46:17,651] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,652] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,753] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,754] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,855] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,856] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,910] [22/Thread-1] [INFO] [root] Scheduler.handle_task_finished called from handle_stream
[2019-05-22 13:46:17,911] [22/Thread-1] [INFO] [root] Scheduler._remove_from_processing called from transition_processing_memory
[2019-05-22 13:46:17,912] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _remove_from_processing
[2019-05-22 13:46:17,913] [22/Thread-1] [INFO] [root] Scheduler.release_resources called from _remove_from_processing
[2019-05-22 13:46:17,913] [22/Thread-1] [INFO] [root] Scheduler._add_to_memory called from transition_processing_memory
[2019-05-22 13:46:17,914] [22/Thread-1] [INFO] [root] Scheduler.report called from _add_to_memory
[2019-05-22 13:46:17,914] [22/Thread-1] [INFO] [root] Scheduler.transitions called from handle_task_finished
[2019-05-22 13:46:17,916] [22/IO loop] [INFO] [joblib.parallel] BatchCompletionCallBack.__call__ called
[2019-05-22 13:46:17,916] [22/IO loop] [INFO] [joblib.parallel] BatchCompletionCallBack.__call__: calling parallel._backend.batch_completed
[2019-05-22 13:46:17,916] [22/IO loop] [INFO] [joblib.parallel] BatchCompletionCallBack.__call__: calling parallel.print_progress
[2019-05-22 13:46:17,916] [22/IO loop] [INFO] [joblib.parallel] Parallel.print_progress called
[2019-05-22 13:46:17,917] [22/IO loop] [INFO] [joblib.parallel] Parallel._print called
[2019-05-22 13:46:17,917] [22/IO loop] [INFO] [joblib.parallel] [Parallel(n_jobs=4)]: Done 1 tasks | elapsed: 2.8s
[2019-05-22 13:46:17,917] [22/IO loop] [INFO] [joblib.parallel] BatchCompletionCallBack.__call__: taking the lock
[2019-05-22 13:46:17,957] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,957] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:17,966] [22/Thread-1] [INFO] [root] Scheduler.handle_task_finished called from handle_stream
[2019-05-22 13:46:17,967] [22/Thread-1] [INFO] [root] Scheduler._remove_from_processing called from transition_processing_memory
[2019-05-22 13:46:17,968] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _remove_from_processing
[2019-05-22 13:46:17,968] [22/Thread-1] [INFO] [root] Scheduler.release_resources called from _remove_from_processing
[2019-05-22 13:46:17,969] [22/Thread-1] [INFO] [root] Scheduler._add_to_memory called from transition_processing_memory
[2019-05-22 13:46:17,970] [22/Thread-1] [INFO] [root] Scheduler.report called from _add_to_memory
[2019-05-22 13:46:17,970] [22/Thread-1] [INFO] [root] Scheduler.transitions called from handle_task_finished
[2019-05-22 13:46:17,971] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:17,972] [22/Thread-1] [INFO] [root] Scheduler.report called from transition_memory_released
[2019-05-22 13:46:17,973] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from transition_released_forgotten
[2019-05-22 13:46:17,974] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,975] [22/Thread-1] [INFO] [root] Scheduler.handle_task_finished called from handle_stream
[2019-05-22 13:46:17,976] [22/Thread-1] [INFO] [root] Scheduler._remove_from_processing called from transition_processing_memory
[2019-05-22 13:46:17,976] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _remove_from_processing
[2019-05-22 13:46:17,977] [22/Thread-1] [INFO] [root] Scheduler.release_resources called from _remove_from_processing
[2019-05-22 13:46:17,978] [22/Thread-1] [INFO] [root] Scheduler._add_to_memory called from transition_processing_memory
[2019-05-22 13:46:17,978] [22/Thread-1] [INFO] [root] Scheduler.report called from _add_to_memory
[2019-05-22 13:46:17,979] [22/Thread-1] [INFO] [root] Scheduler.transitions called from handle_task_finished
[2019-05-22 13:46:17,980] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:17,980] [22/Thread-1] [INFO] [root] Scheduler.report called from transition_memory_released
[2019-05-22 13:46:17,981] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from transition_released_forgotten
[2019-05-22 13:46:17,982] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:17,982] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:17,984] [22/Thread-1] [INFO] [root] Scheduler.report called from transition_memory_released
[2019-05-22 13:46:17,984] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from transition_released_forgotten
[2019-05-22 13:46:17,985] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:18,059] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,160] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,261] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,363] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,467] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,569] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,671] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,774] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,836] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:18,859] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:18,876] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:18,978] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,080] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,183] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,286] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,389] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,491] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,593] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,626] [22/Thread-1] [INFO] [root] Scheduler.update_data called from scatter
[2019-05-22 13:46:19,629] [22/Thread-1] [INFO] [root] Scheduler.report called from update_data
[2019-05-22 13:46:19,631] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from client_desires_keys
[2019-05-22 13:46:19,633] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:19,649] [22/Thread-1] [INFO] [root] Scheduler.add_keys called from handle_stream
[2019-05-22 13:46:19,650] [22/Thread-1] [INFO] [root] Scheduler.add_keys called from handle_stream
[2019-05-22 13:46:19,651] [22/Thread-1] [INFO] [root] Scheduler.add_keys called from handle_stream
[2019-05-22 13:46:19,694] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,795] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,820] [22/Thread-1] [INFO] [root] Scheduler.add_client called from wrapper
[2019-05-22 13:46:19,820] [22/Thread-1] [INFO] [root] Receive client connection: Client-worker-fa9e47a1-7c97-11e9-8017-0a580a0c0351
distributed.core - INFO - Starting established connection
[2019-05-22 13:46:19,896] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _reevaluate_occupancy_worker
[2019-05-22 13:46:19,908] [22/Thread-1] [INFO] [root] Scheduler.handle_task_finished called from handle_stream
[2019-05-22 13:46:19,909] [22/Thread-1] [INFO] [root] Scheduler._remove_from_processing called from transition_processing_memory
[2019-05-22 13:46:19,911] [22/Thread-1] [INFO] [root] Scheduler.check_idle_saturated called from _remove_from_processing
[2019-05-22 13:46:19,912] [22/Thread-1] [INFO] [root] Scheduler.release_resources called from _remove_from_processing
[2019-05-22 13:46:19,913] [22/Thread-1] [INFO] [root] Scheduler._add_to_memory called from transition_processing_memory
[2019-05-22 13:46:19,914] [22/Thread-1] [INFO] [root] Scheduler.report called from _add_to_memory
[2019-05-22 13:46:19,915] [22/Thread-1] [INFO] [root] Scheduler.transitions called from handle_task_finished
[2019-05-22 13:46:19,916] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:19,917] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:19,918] [22/Thread-1] [INFO] [root] Scheduler.report called from transition_memory_released
[2019-05-22 13:46:19,919] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from transition_released_forgotten
[2019-05-22 13:46:19,920] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:19,921] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:19,922] [22/Thread-1] [INFO] [root] Scheduler.worker_send called from transition_memory_released
[2019-05-22 13:46:19,922] [22/Thread-1] [INFO] [root] Scheduler.report called from transition_memory_released
[2019-05-22 13:46:19,923] [22/Thread-1] [INFO] [root] Scheduler.report_on_key called from transition_released_forgotten
[2019-05-22 13:46:19,924] [22/Thread-1] [INFO] [root] Scheduler.report called from report_on_key
[2019-05-22 13:46:20,988] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:21,051] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:23,223] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:23,306] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:25,521] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:25,560] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:27,819] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:27,844] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:30,150] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:30,269] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:32,620] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:32,726] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:35,124] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:35,149] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
[2019-05-22 13:46:37,594] [22/Thread-2] [DEBUG] [urllib3.connectionpool] Starting new HTTP connection (1): 192.168.10.123:8083
[2019-05-22 13:46:37,617] [22/Thread-2] [DEBUG] [urllib3.connectionpool] http://192.168.10.123:8083 "POST /dip/api/tintercom/containers/put-file?fileKind=CONTEXT_DIR&path=sessions%2Fs102%2Fpp1%2Ftrain_infos.tgz&executionId=doctor-train-dfovp5a&expand=true HTTP/1.1" 200 2
Raw
log
[2019-05-21 12:39:33,017] [22/MainThread] [INFO] [root] Creating joblib.Parallel(n_jobs=4, verbose=100, pre_dispatch=n_jobs, backend=dask)
[2019-05-21 12:39:33,205] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-21 12:39:33,206] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-21 12:39:33,208] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: calling self._dispatch
[2019-05-21 12:39:33,209] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-21 12:39:33,209] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 0 to back-end of size 1
[2019-05-21 12:39:33,209] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-21 12:39:33,209] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-21 12:39:33,434] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 0 inserted to back-end
[2019-05-21 12:39:33,434] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-21 12:39:33,435] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-21 12:39:33,436] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched initial batch
[2019-05-21 12:39:33,436] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-21 12:39:33,436] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-21 12:39:33,444] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-21 12:39:33,444] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-21 12:39:33,450] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: calling self._dispatch
[2019-05-21 12:39:33,451] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-21 12:39:33,451] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 1 to back-end of size 1
[2019-05-21 12:39:33,451] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-21 12:39:33,451] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 1 inserted to back-end
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-21 12:39:35,157] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-21 12:39:35,158] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-21 12:39:35,158] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-21 12:39:35,161] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: calling self._dispatch
[2019-05-21 12:39:35,162] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-21 12:39:35,162] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 2 to back-end of size 1
[2019-05-21 12:39:35,162] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-21 12:39:35,162] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 2 inserted to back-end
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-21 12:39:35,212] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-21 12:39:35,213] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-21 12:39:35,213] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-21 12:39:35,217] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: calling self._dispatch
[2019-05-21 12:39:35,218] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-21 12:39:35,218] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 3 to back-end of size 1
[2019-05-21 12:39:35,218] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-21 12:39:35,218] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel.__call__ dispatched one batch
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: job of id 3 inserted to back-end
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: leaving the lock
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: left the lock
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: leaving the lock after self._dispatch
[2019-05-21 12:39:35,261] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: left the lock
[2019-05-21 12:39:35,262] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch called from __call__
[2019-05-21 12:39:35,262] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: took the lock
[2019-05-21 12:39:35,265] [22/MainThread] [INFO] [joblib.parallel] Parallel.dispatch_one_batch: calling self._dispatch
[2019-05-21 12:39:35,266] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch called from dispatch_one_batch
[2019-05-21 12:39:35,266] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: submitting job of id 4 to back-end of size 1
[2019-05-21 12:39:35,266] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: taking the lock
[2019-05-21 12:39:35,266] [22/MainThread] [INFO] [joblib.parallel] Parallel._dispatch: took the lock
[2019-05-21 12:39:35,428] [22/IO loop] [INFO] [joblib.parallel] BatchCompletionCallBack.__call__: taking the lock
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment