search

Donkie / Spoolman

Keep track of your inventory of 3D-printer filament spools.
MIT License
892 stars 82 forks source link

Spoolman keeps restarting #184

Closed srbjessen closed 10 months ago

srbjessen commented 10 months ago

Hi ... again....

My spoolman service keeps restarting. causing moonraker to shut down as well and Mainsail to lose connection.

result of journalctl --user -u Spoolman Nov 02 08:52:14 BTT-CB1 systemd[1664]: Stopped Spoolman. Nov 02 08:52:14 BTT-CB1 systemd[1664]: Spoolman.service: Consumed 16.464s CPU time. Nov 02 08:59:40 BTT-CB1 systemd[3673]: Started Spoolman. Nov 02 08:59:41 BTT-CB1 start.sh[3688]: WARNING: /home/biqu/.local/bin is not in PATH, this will make it difficult to run PDM commands. Temporarily adding /home/biqu/.local/bin to PATH> Nov 02 08:59:41 BTT-CB1 start.sh[3688]: To make this permanent, add the following line to your .bashrc or .zshrc file: Nov 02 08:59:41 BTT-CB1 start.sh[3688]: export PATH=/home/biqu/.local/bin:$PATH Nov 02 08:59:41 BTT-CB1 start.sh[3688]: Starting Spoolman... Nov 02 08:59:50 BTT-CB1 start.sh[3835]: INFO: Started server process [3835] Nov 02 08:59:50 BTT-CB1 start.sh[3835]: INFO: Waiting for application startup. Nov 02 08:59:50 BTT-CB1 start.sh[3835]: spoolman.main INFO Starting Spoolman v0.13.1 (commit: None) (built: None) Nov 02 08:59:50 BTT-CB1 start.sh[3835]: spoolman.main INFO Setting up database... Nov 02 08:59:50 BTT-CB1 start.sh[3835]: spoolman.database.database INFO No database type specified, using a default SQLite database located at "/home/biqu/.local/share/spoolman/spo> Nov 02 08:59:50 BTT-CB1 start.sh[3835]: spoolman.main INFO Performing migrations... Nov 02 08:59:54 BTT-CB1 start.sh[3852]: alembic.runtime.migration INFO Context impl SQLiteImpl. Nov 02 08:59:54 BTT-CB1 start.sh[3852]: alembic.runtime.migration INFO Will assume non-transactional DDL. Nov 02 08:59:54 BTT-CB1 start.sh[3835]: spoolman.database.database INFO Scheduling automatic database backup for midnight. Nov 02 08:59:54 BTT-CB1 start.sh[3835]: spoolman.main INFO Startup complete. Nov 02 08:59:54 BTT-CB1 start.sh[3835]: INFO: Application startup complete. Nov 02 08:59:54 BTT-CB1 start.sh[3835]: INFO: Uvicorn running on http://0.0.0.0:7912 (Press CTRL+C to quit) Nov 02 09:00:24 BTT-CB1 start.sh[3835]: INFO: 192.168.1.161:58040 - "GET /info HTTP/1.1" 200 OK Nov 02 09:00:24 BTT-CB1 start.sh[3835]: INFO: 192.168.1.161:58044 - "GET /health HTTP/1.1" 200 OK Nov 02 09:00:24 BTT-CB1 start.sh[3835]: INFO: 192.168.1.161:58042 - "GET /vendor HTTP/1.1" 200 OK Nov 02 09:00:24 BTT-CB1 start.sh[3835]: INFO: 192.168.1.161:58046 - "GET /spool/52 HTTP/1.1" 200 OK Nov 02 09:00:26 BTT-CB1 start.sh[3835]: INFO: 192.168.1.161:58048 - "GET /spool HTTP/1.1" 200 OK Nov 02 09:00:27 BTT-CB1 start.sh[3835]: INFO: 192.168.1.141:50493 - "GET /spool HTTP/1.1" 304 Not Modified Nov 02 09:00:27 BTT-CB1 start.sh[3835]: INFO: 192.168.1.141:50493 - "GET /info HTTP/1.1" 200 OK Nov 02 09:00:27 BTT-CB1 start.sh[3835]: INFO: 192.168.1.141:50493 - "GET /info HTTP/1.1" 200 OK Nov 02 09:00:28 BTT-CB1 start.sh[3835]: INFO: 192.168.1.141:50493 - "GET /spool?allow_archived=false HTTP/1.1" 200 OK Nov 02 09:00:28 BTT-CB1 start.sh[3835]: INFO: ('192.168.1.141', 50495) - "WebSocket /spool" [accepted] Nov 02 09:00:28 BTT-CB1 start.sh[3835]: spoolman.ws INFO Client 192.168.1.141 is now listening on pool spool Nov 02 09:00:28 BTT-CB1 start.sh[3835]: INFO: connection open Nov 02 09:00:28 BTT-CB1 start.sh[3835]: INFO: 192.168.1.141:50494 - "GET /spool?allow_archived=false&limit=100&offset=0&sort=id:desc HTTP/1.1" 200 OK Nov 02 09:01:25 BTT-CB1 systemd[3673]: Stopping Spoolman... Nov 02 09:01:25 BTT-CB1 start.sh[3835]: INFO: Shutting down Nov 02 09:01:25 BTT-CB1 start.sh[3835]: spoolman.ws INFO Client 192.168.1.141 has stopped listening on pool spool Nov 02 09:01:25 BTT-CB1 start.sh[3835]: INFO: connection closed Nov 02 09:01:25 BTT-CB1 start.sh[3835]: INFO: Waiting for application shutdown. Nov 02 09:01:25 BTT-CB1 start.sh[3835]: INFO: Application shutdown complete. Nov 02 09:01:25 BTT-CB1 start.sh[3835]: INFO: Finished server process [3835] Nov 02 09:01:27 BTT-CB1 systemd[3673]: Spoolman.service: Succeeded. Nov 02 09:01:27 BTT-CB1 systemd[3673]: Stopped Spoolman. and then it just repeats every few minutes.

