IndexError: deque index out of range in app/logger.py when tqdm writes \r before any log line exists
- Dominant language
- Python
- Stars
- 133k
- Forks
- 15.7k
- Avg merge
- 1d 6h
- Merged PRs (30d)
- 155
Description
### Custom Node Testing
- [x] I have tried disabling custom nodes and the issue persists (see [how to disable custom nodes](https://docs.comfy.org/troubleshooting/custom-node-issues#step-1%3A-test-with-all-custom-nodes-disabled) if you need help)
### Expected Behavior
Queuing a prompt should run sampling normally and produce an output image, regardless of log verbosity level or which sampler variant (CPU vs GPU noise) is used.
### Actual Behavior
Shortly after starting the server (cold model load), queuing a prompt sometimes crashes with `IndexError: deque index out of range` inside `app/logger.py`, instead of completing the generation. The crash happens inside the `KSampler` node's progress-bar callback, not in the actual sampling math.
### Steps to Reproduce
1. Start ComfyUI fresh (service restart / cold model load), with default or low `--verbose` level (e.g. `WARNING`).
2. Queue a prompt using a GGUF UNet loader (`UnetLoaderGGUF`) + LoRA + `KSampler` with `sampler_name: dpmpp_sde` (or `dpmpp_sde_gpu`).
3. On the very first generation after startup, the prompt fails with the `IndexError` above instead of producing an image.
4. Queuing the same or a different prompt again immediately afterward succeeds.
### Debug Logs
```powershell
ago 08 00:39:00 orion systemd[1]: Started comfyui.service - ComfyUI - backend image generation.
ago 08 00:39:50 orion python[230885]: [ERROR] !!! Exception during processing !!! deque index out of range
ago 08 00:39:50 orion python[230885]: [ERROR] Traceback (most recent call last):
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/execution.py", line 545, in execute
ago 08 00:39:50 orion python[230885]: output_data, output_ui, has_subgraph, has_pending_tasks = await get_output_data(prompt_id, unique_id, obj, input_data_all, execution_block_cb=execution_block_cb, pre_execute_cb=pre_execute_cb, v3_data=v3_data)
ago 08 00:39:50 orion python[230885]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/execution.py", line 344, in get_output_data
ago 08 00:39:50 orion python[230885]: return_values = await _async_map_node_over_list(prompt_id, unique_id, obj, input_data_all, obj.FUNCTION, allow_interrupt=True, execution_block_cb=execution_block_cb, pre_execute_cb=pre_execute_cb, v3_data=v3_data)
ago 08 00:39:50 orion python[230885]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/execution.py", line 318, in _async_map_node_over_list
ago 08 00:39:50 orion python[230885]: await process_inputs(input_dict, i)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/execution.py", line 306, in process_inputs
ago 08 00:39:50 orion python[230885]: result = f(**inputs)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/nodes.py", line 1616, in sample
ago 08 00:39:50 orion python[230885]: return common_ksampler(model, seed, steps, cfg, sampler_name, scheduler, positive, negative, latent_image, denoise=denoise)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/nodes.py", line 1580, in common_ksampler
ago 08 00:39:50 orion python[230885]: samples = comfy.sample.sample(model, noise, steps, cfg, sampler_name, scheduler, positive, negative, latent_image,
ago 08 00:39:50 orion python[230885]: denoise=denoise, disable_noise=disable_noise, start_step=start_step, last_step=last_step,
ago 08 00:39:50 orion python[230885]: force_full_denoise=force_full_denoise, noise_mask=noise_mask, callback=callback, disable_pbar=disable_pbar, seed=seed)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/sample.py", line 74, in sample
ago 08 00:39:50 orion python[230885]: samples = sampler.sample(noise, positive, negative, cfg=cfg, latent_image=latent_image, start_step=start_step, last_step=last_step, force_full_denoise=force_full_denoise, denoise_mask=noise_mask, sigmas=sigmas, callback=callback, disable_pbar=disable_pbar, seed=seed)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1463, in sample
ago 08 00:39:50 orion python[230885]: return sample(self.model, noise, positive, negative, cfg, self.device, sampler, sigmas, self.model_options, latent_image=latent_image, denoise_mask=denoise_mask, callback=callback, disable_pbar=disable_pbar, seed=seed)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1353, in sample
ago 08 00:39:50 orion python[230885]: return cfg_guider.sample(noise, latent_image, sampler, sigmas, denoise_mask, callback, disable_pbar, seed)
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1335, in sample
ago 08 00:39:50 orion python[230885]: output = executor.execute(noise, latent_image, sampler, sigmas, denoise_mask, callback, disable_pbar, seed, latent_shapes=latent_shapes)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/patcher_extension.py", line 113, in execute
ago 08 00:39:50 orion python[230885]: return self.original(*args, **kwargs)
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1262, in outer_sample
ago 08 00:39:50 orion python[230885]: output = self.inner_sample(noise, latent_image, device, sampler, sigmas, denoise_mask, callback, disable_pbar, seed, latent_shapes=latent_shapes)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1237, in inner_sample
ago 08 00:39:50 orion python[230885]: samples = executor.execute(self, sigmas, extra_args, callback, noise, latent_image, denoise_mask, disable_pbar)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/patcher_extension.py", line 113, in execute
ago 08 00:39:50 orion python[230885]: return self.original(*args, **kwargs)
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/samplers.py", line 1005, in sample
ago 08 00:39:50 orion python[230885]: samples = self.sampler_function(model_k, noise, sigmas, extra_args=extra_args, callback=k_callback, disable=disable_pbar, **self.extra_options)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/torch/utils/_contextlib.py", line 124, in decorate_context
ago 08 00:39:50 orion python[230885]: return func(*args, **kwargs)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/k_diffusion/sampling.py", line 981, in sample_dpmpp_sde_gpu
ago 08 00:39:50 orion python[230885]: return sample_dpmpp_sde(model, x, sigmas, extra_args=extra_args, callback=callback, disable=disable, eta=eta, s_noise=s_noise, noise_sampler=noise_sampler, r=r)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/torch/utils/_contextlib.py", line 124, in decorate_context
ago 08 00:39:50 orion python[230885]: return func(*args, **kwargs)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/k_diffusion/sampling.py", line 755, in sample_dpmpp_sde
ago 08 00:39:50 orion python[230885]: for i in trange(len(sigmas) - 1, disable=disable):
ago 08 00:39:50 orion python[230885]: ~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/comfy/utils.py", line 1232, in model_trange
ago 08 00:39:50 orion python[230885]: pbar = trange(*args, **kwargs, smoothing=1.0)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/auto.py", line 37, in trange
ago 08 00:39:50 orion python[230885]: return tqdm(range(*args), **kwargs)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/asyncio.py", line 24, in __init__
ago 08 00:39:50 orion python[230885]: super().__init__(iterable, *args, **kwargs)
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/std.py", line 1103, in __init__
ago 08 00:39:50 orion python[230885]: self.refresh(lock_args=self.lock_args)
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/std.py", line 1355, in refresh
ago 08 00:39:50 orion python[230885]: self.display()
ago 08 00:39:50 orion python[230885]: ~~~~~~~~~~~~^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/std.py", line 1503, in display
ago 08 00:39:50 orion python[230885]: self.sp(self.__str__() if msg is None else msg)
ago 08 00:39:50 orion python[230885]: ~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/std.py", line 457, in print_status
ago 08 00:39:50 orion python[230885]: fp_write('\r' + s + (' ' * max(last_len[0] - len_s, 0)))
ago 08 00:39:50 orion python[230885]: ~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/std.py", line 450, in fp_write
ago 08 00:39:50 orion python[230885]: fp.write(str(s))
ago 08 00:39:50 orion python[230885]: ~~~~~~~~^^^^^^^^
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/venv/lib/python3.13/site-packages/tqdm/utils.py", line 179, in inner
ago 08 00:39:50 orion python[230885]: return func(*args, **kwargs)
ago 08 00:39:50 orion python[230885]: File "/opt/comfyui/comfyui/app/logger.py", line 67, in write
ago 08 00:39:50 orion python[230885]: if isinstance(data, str) and data.startswith("\r") and not logs[-1]["m"].endswith("\n"):
ago 08 00:39:50 orion python[230885]: ~~~~^^^^
ago 08 00:39:50 orion python[230885]: IndexError: deque index out of range
ago 08 00:40:25 orion python[230885]: [275B blob data]
ago 08 00:40:25 orion python[230885]: warnings.warn(f"Should have {tb_name}<=t1 but got {tb_name}={tb} and t1={self._end}.")
ago 08 00:40:33 orion python[230885]: [497B blob data]
```
### Other
### Root Cause
`app/logger.py`'s stdout-capturing `write()` method assumes the internal `logs` deque always has at least one entry:
```python
if isinstance(data, str) and data.startswith("\r") and not logs[-1]["m"].endswith("\n"):
```
When `tqdm` emits a carriage-return progress update (`\r`) via `trange`/`model_trange` at a moment when `logs` is still empty — e.g. immediately after startup or a cold model load, before any regular log line has been appended — `logs[-1]` raises `IndexError` because there is nothing at index `-1`.
This is a race/edge-case condition, not something caused by the workflow itself. In my testing:
- It reproduces reliably on the first generation after a service restart when using a GGUF-quantized UNet (cold load path triggers more stdout/log activity right as sampling starts).
- Switching `--verbose` from `WARNING` to `INFO` makes it effectively stop reproducing, because far more regular log lines are written, so `logs` is almost never empty when a `\r` arrives — this reduces the race window but does not fix it.
- Switching sampler between `dpmpp_sde` (CPU noise, more CPU/GPU sync points) and `dpmpp_sde_gpu` (GPU noise) changes timing slightly but did not reliably prevent the crash either.
None of the above are true fixes — they only change the timing of when `\r` writes happen relative to `logs` being populated, so the underlying race is still present and can resurface (larger models, slower disk, additional custom nodes logging at startup, verbosity turned back down, etc.).
### Suggested Fix
Guard against an empty deque before indexing it:
```python
# app/logger.py, in write()
if isinstance(data, str) and data.startswith("\r") and logs and not logs[-1]["m"].endswith("\n"):
```
This is a minimal, low-risk one-line change that removes the race entirely without altering logging behavior otherwise.
### Environment
- ComfyUI: installed via `git clone` (not portable build)
- OS: Linux (Debian-based)
- Python: 3.13
- GPU: NVIDIA RTX A2000 12GB
- Install method: manual venv, custom systemd service
- Relevant custom nodes: ComfyUI-GGUF (`UnetLoaderGGUF`)
- Workflow: SDXL UNet (GGUF, Q4_0), dual CLIP loader (fp8), LoRA (SDXL Lightning 4-step), `KSampler` with `dpmpp_sde` / `dpmpp_sde_gpu`, `karras` scheduler
Contributor guide
Research direction
Start in app/logger.py at the stdout-capturing write() method and inspect how its logs deque is used when tqdm emits a carriage return. Trace the call path through comfy/utils.py model_trange and reproduce the first-generation cold-load workflow. Done means the initial prompt completes without an IndexError and subsequent progress output still works.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python, pytorch
- Domain
- backend, observability
- Issue type
- Bug
- Difficulty
- 2/5
- Estimated time
- 1-3 hours
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 76/100