Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'> #63

Closed
D34DC3N73R opened this issue Mar 25, 2024 · 23 comments · Fixed by #70
Closed

Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'> #63

D34DC3N73R opened this issue Mar 25, 2024 · 23 comments · Fixed by #70
Labels
bug Something isn't working

Comments

@D34DC3N73R
Copy link

D34DC3N73R commented Mar 25, 2024 •
edited
Loading

I just started decluttarr for the first time and ran into the following error. I saw a comment in #52 asking for a new issue so I opened this one. I will try out verbose logs to see if there is any other details.

$ docker logs -f decluttarr
[INFO]: ##################################################
[INFO]: Decluttarr - Application Started!
[INFO]: 
[INFO]: *** Current Settings ***
[INFO]: Version: v1.31.0
[INFO]: Commit: dca40aa
[INFO]: 
[INFO]: True | Removing failed downloads
[INFO]: True | Removing downloads missing metadata
[INFO]: False | Removing downloads missing files
[INFO]: False | Removing orphan downloads
[INFO]: False | Removing slow downloads
[INFO]: True | Removing stalled downloads
[INFO]: False | Removing downloads belonging to unmonitored TV shows/movies
[INFO]: 
[INFO]: Running every: 0 days 0 hours 10.0 minutes
[INFO]: Permitted number of times before stalled/missing metadata/slow downloads are removed: 3
[INFO]: Downloads with this tag will be skipped: "Keep"
[INFO]: Private Trackers will be skipped: True
[INFO]: 
[INFO]: *** Configured Instances ***
[INFO]: Radarr: http://radarr:7878/api/v3
[INFO]: Sonarr: http://sonarr:8989/api/v3
[INFO]: Lidarr: http://lidarr:8686/api/v1
[INFO]: qBittorrent: http://qbit:8888/api/v2
[INFO]: 
[INFO]: *** Check Instances ***
[INFO]: OK | Radarr
[INFO]: OK | Sonarr
[INFO]: OK | Lidarr
[INFO]: OK | qBittorrent
[INFO]: 
[INFO]: ##################################################
[INFO]: LOG_LEVEL = INFO: Only logging changes (switch to VERBOSE for more info)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[INFO]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[INFO]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)

Verbose Logs:

[INFO   ]: ##################################################
[INFO   ]: 
[VERBOSE]: --------------------------------------------------
[VERBOSE]: Cleaning queue on Radarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Sonarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Lidarr:
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[INFO   ]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (1 out of 3 permitted times): Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: 
[VERBOSE]: Queue clean-up complete!
[VERBOSE]: --------------------------------------------------
[VERBOSE]: Cleaning queue on Radarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Sonarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Lidarr:
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[INFO   ]: >>> Detected stalled download (2 out of 3 permitted times): Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (2 out of 3 permitted times): Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (2 out of 3 permitted times): Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: 
[VERBOSE]: Queue clean-up complete!
[VERBOSE]: --------------------------------------------------
[VERBOSE]: Cleaning queue on Radarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Sonarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Lidarr:
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[INFO   ]: >>> Detected stalled download (3 out of 3 permitted times): Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (3 out of 3 permitted times): Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download (3 out of 3 permitted times): Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: 
[VERBOSE]: Queue clean-up complete!
[VERBOSE]: --------------------------------------------------
[VERBOSE]: Cleaning queue on Radarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Sonarr:
[VERBOSE]: >>> Queue is clean.
[VERBOSE]: Cleaning queue on Lidarr:
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[INFO   ]: >>> Detected stalled download too many times (4 out of 3 permitted times): Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download too many times (4 out of 3 permitted times): Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO   ]: >>> Detected stalled download too many times (4 out of 3 permitted times): Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[INFO   ]: >>> Removing stalled download: Xxxtentacion - NA (2018 - Hip Hop Rap) [Flac 16-44]
[INFO   ]: >>> Removing stalled download: Xxxtentacion - Bad Vibes Forever (2019 - Pop) [Flac 16-44]
[INFO   ]: >>> Removing stalled download: Xxxtentacion - SKINS (2018 - Pop) [Flac 16-44]
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[VERBOSE]: 
[VERBOSE]: Queue clean-up complete!

The stalled torrents were removed from qbit. I'm not sure if there is an API issue with lidarr, but it does seem to work as intended. Removed downloads were not immediately removed from lidarr queue, but replacement downloads had already been searched by the time the queue refreshed.
@ManiMatter
Copy link
Owner