Donkie commented 10 months ago

Did you solve your problem? :)

srbjessen commented 10 months ago

No, but it seems to be more of a moonraker issue, as both mainsail and spoolman loses connection simultaneously. though it still seems like systemd is shutting down spoolman, but i'm not yet qualified to research it. Google will be busy the next few days :-D

srbjessen commented 10 months ago

Hmm, I don't know whats going on, yesterday i did a fresh install of everything, and it's still the same. For some reason it takes spoolman 4 minutes to start, just to have systemd eventually shut it down and restart. each time it shuts down, mainsail also disconnects, but printing continues. So I'm guessing it's not moonraker?

Here's "journalctl" content: Nov 03 09:46:37 BTT-CB1 systemd[1601]: Started Spoolman. Nov 03 09:46:38 BTT-CB1 start.sh[1647]: WARNING: /home/biqu/.local/bin is not in PATH, this will make it difficult to run PDM commands. Temporarily adding /home/biqu/.local/bin to PATH... Nov 03 09:46:38 BTT-CB1 start.sh[1647]: To make this permanent, add the following line to your .bashrc or .zshrc file: Nov 03 09:46:38 BTT-CB1 start.sh[1647]: export PATH=/home/biqu/.local/bin:$PATH Nov 03 09:46:38 BTT-CB1 start.sh[1647]: Starting Spoolman... Nov 03 09:50:37 BTT-CB1 start.sh[2166]: INFO: Started server process [2166] Nov 03 09:50:37 BTT-CB1 start.sh[2166]: INFO: Waiting for application startup. Nov 03 09:50:37 BTT-CB1 start.sh[2166]: spoolman.main INFO Starting Spoolman v0.13.1 (commit: None) (built: None) Nov 03 09:50:37 BTT-CB1 start.sh[2166]: spoolman.main INFO Setting up database... Nov 03 09:50:37 BTT-CB1 start.sh[2166]: spoolman.database.database INFO No database type specified, using a default SQLite database located at "/home/biqu/.local/share/spoolman/spoolman.db" Nov 03 09:50:39 BTT-CB1 start.sh[2166]: spoolman.main INFO Performing migrations... Nov 03 09:51:19 BTT-CB1 start.sh[2584]: alembic.runtime.migration INFO Context impl SQLiteImpl. Nov 03 09:51:19 BTT-CB1 start.sh[2584]: alembic.runtime.migration INFO Will assume non-transactional DDL. Nov 03 09:51:26 BTT-CB1 start.sh[2166]: spoolman.database.database INFO Scheduling automatic database backup for midnight. Nov 03 09:51:26 BTT-CB1 start.sh[2166]: spoolman.main INFO Startup complete. Nov 03 09:51:26 BTT-CB1 start.sh[2166]: INFO: Application startup complete. Nov 03 09:51:26 BTT-CB1 start.sh[2166]: INFO: Uvicorn running on http://0.0.0.0:7912 (Press CTRL+C to quit)

