[bug]: Continuous Python errors after start.

[Crono141]

Is there an existing issue for this problem?

• I have searched the existing issues

Operating system

Linux

GPU vendor

Nvidia (CUDA)

GPU model

3060

GPU VRAM

12gb

Version number

5.0.2

Browser

Brave (but doesn't matter for this bug)

Python dependencies

accelerate 0.30.1
compel 2.0.2
cuda 12.1
diffusers 0.27.2
numpy 1.26.4
opencv 4.9.0.80
onnx 1.15.0
pillow 10.4.0
python 3.10.14
torch 2.2.2+cu121
torchvision 0.17.2
transformers 4.41.1
xformers 0.0.25.post1

What happened

I am not sure when this issue started, or even if it is an issue, but when I start invoke 5.0.2 it has a continuous stream of python errors. I am not sure when it started because I didn't notice it until yesterday after I had an unrelated system crash. I have the error log attached. Apologies for its size, I started the log, and then was pulled away to something else.
error.log

It does not appear to affect the ability for InvokeAI web interface to function, and I was able to generate several images even while this string of errors continue to occur. It may be related to a recent nVidia driver update, but this may have been happening ever since 5.0 released. I am sorry that I cannot nail it down further.

What you expected to happen

No errors on launch

How to reproduce the problem

For me, just starting invoke.sh and choosing option 1 immediately causes the errors to start.

Additional context

I attempted to reinstall from the installer twice, the first time just running the installer, and the second time removing the .venv folder first. Neither helped.

Discord username

No response

[psychedelicious]

The error relates to the python logging module. It looks like the app is attempting to output some log messages, but the destination for the logs is borked.

Did you maybe specify an alternate logging method in the invokeai.yaml file? If not, it's trying to log to the console/terminal, in which case the error sounds like something's gone sideways with your system...

[Crono141]

Here is the contents of my invokeai.yaml

Internal metadata - do not edit:

schema_version: 4.0.2

Put user settings here - see https://invoke-ai.github.io/InvokeAI/features/CONFIGURATION/:

host: 0.0.0.0
port: 42422
ram: 8.0

log_handlers:

• console
• file=/home/master/invokeai/invokeai.log
• syslog=localhost

log_level: debug

I was logging, and the log file was 252mb in size. I deleted that file and restarted invokeai. I was still getting the same string of errors, and I stopped the process. A new invokeai.log file was created, which I've attached here.

[2024-10-06 11:00:39,476]::[InvokeAI]::INFO --> Patchmatch not loaded (nonfatal)
[2024-10-06 11:00:40,127]::[InvokeAI]::INFO --> Using torch device: NVIDIA GeForce RTX 3060
[2024-10-06 11:00:40,253]::[InvokeAI]::INFO --> cuDNN version: 8902
[2024-10-06 11:00:40,272]::[uvicorn.error]::INFO --> Started server process [1446991]
[2024-10-06 11:00:40,273]::[uvicorn.error]::INFO --> Waiting for application startup.
[2024-10-06 11:00:40,274]::[InvokeAI]::INFO --> InvokeAI version 5.0.2
[2024-10-06 11:00:40,277]::[InvokeAI]::INFO --> Root directory = /home/master/invokeai
[2024-10-06 11:00:40,277]::[InvokeAI]::INFO --> Initializing database at /home/master/invokeai/databases/invokeai.db
[2024-10-06 11:00:40,278]::[InvokeAI]::DEBUG --> Registered migration 0 -> 1
[2024-10-06 11:00:40,279]::[InvokeAI]::DEBUG --> Registered migration 1 -> 2
[2024-10-06 11:00:40,279]::[InvokeAI]::DEBUG --> Registered migration 2 -> 3
[2024-10-06 11:00:40,279]::[InvokeAI]::DEBUG --> Registered migration 3 -> 4
[2024-10-06 11:00:40,280]::[InvokeAI]::DEBUG --> Registered migration 4 -> 5
[2024-10-06 11:00:40,280]::[InvokeAI]::DEBUG --> Registered migration 5 -> 6
[2024-10-06 11:00:40,280]::[InvokeAI]::DEBUG --> Registered migration 6 -> 7
[2024-10-06 11:00:40,281]::[InvokeAI]::DEBUG --> Registered migration 7 -> 8
[2024-10-06 11:00:40,281]::[InvokeAI]::DEBUG --> Registered migration 8 -> 9
[2024-10-06 11:00:40,281]::[InvokeAI]::DEBUG --> Registered migration 9 -> 10
[2024-10-06 11:00:40,282]::[InvokeAI]::DEBUG --> Registered migration 10 -> 11
[2024-10-06 11:00:40,282]::[InvokeAI]::DEBUG --> Registered migration 11 -> 12
[2024-10-06 11:00:40,282]::[InvokeAI]::DEBUG --> Registered migration 12 -> 13
[2024-10-06 11:00:40,282]::[InvokeAI]::DEBUG --> Registered migration 13 -> 14
[2024-10-06 11:00:40,283]::[InvokeAI]::DEBUG --> Registered migration 14 -> 15
[2024-10-06 11:00:40,284]::[InvokeAI]::DEBUG --> Database is up to date, no migrations to run
[2024-10-06 11:00:40,287]::[ModelInstallService]::DEBUG --> Installer thread 139931414304448 starting
[2024-10-06 11:00:40,288]::[ModelInstallService]::DEBUG --> Installer thread 139931414304448 polling
[2024-10-06 11:00:40,313]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-2 (_download_next_item) starting.
[2024-10-06 11:00:40,314]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-3 (_download_next_item) starting.
[2024-10-06 11:00:40,314]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-4 (_download_next_item) starting.
[2024-10-06 11:00:40,315]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-5 (_download_next_item) starting.
[2024-10-06 11:00:40,315]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-6 (_download_next_item) starting.
[2024-10-06 11:00:40,363]::[InvokeAI]::INFO --> Pruned 174 finished queue items
[2024-10-06 11:00:40,365]::[InvokeAI]::DEBUG --> Waiting for next polling interval or event
[2024-10-06 11:00:40,539]::[InvokeAI]::INFO --> Cleaned database (freed 5.48MB)
[2024-10-06 11:00:40,540]::[uvicorn.error]::INFO --> Application startup complete.
[2024-10-06 11:00:40,540]::[uvicorn.error]::INFO --> Uvicorn running on http://0.0.0.0:42422 (Press CTRL+C to quit)
[2024-10-06 11:00:41,288]::[ModelInstallService]::DEBUG --> Installer thread 139931414304448 polling
[2024-10-06 11:00:41,367]::[InvokeAI]::DEBUG --> Waiting for next polling interval or event
[2024-10-06 11:00:42,289]::[ModelInstallService]::DEBUG --> Installer thread 139931414304448 polling
[2024-10-06 11:00:42,367]::[InvokeAI]::DEBUG --> Waiting for next polling interval or event
[2024-10-06 11:00:43,146]::[uvicorn.error]::INFO --> Shutting down
[2024-10-06 11:00:43,247]::[uvicorn.error]::INFO --> Waiting for application shutdown.
[2024-10-06 11:00:43,248]::[ModelInstallService]::DEBUG --> calling stop_event.set()
[2024-10-06 11:00:43,289]::[ModelInstallService]::INFO --> Installer thread 139931414304448 exiting
[2024-10-06 11:00:43,314]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-2 (_download_next_item) exiting.
[2024-10-06 11:00:43,315]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-3 (_download_next_item) exiting.
[2024-10-06 11:00:43,315]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-4 (_download_next_item) exiting.
[2024-10-06 11:00:43,315]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-5 (_download_next_item) exiting.
[2024-10-06 11:00:43,316]::[DownloadQueueService]::DEBUG --> Download queue worker thread Thread-6 (_download_next_item) exiting.
[2024-10-06 11:00:43,316]::[uvicorn.error]::INFO --> Application shutdown complete.
[2024-10-06 11:00:43,317]::[uvicorn.error]::INFO --> Finished server process [1446991]

The "going sideways with my system" is what I'm worried about. If that is the case, any clue where I should start looking?

[psychedelicious]

My guess is a problem with the system API with which SysLogHandler interacts. Does commenting out the logging config fix it?

You could write a simple python script outside the Invoke venv with that same SysLogHandler (per python docs) to see if the issue occurs only in the context of Invoke or if it's truly a system issue. Not sure where to go from there, sorry!

[Crono141]

OK, I commented out all the logging lines:

log_handlers:
  - console
  - file=/home/master/invokeai/invokeai.log
  - syslog=localhost

And was still getting all the errors. Then I commented this last one:

log_level: debug

And that seemed to solve it. Hopefully this isn't indicative of something borked in my system, though if it is it might be a good opportunity to switch my server backend to a different flavor of nix.

[psychedelicious]

The messages you pasted in this comment are not errors. Those messages are expected when you set the log level to debug.

The attached log in the first post of this issue have actual errors. Sounds like you've got taht sorted now.

If you are seeing no errors/exceptions, I think everything is fine. Sorry for any misunderstanding.