Thank you for the details.

could you please

  1. switch to ‚DEBUG‘ logs
  2. turn off all features but one that causes the issue
  3. if it‘s lidarr related, remove radarr/sonarr/readarr
  4. submit logs to a pastebin

this would give us way more logs and remove unecessary logs

thank you

@ManiMatter ManiMatter added the bug Something isn't working label Mar 25, 2024
@D34DC3N73R
Copy link
Author

D34DC3N73R commented Mar 25, 2024 •
edited
Loading

Maybe I'm not running this right but this is my docker-compose

  decluttarr-debug:
    image: ghcr.io/manimatter/decluttarr:latest
    container_name: decluttarr-debug
    restart: unless-stopped
    environment:
      - TZ=$TZ
      - PUID=$PUID
      - PGID=$PGID
      ## General
      - LOG_LEVEL=DEBUG
      #- TEST_RUN=True
      #- SSL_VERIFICATION=False
      ## Features 
      - REMOVE_TIMER=10
      - REMOVE_FAILED=True
      - REMOVE_METADATA_MISSING=True
      - REMOVE_MISSING_FILES=False
      - REMOVE_ORPHANS=False
      - REMOVE_SLOW=False
      - REMOVE_STALLED=True
      - REMOVE_UNMONITORED=False
      - MIN_DOWNLOAD_SPEED=100
      - PERMITTED_ATTEMPTS=3
      - NO_STALLED_REMOVAL_QBIT_TAG=Keep
      - IGNORE_PRIVATE_TRACKERS=True
      ## Lidarr
      - LIDARR_URL=http://lidarr:8686
      - LIDARR_KEY=$LIDARR_KEY
      ## qBittorrent
      - QBITTORRENT_URL=http://qbit:8888
      - QBITTORRENT_USERNAME=$QBIT_UN
      - QBITTORRENT_PASSWORD=$QBIT_PW

The container constantly restarts with these logs

$ docker logs -f decluttarr-debug
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
$

Edit, it appears the container won't run with just lidarr configured. These are debug logs with radarr and sonarr as well as lidarr
https://hastebin.com/share/lepamajezi.markdown

@ManiMatter
Copy link
Owner

Thank you. I‘ll try to look into it on the weekend.

@ManiMatter
Copy link
Owner

ManiMatter commented Mar 26, 2024 •
edited
Loading

ok few questions:

  1. let's does it run if you only have either radarr or sonarr running together with lidarr? or do you need both so that the container starts?
  2. can you please pull the "dev" version instead of the "latest" version and repaste the logs? I added logs hoping to understanding better what's going on.
  3. Which lidarr version are you using?

I will probably need to ask you a few more times to pull logs, please bear with me

@D34DC3N73R
Copy link
Author

D34DC3N73R commented Mar 26, 2024 •
edited
Loading

:latest w/ Sonarr + Lidarr: TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
:latest w/ Radarr + Lidarr: Container starts

I'm not able to pull the dev image. (image: ghcr.io/manimatter/decluttarr:dev)

$ docker compose pull decluttarr
[+] Pulling 0/1
 ⠼ decluttarr Pulling                                                                                                                             1.4s 
manifest unknown

There only appears to be a single image on github and there are no tags in docker hub.

edit: lidarr 2.1.7.4030-ls161 by linuxserver.io pulled using lscr.io/linuxserver/lidarr

edit2: Cloned the dev branch and built the dev image

:dev w/ only Lidarr: TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
:dev w/ Sonarr + Lidarr: TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
:dev w/ Radarr + Lidarr: Container starts

dev built image with debug logs using radar + lidarr: https://hastebin.com/share/ukohivohad.bash (cleaned up the download waiting to be imported in lidarr)

@ManiMatter
Copy link
Owner

This gets worse and worse 🤷‍♂️
Weekend work! Thx for the help thus far

@ManiMatter
Copy link
Owner

you should now again be able to pull images.
Quick Q: does sonarr alone start?

@D34DC3N73R
Copy link
Author

D34DC3N73R commented Mar 28, 2024 •
edited
Loading

No. With lidarr and radarr commented out, I get the same logs

$ docker logs -f decluttarr
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'
TypeError: unsupported operand type(s) for +: 'dict' and 'dict'

Decluttarr : dev image
Sonarr: 4.0.2.1183-ls231
Radarr: 5.3.6.8612-ls210
Lidarr: 2.1.7.4030-ls162