srbjessen commented 10 months ago

Does 'systemd' shut down porcesses if cpu is overloaded? Just noticed 'klipper_mcu' was using close to 100% cpu according to 'top' Maybe that's what's been screwing me...

srbjessen commented 10 months ago

I've reopened, it definitely seems it's specifically Spoolman being closed, but I've yet to understand why.

Nov 03 12:01:08 BTT-CB1 start.sh[13876]: INFO:     connection open
Nov 03 12:01:08 BTT-CB1 start.sh[13876]: INFO:     ('192.168.1.141', 60820) - "WebSocket /spool/49" [accepted]
Nov 03 12:01:08 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,49
Nov 03 12:01:08 BTT-CB1 start.sh[13876]: INFO:     connection open
Nov 03 12:01:21 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50534 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:01:34 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50536 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:01:51 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50538 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:02:04 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50540 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:02:21 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50542 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:02:34 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50544 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:02:51 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50546 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:03:06 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50548 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:03:21 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50550 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:03:36 BTT-CB1 start.sh[13876]: INFO:     192.168.1.161:50552 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:03:48 BTT-CB1 systemd[13714]: Stopping Spoolman...
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     Shutting down
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,6
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,41
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,9
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,49
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,42
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,34
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,52
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,40
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,47
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,11
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,14
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,30
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,43
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,50
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,37
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,45
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,39
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,18
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,23
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,38
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,53
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,25
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,15
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,31
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,51
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,3
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,5
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,16
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,55
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,10
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,8
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,27
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,24
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,22
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,32
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,29
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,20
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,13
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,48
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,36
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,12
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,2
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,21
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,19
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,44
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,56
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,33
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,17
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,1
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,7
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,26
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,46
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,35
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,28
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: spoolman.ws                INFO     Client 192.168.1.141 has stopped listening on pool spool,54
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     connection closed
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     Waiting for application shutdown.
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     Application shutdown complete.
Nov 03 12:03:48 BTT-CB1 start.sh[13876]: INFO:     Finished server process [13876]
Nov 03 12:03:49 BTT-CB1 systemd[13714]: Spoolman.service: Succeeded.
Nov 03 12:03:49 BTT-CB1 systemd[13714]: Stopped Spoolman.
Nov 03 12:03:49 BTT-CB1 systemd[13714]: Spoolman.service: Consumed 38.018s CPU time.
Nov 03 12:10:04 BTT-CB1 systemd[19491]: Started Spoolman.
Nov 03 12:10:04 BTT-CB1 start.sh[19506]: WARNING: /home/biqu/.local/bin is not in PATH, this will make it difficult to run PDM commands. Temporarily adding /home/biqu/.local/bin to PATH...
Nov 03 12:10:04 BTT-CB1 start.sh[19506]: To make this permanent, add the following line to your .bashrc or .zshrc file:
Nov 03 12:10:04 BTT-CB1 start.sh[19506]: export PATH=/home/biqu/.local/bin:$PATH
Nov 03 12:10:04 BTT-CB1 start.sh[19506]: Starting Spoolman...
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: INFO:     Started server process [19655]
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: INFO:     Waiting for application startup.
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: spoolman.main              INFO     Starting Spoolman v0.13.1 (commit: None) (built: None)
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: spoolman.main              INFO     Setting up database...
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: spoolman.database.database INFO     No database type specified, using a default SQLite database located at "/home/biqu/.local/share/spoolman/spoolman.db"
Nov 03 12:10:14 BTT-CB1 start.sh[19655]: spoolman.main              INFO     Performing migrations...
Nov 03 12:10:17 BTT-CB1 start.sh[19670]: alembic.runtime.migration  INFO     Context impl SQLiteImpl.
Nov 03 12:10:17 BTT-CB1 start.sh[19670]: alembic.runtime.migration  INFO     Will assume non-transactional DDL.
Nov 03 12:10:18 BTT-CB1 start.sh[19655]: spoolman.database.database INFO     Scheduling automatic database backup for midnight.
Nov 03 12:10:18 BTT-CB1 start.sh[19655]: spoolman.main              INFO     Startup complete.
Nov 03 12:10:18 BTT-CB1 start.sh[19655]: INFO:     Application startup complete.
Nov 03 12:10:18 BTT-CB1 start.sh[19655]: INFO:     Uvicorn running on http://0.0.0.0:7912 (Press CTRL+C to quit)
Nov 03 12:10:25 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50698 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:10:36 BTT-CB1 start.sh[19655]: INFO:     192.168.1.141:61106 - "GET /spool HTTP/1.1" 200 OK
Nov 03 12:10:36 BTT-CB1 start.sh[19655]: INFO:     192.168.1.141:61106 - "GET /info HTTP/1.1" 200 OK
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     192.168.1.141:61106 - "GET /info HTTP/1.1" 200 OK
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61108) - "WebSocket /spool" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     192.168.1.141:61106 - "GET /spool?allow_archived=false HTTP/1.1" 200 OK
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     192.168.1.141:61107 - "GET /spool?allow_archived=false&limit=100&offset=0&sort=id:asc HTTP/1.1" 200 OK
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61112) - "WebSocket /spool/1" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,1
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61113) - "WebSocket /spool/2" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,2
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61114) - "WebSocket /spool/3" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,3
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61115) - "WebSocket /spool/5" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,5
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61116) - "WebSocket /spool/6" [accepted]
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,6
Nov 03 12:10:37 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61118) - "WebSocket /spool/7" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,7
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61119) - "WebSocket /spool/8" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,8
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61120) - "WebSocket /spool/9" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,9
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61121) - "WebSocket /spool/10" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,10
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61122) - "WebSocket /spool/11" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,11
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50700 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50702 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61123) - "WebSocket /spool/12" [accepted]
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,12
Nov 03 12:10:38 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:10:55 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50704 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:10:58 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61131) - "WebSocket /spool/14" [accepted]
Nov 03 12:10:58 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,14
Nov 03 12:10:58 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:03 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50706 - "GET /info HTTP/1.1" 200 OK
Nov 03 12:11:03 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50708 - "GET /health HTTP/1.1" 200 OK
Nov 03 12:11:03 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50710 - "GET /vendor HTTP/1.1" 200 OK
Nov 03 12:11:03 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50712 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:11:04 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50714 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:11:04 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50716 - "GET /spool HTTP/1.1" 200 OK
Nov 03 12:11:13 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50718 - "GET /spool/32 HTTP/1.1" 200 OK
Nov 03 12:11:25 BTT-CB1 start.sh[19655]: INFO:     192.168.1.161:50720 - "PUT /spool/32/use HTTP/1.1" 200 OK
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61167) - "WebSocket /spool/47" [accepted]
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,47
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61173) - "WebSocket /spool/28" [accepted]
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,28
Nov 03 12:11:27 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:31 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61174) - "WebSocket /spool/16" [accepted]
Nov 03 12:11:31 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,16
Nov 03 12:11:31 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61175) - "WebSocket /spool/20" [accepted]
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,20
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61176) - "WebSocket /spool/27" [accepted]
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,27
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61177) - "WebSocket /spool/24" [accepted]
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,24
Nov 03 12:11:32 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61178) - "WebSocket /spool/35" [accepted]
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,35
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: INFO:     connection open
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: INFO:     ('192.168.1.141', 61180) - "WebSocket /spool/32" [accepted]
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: spoolman.ws                INFO     Client 192.168.1.141 is now listening on pool spool,32
Nov 03 12:11:33 BTT-CB1 start.sh[19655]: INFO:     connection open
srbjessen commented 10 months ago

