Dashboard profile page is often blank until computation completes

[stuarteberg]

Sometimes, I can view the dashboard's super-useful "profile" page while my computation is running, but more often than not, I must wait until the computation is complete before that page displays anything.

It seems to be dependent on the particular computation I'm running. (For a particular program, it either works every time I run it, or is blank every time I run it.) I haven't figured out exactly which operations trigger the update.

Is there some way I can poke the client/scheduler/dashboard to force the profile page to be updated before the computation is complete?

[mrocklin]

Unfortunately I haven't seen this before, don't know why this would be happening, and don't have suggestions for ways for you to poke it.

If you have more information or a way to reliably produce the issue that might be good. Honestly if I were to debug this I would probably start throwing print statements into various parts of the code; nothing particularly sophisticated.

[stuarteberg]

Thanks for the response. I don't have a good test case for you yet, but I'll work on it.

In the meantime, I'll jot down a couple notes, based on very limited testing. (I need to do more investigation -- these might be coincidental.)

1. It may be an issue that affects Firefox specifically (not Chrome). For the dashboard I had open today, Firefox refused to show the profile tab, but Chrome would show it.

2. Even in Chrome, I noticed that the profile page can take a long time to pop up if the scheduler process is undergoing a garbage collection. I noticed a lot of messages like this appearing in my console:

   WARNING full garbage collections took 39% CPU time recently (threshold: 10%)
   

   ... and the profile page was blank until they stopped appearing, which took 10 seconds or so.

[stuarteberg]

FWIW, this is what I mean by a "blank" profile page. The header is present, but no content otherwise.

[bnaul]

In my experience the profile tab isn't usable with more than say a few dozen workers; calling client.profile() with a subset of workers (I use 100) does work, and I visualize the results with something like #1461 (comment) instead. I suspect something is just timing out? If there were a way to only profile a subset of workers through the web interface I suspect that would resolve the issue.

[mrocklin]

It's odd that client.profile would work while the dashboard wouldn't. They're mostly the same code path.

@stuarteberg does your experience align with @bnaul 's ?

[bnaul]

Just to be clear, client.profile() also fails in that case; what I run instead is

workers = list(client.scheduler_info()['workers'])[:n_workers]
profile_info = client.profile(workers=workers)

usually w/ n_workers=100

[mrocklin]

Ah I see. I'd be curious to learn more. Is the scheduler using a bunch of CPU during this time? Any errors showing up on the workers?

[bnaul]

Warnings/error (the error only shows up after a couple minutes of churning):

distributed.utils_perf - INFO - full garbage collection released 367.26 MB from 24072 reference cycles (threshold: 10.00 MB)
distributed.utils_perf - WARNING - full garbage collections took 10% CPU time recently (threshold: 10%)
distributed.utils_perf - WARNING - full garbage collections took 11% CPU time recently (threshold: 10%)
distributed.utils_perf - WARNING - full garbage collections took 12% CPU time recently (threshold: 10%)
distributed.core - INFO - Event loop was unresponsive in Scheduler for 21.42s.  This is often caused by long-running GIL-holding functions or moving large chunks of data. This can cause timeouts and instability.
distributed.utils - ERROR - 'NoneType' object has no attribute 'add_next_tick_callback'
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/distributed/utils.py", line 648, in log_errors
    yield
  File "/usr/local/lib/python3.7/site-packages/distributed/bokeh/components.py", line 572, in cb
    self.doc().add_next_tick_callback(lambda: self.update(prof, metadata))
AttributeError: 'NoneType' object has no attribute 'add_next_tick_callback'

Memory dropped back to 3.7GB after the spike finished.

[mrocklin]

OK, so it looks like it's possibly just very expensive to aggregate all of that information from the different workers. This problem would presumably also compound as we had data for longer time periods.

It sounds like we might need to genuinely consider how best to aggregate profile information across workers. Some options:

1. As you suggest, just get a subset of the workers, in many cases this is fast and likely representative
2. Have the workers aggregate their data amongst themselves in some sort of tree reduction (every ten workers share their data to one that then combines it and sends it up. Representatives from every ten such groups then do the same. Etc..)
3. ?

This might be a good problem if someone is interested in learning more about profiling, and about controlling dask workers for work other than normal tasks.

[rbavery]

Currently running into this issue. The dashboard is failing with 16 workers that are trying to run an xarray.apply_ufunc on about 2000*1000 chunks (each is a time series at a pixel), and doesn't show any progress, going blank once I call persist(). All the dashboard tabs including Profile are blank.

This is my environment

INSTALLED VERSIONS
------------------
commit: None
python: 3.8.8 | packaged by conda-forge | (default, Feb 20 2021, 16:22:27) 
[GCC 9.3.0]
python-bits: 64
OS: Linux
OS-release: 5.4.0-1043-azure
machine: x86_64
processor: x86_64
byteorder: little
LC_ALL: None
LANG: en.UTF-8
LOCALE: en_US.UTF-8
libhdf5: 1.12.0
libnetcdf: 4.7.4

xarray: 0.17.0
pandas: 1.2.3
numpy: 1.20.1
scipy: 1.6.1
netCDF4: 1.5.6
pydap: None
h5netcdf: None
h5py: None
Nio: None
zarr: None
cftime: 1.4.1
nc_time_axis: None
PseudoNetCDF: None
rasterio: 1.2.1
cfgrib: None
iris: None
bottleneck: None
dask: 2021.03.0
distributed: 2021.03.0
matplotlib: 3.3.4
cartopy: None
seaborn: 0.11.1
numbagg: None
pint: None
setuptools: 49.6.0.post20210108
pip: 21.0.1
conda: None
pytest: None
IPython: 7.21.0
sphinx: None

[jacobtomlinson]

This issue still requires more info but there has been no activity here for many years, so I'm going to close it out.