@ManiMatter
Copy link
Owner

Super! I was hoping that‘d be the case. Will start digging

@ManiMatter
Copy link
Owner

I think I solved it. Could you please try to pull the dev image and verify?

@D34DC3N73R
Copy link
Author

The container now starts with just lidarr (and just sonarr as well) configured.
Dev w/ only lidarr - debug logs: https://hastebin.com/share/ciwogobali.bash

@ManiMatter
Copy link
Owner

ManiMatter commented Mar 29, 2024 •
edited
Loading

Hm. I think we are on to something here

The below code shows that the lidarr queue API was successfully hit, but the response does not have the 'downloadId' key in it. According to the Lidarr API spec that should be there though.

[DEBUG]: http://lidarr:8686 "GET /api/v1/queue?page=1&pageSize=1 HTTP/1.1" 200 None
[WARNING]: >>> Queue cleaning failed on formattedQueueInfo. (File: shared.py / Line: 128 / Error Message: 'downloadId' / Error Type: <class 'KeyError'>)
[DEBUG]: KeyError: 'downloadId'

[DEBUG]: formattedQueueInfo/queue for debug: {'page': 1, 'pageSize': 1, 'sortKey': 'timeleft', 'sortDirection': 'descending', 'totalRecords': 1, 'records': [{'artistId': 492, 'albumId': 4535, 'quality': {'quality': {'id': 4, 'name': 'MP3-320'}, 'revision': {'version': 1, 'real': 0, 'isRepack': False}}, 'customFormats': [], 'customFormatScore': 0, 'size': 98481208, 'title': 'Buddy   Harlan & Alondra (2018) Mp3 (320kbps) [Hunter]', 'sizeleft': 98481208, 'timeleft': '00:04:38.2148902', 'estimatedCompletionTime': '2024-03-29T17:34:50Z', 'added': '2024-02-23T01:10:54Z', 'status': 'delay', 'protocol': 'torrent', 'downloadClientHasPostImportCategory': False, 'indexer': '1337x (Prowlarr)', 'trackFileCount': 12, 'trackHasFileCount': 12, 'downloadForced': False, 'id': 1177655784}]}

Will try to find somebody from lidarr and ask
Update: Just did, and we need your help in reproducing this.

Is there any reason that you can think of why this particular item would not have a downloadId?
This happens on qBittorrent, right?
which qbit version are you using, and which image?

@D34DC3N73R
Copy link
Author

D34DC3N73R commented Mar 29, 2024 •
edited
Loading

Lidarr 2.1.7.4030-ls162 (lscr.io/linuxserver/lidarr)
qBittorrent: v4.6.3 (binhex/arch-qbittorrentvpn)

Yes, that particular torrent likely doesn't have a download id because the torrent is currently 'pending' due to delay profiles in Lidarr.

Edit: with that torrent completed, the logs look as intended, although there are currently no downloading items in lidarr

[DEBUG]: Starting new HTTP connection (1): qbit:8888
[DEBUG]: http://qbit:8888 "GET /api/v2/torrents/info HTTP/1.1" 200 8252
[VERBOSE]: Cleaning queue on Lidarr:
[DEBUG]: Starting new HTTP connection (1): lidarr:8686
[DEBUG]: http://lidarr:8686 "POST /api/v1/command HTTP/1.1" 201 None
[DEBUG]: Starting new HTTP connection (1): lidarr:8686
[DEBUG]: http://lidarr:8686 "GET /api/v1/queue?includeUnknownArtistItems=True HTTP/1.1" 200 None
[VERBOSE]: >>> Queue is empty.
[VERBOSE]: 
[VERBOSE]: Queue clean-up complete!

@ManiMatter
Copy link
Owner

ManiMatter commented Mar 29, 2024 •
edited
Loading

I wasn't even aware of the delayed profiles - functionality. learnt something new.

I just added a piece of code that should hopefully deal with those delayed items.

Are you able to again create a delayed lidarr-download, pull the "dev" version I just uploadeded, and post the logs (on debug level)?
Hopefully you should not encounter any problems anymore.

@D34DC3N73R
Copy link
Author

D34DC3N73R commented Mar 30, 2024 •
edited
Loading

I seem to be running into a different error now that forces the container to exit.