Content of moonraker service. "12.09.55" seems to say something, but not sure....

Nov 03 12:09:42 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 3.83ms Nov 03 12:09:42 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472762730672, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:09:42 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472762730672 Client Identified - Name: mainsail, Version: 2.8.0, Type: web Nov 03 12:09:43 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/health Nov 03 12:09:43 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/info Nov 03 12:09:43 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/vendor Nov 03 12:09:43 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:09:44 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:09:45 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472762730672 Close Code: 1001, Close Reason: None, Pong Time Elapsed: 2.92 Nov 03 12:09:45 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472762731392 Close Code: 1001, Close Reason: None, Pong Time Elapsed: 3.68 Nov 03 12:09:45 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 7.27ms Nov 03 12:09:45 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472780923040, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:09:45 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472780923040 Client Identified - Name: OctoEverywhere-BrowserAgent, Version: 1.0.0, Type: web Nov 03 12:09:46 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 4.12ms Nov 03 12:09:46 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472780908672, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:09:46 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472780908672 Client Identified - Name: mainsail, Version: 2.8.0, Type: web Nov 03 12:09:47 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/info Nov 03 12:09:47 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/health Nov 03 12:09:47 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/vendor Nov 03 12:09:47 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:09:47 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:09:55 BTT-CB1 python[827]: [eventloop.py:_wrapper()] - Error Running Callback Nov 03 12:09:55 BTT-CB1 python[827]: Traceback (most recent call last): Nov 03 12:09:55 BTT-CB1 python[827]: File "/home/biqu/moonraker/moonraker/components/http_client.py", line 115, in request Nov 03 12:09:55 BTT-CB1 python[827]: resp = await asyncio.wait_for(fut, timeout) Nov 03 12:09:55 BTT-CB1 python[827]: File "/usr/lib/python3.9/asyncio/tasks.py", line 481, in wait_for Nov 03 12:09:55 BTT-CB1 python[827]: return fut.result() Nov 03 12:09:55 BTT-CB1 python[827]: ConnectionRefusedError: [Errno 111] Connection refused Nov 03 12:09:55 BTT-CB1 python[827]: The above exception was the direct cause of the following exception: Nov 03 12:09:55 BTT-CB1 python[827]: Traceback (most recent call last): Nov 03 12:09:55 BTT-CB1 python[827]: File "/home/biqu/moonraker/moonraker/eventloop.py", line 84, in _wrapper Nov 03 12:09:55 BTT-CB1 python[827]: await ret Nov 03 12:09:55 BTT-CB1 python[827]: File "/home/biqu/moonraker/moonraker/components/spoolman.py", line 107, in _handle_status_update Nov 03 12:09:55 BTT-CB1 python[827]: await self.track_filament_usage() Nov 03 12:09:55 BTT-CB1 python[827]: File "/home/biqu/moonraker/moonraker/components/spoolman.py", line 150, in track_filament_usage Nov 03 12:09:55 BTT-CB1 python[827]: response.raise_for_status() Nov 03 12:09:55 BTT-CB1 python[827]: File "/home/biqu/moonraker/moonraker/components/http_client.py", line 363, in raise_for_status Nov 03 12:09:55 BTT-CB1 python[827]: raise ServerError(msg, code) from self._error Nov 03 12:09:55 BTT-CB1 python[827]: moonraker.utils.ServerError: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32/use Nov 03 12:10:04 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:10:04 BTT-CB1 python[827]: [common.py:build_error()] - JSON-RPC Request Error - Requested Method: server.spoolman.proxy, Code: 500, Message: HTTP Request Error: http://192.168.1.161:7912/api/v1/spool/32 Nov 03 12:10:59 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472762852208 Close Code: 1001, Close Reason: None, Pong Time Elapsed: 9.91 Nov 03 12:11:00 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472780533088 Close Code: None, Close Reason: None, Pong Time Elapsed: 10.70 Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472780923040 Close Code: 1001, Close Reason: None, Pong Time Elapsed: 6.15 Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472780908672 Close Code: 1001, Close Reason: None, Pong Time Elapsed: 5.64 Nov 03 12:11:02 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 8.32ms Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472762731872, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472762731872 Client Identified - Name: OctoEverywhere-BrowserAgent, Version: 1.0.0, Type: web Nov 03 12:11:02 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 3.96ms Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472780531312, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:11:02 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472780531312 Client Identified - Name: mainsail, Version: 2.8.0, Type: web Nov 03 12:12:41 BTT-CB1 python[827]: [app.py:log_request()] - 101 GET /websocket (192.168.1.141) [_TRUSTEDUSER] 4.81ms Nov 03 12:12:41 BTT-CB1 python[827]: [websockets.py:open()] - Websocket Opened: ID: 281472781321408, Proxied: True, User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/5> Nov 03 12:12:41 BTT-CB1 python[827]: [websockets.py:_handle_identify()] - Websocket 281472781321408 Client Identified - Name: OctoEverywhere-BrowserAgent, Version: 1.0.0, Type: web Nov 03 12:12:52 BTT-CB1 python[827]: [websockets.py:write_to_socket()] - Websocket closed while writing: 281472762731872 Nov 03 12:12:57 BTT-CB1 python[827]: [websockets.py:on_close()] - Websocket Closed: ID: 281472762731872 Close Code: None, Close Reason: None, Pong Time Elapsed: 45.00

claudermilk commented 10 months ago

I'm trying to run spoolman from a docker container on a separate server (my Plex server, which runs Debian--the Alpine-based Home Assistant one wouldn't even run the install command). It's stuck with status of restart and cycles about every minute. Grabbing logs I see this error repeating: Traceback (most recent call last): spoolman-spoolman-1 | File "/home/app/spoolman/.venv/bin/uvicorn", line 5, in spoolman-spoolman-1 | from uvicorn.main import main spoolman-spoolman-1 | File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/init.py", line 1, in spoolman-spoolman-1 | from uvicorn.config import Config spoolman-spoolman-1 | File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/config.py", line 1, in spoolman-spoolman-1 | import asyncio spoolman-spoolman-1 | File "/usr/local/lib/python3.11/asyncio/init.py", line 8, in spoolman-spoolman-1 | from .base_events import * spoolman-spoolman-1 | File "/usr/local/lib/python3.11/asyncio/base_events.py", line 18, in spoolman-spoolman-1 | import concurrent.futures spoolman-spoolman-1 | File "/usr/local/lib/python3.11/concurrent/futures/init.py", line 8, in spoolman-spoolman-1 | from concurrent.futures._base import (FIRST_COMPLETED, spoolman-spoolman-1 | File "/usr/local/lib/python3.11/concurrent/futures/_base.py", line 7, in spoolman-spoolman-1 | import logging spoolman-spoolman-1 | File "/usr/local/lib/python3.11/logging/init.py", line 58, in spoolman-spoolman-1 | _startTime = time.time() spoolman-spoolman-1 | ^^^^^^^^^^^ spoolman-spoolman-1 | PermissionError: [Errno 1] Operation not permitted