[DEBUG]: Using selector: EpollSelector
[DEBUG]: Starting new HTTP connection (1): lidarr:8686
[DEBUG]: http://lidarr:8686 "GET /api/v1/system/status HTTP/1.1" 200 None
[INFO]: ##################################################
[INFO]: Decluttarr - Application Started!
[INFO]: 
[INFO]: *** Current Settings ***
[INFO]: Version: dev
[INFO]: Commit: 5f0a218
[INFO]: 
[INFO]: True | Removing failed downloads
[INFO]: True | Removing downloads missing metadata
[INFO]: False | Removing downloads missing files
[INFO]: False | Removing orphan downloads
[INFO]: False | Removing slow downloads
[INFO]: True | Removing stalled downloads
[INFO]: False | Removing downloads belonging to unmonitored items
[INFO]: 
[INFO]: Running every: 0 days 0 hours 10.0 minutes
[INFO]: Permitted number of times before stalled/missing metadata/slow downloads are removed: 3
[INFO]: Downloads with this tag will be skipped: "Keep"
[INFO]: Private Trackers will be skipped: True
[INFO]: 
[INFO]: *** Configured Instances ***
[INFO]: Lidarr: http://lidarr:8686/api/v1
[INFO]: qBittorrent: http://qbit:8888/api/v2
[INFO]: 
[INFO]: *** Check Instances ***
[DEBUG]: Starting new HTTP connection (1): lidarr:8686
[DEBUG]: http://lidarr:8686 "GET /api/v1/system/status HTTP/1.1" 200 None
[INFO]: OK  | Lidarr
UnboundLocalError: local variable 'current_version' referenced before assignment

The delay profiles are super helpful if you have private indexers. I prefer to dl what I can from usenet, but often the releases will first appear on private indexers, so I have delays in all the 'arrs. If the content doesn't show up within 12 hours, the torrent is processed, otherwise, the nzb will take priority and remove the torrent from pending.

@ManiMatter
Copy link
Owner

I am so sorry for the back and forth. I just uploaded a new version that should fix also the current_version problem.
Refactored quite a bit of code yesterday when trying to find the dict + dict problem, and by doing so I seem to have added this new bug... sorry for that.

thanks for the explanation on the delay profiles and the new logs.

@D34DC3N73R
Copy link
Author

The dev container now starts fine. From what I can gather, manually searched items don't adhere to the delay profiles. I believe they have to be from the RSS search. So, I haven't been able to get one from lidarr yet, but I do have some delayed downloads in sonarr so I've captured those debug logs: https://hastebin.com/share/iqedixisaz.markdown

I trimmed them a bit, but let me know if you need more.

@ManiMatter
Copy link
Owner

Not sure I understand your reference to RSS searched items.

From the logs, things look as if they are running fine now. Are you still experiencing any issues?
The additition from yesterday seems to work (">>> Delayed queue item ignored: ...")

@D34DC3N73R
Copy link
Author

There are 3 types of searches in the arrs. Interactive search where you pick the download, automatic search where the arr picks the download, and RSS which really isn't a search, but rather an RSS list of all torrents from every indexer that is parsed by the arrs. If something in your wanted list matches a parsed torrent from the RSS feed, it's added to the download queue. The RSS parsed torrents seem to be the only method that utilizes delay profiles.

With that said, it does appear to be working as intended and I haven't seen any errors. If you want to close this, that's fine with me. I can open a different issue if I notice anything when lidarr does pick up a delayed torrent.

@ManiMatter
Copy link
Owner

understood.

in theory, the way i implemented it should be agnostic about the method and should work in all 3 methods.

thanks for your help with debugging this.

quick one: i just pushed a (hopefully final) version, would you mind to once again post the logs of sonarr ?
just want to make sure it works as expected, then will merge to the "latest"

@D34DC3N73R
Copy link
Author

sure thing. here are the full logs from a startup with just sonarr enabled on the most recent dev image
https://hastebin.com/share/avimemipay.markdown

@ManiMatter
Copy link
Owner

Looks splendid. thanks for the help.

Merging to latest now and suggest we close this ticket, unless you need help with anything else?

@D34DC3N73R
Copy link
Author

sounds good. If I notice anything else I'll open a new ticket. Thanks for the help!

@ManiMatter ManiMatter linked a pull request Mar 30, 2024 that will close this issue
Fixing problems with dict + dict issue // adding compatibility for delay profiles // code cleanup #70
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
2 participants
@D34DC3N73R @ManiMatter