I thought maybe it didn't like me switching the TZ, so I commented that out but it had no effect.

Donkie commented 10 months ago

I'm trying to run spoolman from a docker container on a separate server (my Plex server, which runs Debian--the Alpine-based Home Assistant one wouldn't even run the install command). It's stuck with status of restart and cycles about every minute. Grabbing logs I see this error repeating: Traceback (most recent call last): spoolman-spoolman-1 | File "/home/app/spoolman/.venv/bin/uvicorn", line 5, in spoolman-spoolman-1 | from uvicorn.main import main spoolman-spoolman-1 | File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/init.py", line 1, in spoolman-spoolman-1 | from uvicorn.config import Config spoolman-spoolman-1 | File "/home/app/spoolman/.venv/lib/python3.11/site-packages/uvicorn/config.py", line 1, in spoolman-spoolman-1 | import asyncio spoolman-spoolman-1 | File "/usr/local/lib/python3.11/asyncio/init.py", line 8, in spoolman-spoolman-1 | from .base_events import * spoolman-spoolman-1 | File "/usr/local/lib/python3.11/asyncio/base_events.py", line 18, in spoolman-spoolman-1 | import concurrent.futures spoolman-spoolman-1 | File "/usr/local/lib/python3.11/concurrent/futures/init.py", line 8, in spoolman-spoolman-1 | from concurrent.futures._base import (FIRST_COMPLETED, spoolman-spoolman-1 | File "/usr/local/lib/python3.11/concurrent/futures/_base.py", line 7, in spoolman-spoolman-1 | import logging spoolman-spoolman-1 | File "/usr/local/lib/python3.11/logging/init.py", line 58, in spoolman-spoolman-1 | _startTime = time.time() spoolman-spoolman-1 | ^^^^^^^^^^^ spoolman-spoolman-1 | PermissionError: [Errno 1] Operation not permitted

I thought maybe it didn't like me switching the TZ, so I commented that out but it had no effect.

Please don't hijack another person's issue. Regarding your issue, this is a known python/docker issue. Not a problem with Spoolman. See e.g. https://stackoverflow.com/a/72719088

Donkie commented 10 months ago

@srbjessen I'm clueless as to what could be the issue here. None of the logs you sent would suggest any issue in Spoolman. Systemd seemingly just want to shut Spoolman off. Maybe you could try a docker installation instead? It doesn't use systemd at all.

srbjessen commented 10 months ago

Yeah, I'm also totally lost. Seems to work fine, and then just gets killed. How would i go about removing "old" install correctly, and migrating db to docker install?

Donkie commented 10 months ago

Your db should be located at /home/biqu/.local/share/spoolman/spoolman.db, verify that before you move on.

  1. Simply remove your Spoolman installation folder, then run systemd --user stop Spoolman and systemd --user disable Spoolman
  2. Follow the instructions in the README for a docker installation, use the suggested docker-compose.yml in the README, but change the source: ./data row to source: /home/biqu/.local/share/spoolman
  3. Should be all set :)
srbjessen commented 10 months ago

It sorta worked. Spoolman doesn't restart enymore, but now i can't access klipper_mcu anymore. [mcu host] serial: /tmp/klipper_host_mcu

Klipper rapporter: ERROR

mcu 'host': Unable to connect Only changed to docker for spoolman, so not sure if docker has messed with permissions or?

Donkie commented 10 months ago

That should be completely unrelated.. not sure what has gone wrong. I'm personally hosting Spoolman in docker on the same host as klipper and moonraker. Have you tried troubleshooting via their help channels?

srbjessen commented 10 months ago

I will have a look at their support channels. Thanks for your help, at least spoolman works as intended.

meltiseugen commented 10 months ago

It sorta worked. Spoolman doesn't restart enymore, but now i can't access klipper_mcu anymore. [mcu host] serial: /tmp/klipper_host_mcu

Klipper rapporter: ERROR

mcu 'host': Unable to connect Only changed to docker for spoolman, so not sure if docker has messed with permissions or?

@srbjessen Have you managed to find a fix? I also lost klipper_host_mcu after adding docker

srbjessen commented 10 months ago

Not yet, haven't gotten around to it yet.
Life, you know.....

meltiseugen commented 10 months ago

Not yet, haven't gotten around to it yet. Life, you know.....

Oh believe me, I know... Anyways I'll let you know if I fix it

iliyan61 commented 10 months ago

So I started trying to run spool man in docker and im getting what i think is a similar issue of it just shutting down the application if the terminal or webui is closed and the only way to bring it back up is to open an ssh terminal.

Ive attached the relevant parts of the docker compose logs but i dont see anything explaining what's happening.

spoolman-spoolman-1 | INFO: connection open spoolman-spoolman-1 | INFO: 172.19.0.1:58452 - "GET /spool?allow_archived=false HTTP/1.1" 200 OK spoolman-spoolman-1 | INFO: 172.19.0.1:58466 - "GET /spool?allow_archived=false&limit=20&offset=0&sort=id:asc HTTP/1.1" 200 OK spoolman-spoolman-1 | INFO: Shutting down spoolman-spoolman-1 | spoolman.ws INFO Client 172.19.0.1 has stopped listening on pool spool spoolman-spoolman-1 | INFO: connection closed spoolman-spoolman-1 | INFO: Waiting for application shutdown. spoolman-spoolman-1 | INFO: Application shutdown complete. spoolman-spoolman-1 | INFO: Finished server process [1] spoolman-spoolman-1 | INFO: Started server process [1] spoolman-spoolman-1 | INFO: Waiting for application startup. spoolman-spoolman-1 | spoolman.main INFO Starting Spoolman v0.13.1 (commit: 33b1c4f) (built: 2023-10-24 18:51:51+00:00)

srbjessen commented 9 months ago

@meltiseugen This worked for me: https://discord.com/channels/431557959978450984/1186600356235444324

iliyan61 commented 9 months ago

i know this isn’t terribly helpful but i somehow fixed/side stepped it by just copying the files to a LXC container with a docker install using the same docker install script and it’s worked perfectly since then so i’ve got no idea what’s going on.

artfulbodger commented 3 months ago

I came across a similar issue and ran docker compose logs -f --tail=50 This showed me an error where the data folder was not writeable and told me to run sudo chown -R 1000:1000 <path to spoolman data directory on host>

Once I correctly set the owner of the spoolman/data directory and ran docker compose up -d all sprang into life.

Hope this helps someone