Closed schumi4 closed 11 months ago
Ah, there's some interesting things for me to work through here. I didn't consider checking to make sure it's a video file that's found, I see you have some .nfo
files that are being found as well. I guess either the API call to retrieve the command log/queue is different in Sonarr-v3 than Sonarr-v4 as well, or there's too many commands in the log/queue and it got pushed to another page.
I'll spin up a v4 container and work on this over the next few days.
Thanks for the response! I tested further, -h
and -u
flags work, no flag instantly exits withour printing anything.
no flag instantly exits withour printing anything.
Yeah, there's a (now stale) lockfile in place that was not removed when you presumably exited via Ctrl+C
. I didn't set up any traps for SIGINT
etc. to remove the lockfile if exiting outside a defined condition. That's why you get no output, if the lockfile exists, the script immediately silently exits.
The lockfile exists next to the script as .${scriptName}.lock
. Assuming you kept the script named sonarr-update-tba.bash
(as your logs seem to indicate), you can remove it via rm .sonarr-update-tba.bash.lock
. I'll add a check to make sure the lockfile isn't stale when I update the script, and traps for abnormal exit conditions, as well.
Ah yes, I see it now, thanks. Is silently exiting by design here? A message like Exiting because of existing lockfile
saves a lot of confusion here.
But now that is cleaned up, if you need any more testing regarding the actual renaming let me know.
Yeah, that's a good point, I'll add that message for exiting due to lockfile in as well.
As I'm not going to be able to dive into this more deeply for at least a few hours, but if you are able/have the time, could you attempt to retrieve the command queue and show me what the output is? That's the first part I largely need to look in to. If you able/willing to, the command is:
curl -skL "[CONTAINER_IP]:[SONARR_PORT][SONARR_URL_BASE]/api/v3/command?apikey=[SONARR_API_KEY]"
Where:
[CONTAINER_IP]
is the IP address of the Sonarr container (assuming your container name is sonarr
, retrievable via: docker inspect -f '{{range.NetworkSettings.Networks}}{{.IPAddress}}{{end}}' sonarr
)[SONARR_PORT]
is the port Sonarr is running on (Settings > General > Host > Port Number)[SONARR_URL_BASE]
is the URL base, if you have one configured, you can omit this if you do not have one configured (the /sonarr
part of http://127.0.0.1:8989/sonarr
) (Settings > General Host > Host > URL Base)[SONARR_API_KEY]
is the API (Settings > General > Security > API Key)It'll return a large-ish JSON output, some of which may have information that you'd want to scrub (API key being the most sensitive thing). If you're willing to share that with me, it would be helpful/save me some time. If not, no worries, I can check it myself when I get around to spinning a container up later today or tomorrow.
First off the verbose log for the first episode:
sonarr-update-tba.bash :: 2023-11-26 14:36:50 :: [2] Detected 125 TBA items
sonarr-update-tba.bash :: 2023-11-26 14:36:50 :: [3] Library: /tv
sonarr-update-tba.bash :: 2023-11-26 14:36:50 :: [3] File: /tv/7 vs. Wild/Season 03/7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.mkv
sonarr-update-tba.bash :: 2023-11-26 14:36:50 :: [2] Processing 7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.mkv
sonarr-update-tba.bash :: 2023-11-26 14:36:50 :: [3] Verifying file has not already been renamed
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Filename unchanged
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [2] Initiating series rename command
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Determined root folder: /tv
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Determined series folder: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Built series path: /tv/7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Determined series: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Determined series ID: 32
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [2] Issuing refresh command for: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Command status: 400
sonarr-update-tba.bash :: 2023-11-26 14:36:51 :: [3] Command ID: null
sonarr-update-tba.bash :: 2023-11-26 14:36:52 :: [3] Getting command status queue
sonarr-update-tba.bash :: 2023-11-26 14:36:52 :: [1] Unable to retrieve command ID null from command log
sonarr-update-tba.bash :: 2023-11-26 14:36:52 :: [3] Sleeping 15 seconds to attempt to ensure system has time to process command
sonarr-update-tba.bash :: 2023-11-26 14:37:07 :: [2] Issuing rename command for: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:07 :: [3] Command status: 400
sonarr-update-tba.bash :: 2023-11-26 14:37:07 :: [3] Command ID: null
sonarr-update-tba.bash :: 2023-11-26 14:37:08 :: [3] Getting command status queue
sonarr-update-tba.bash :: 2023-11-26 14:37:08 :: [1] Unable to retrieve command ID null from command log
sonarr-update-tba.bash :: 2023-11-26 14:37:08 :: [3] Sleeping 15 seconds to attempt to ensure system has time to process command
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [3] Verifying file rename status
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [3] Matched '7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.mkv' to '7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.mkv'
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [2] [sonarr] File name unchanged, new title unavailable for: 7 vs. Wild S03E01
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [3] Library: /tv
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [3] File: /tv/7 vs. Wild/Season 03/7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.nfo
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [2] Processing 7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.nfo
sonarr-update-tba.bash :: 2023-11-26 14:37:23 :: [3] Verifying file has not already been renamed
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Filename unchanged
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [2] Initiating series rename command
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Determined root folder: /tv
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Determined series folder: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Built series path: /tv/7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Determined series: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Determined series ID: 32
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [2] Issuing refresh command for: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Command status: 400
sonarr-update-tba.bash :: 2023-11-26 14:37:24 :: [3] Command ID: null
sonarr-update-tba.bash :: 2023-11-26 14:37:25 :: [3] Getting command status queue
sonarr-update-tba.bash :: 2023-11-26 14:37:25 :: [1] Unable to retrieve command ID null from command log
sonarr-update-tba.bash :: 2023-11-26 14:37:25 :: [3] Sleeping 15 seconds to attempt to ensure system has time to process command
sonarr-update-tba.bash :: 2023-11-26 14:37:40 :: [2] Issuing rename command for: 7 vs. Wild
sonarr-update-tba.bash :: 2023-11-26 14:37:40 :: [3] Command status: 400
sonarr-update-tba.bash :: 2023-11-26 14:37:40 :: [3] Command ID: null
sonarr-update-tba.bash :: 2023-11-26 14:37:41 :: [3] Getting command status queue
sonarr-update-tba.bash :: 2023-11-26 14:37:41 :: [1] Unable to retrieve command ID null from command log
sonarr-update-tba.bash :: 2023-11-26 14:37:41 :: [3] Sleeping 15 seconds to attempt to ensure system has time to process command
sonarr-update-tba.bash :: 2023-11-26 14:37:56 :: [3] Verifying file rename status
sonarr-update-tba.bash :: 2023-11-26 14:37:56 :: [3] Matched '7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.nfo' to '7 vs. Wild (2021) - S03E01 - TBA [WEBDL-1080p Proper][EAC3 2.0][h264]-MGE.nfo'
sonarr-update-tba.bash :: 2023-11-26 14:37:56 :: [2] [sonarr] File name unchanged, new title unavailable for: 7 vs. Wild S03E01
And the command queue retrieved directly after exiting the script (let me know if theres sensitive information in there, pretty sure there's not though):
[
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:28:54Z",
"lastStartTime": "2023-11-26T13:28:53Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:30:23Z",
"started": "2023-11-26T13:30:23Z",
"ended": "2023-11-26T13:30:24Z",
"duration": "00:00:00.1597689",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:30:23Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:28:54Z",
"id": 85055
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:30:24Z",
"started": "2023-11-26T13:30:24Z",
"ended": "2023-11-26T13:30:24Z",
"duration": "00:00:00.0017863",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:30:24Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85056
},
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:30:24Z",
"lastStartTime": "2023-11-26T13:30:23Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:31:53Z",
"started": "2023-11-26T13:31:53Z",
"ended": "2023-11-26T13:31:54Z",
"duration": "00:00:00.1888671",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:31:53Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:30:24Z",
"id": 85057
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:31:54Z",
"started": "2023-11-26T13:31:54Z",
"ended": "2023-11-26T13:31:54Z",
"duration": "00:00:00.0013481",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:31:54Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85058
},
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:31:54Z",
"lastStartTime": "2023-11-26T13:31:53Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:33:23Z",
"started": "2023-11-26T13:33:23Z",
"ended": "2023-11-26T13:33:24Z",
"duration": "00:00:00.1273562",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:33:23Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:31:54Z",
"id": 85059
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:33:24Z",
"started": "2023-11-26T13:33:24Z",
"ended": "2023-11-26T13:33:24Z",
"duration": "00:00:00.0031975",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:33:24Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85060
},
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:33:24Z",
"lastStartTime": "2023-11-26T13:33:23Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:34:53Z",
"started": "2023-11-26T13:34:53Z",
"ended": "2023-11-26T13:34:54Z",
"duration": "00:00:00.1372904",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:34:53Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:33:24Z",
"id": 85062
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:34:54Z",
"started": "2023-11-26T13:34:54Z",
"ended": "2023-11-26T13:34:54Z",
"duration": "00:00:00.0011191",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:34:54Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85063
},
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:34:54Z",
"lastStartTime": "2023-11-26T13:34:53Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:36:23Z",
"started": "2023-11-26T13:36:23Z",
"ended": "2023-11-26T13:36:24Z",
"duration": "00:00:00.1225289",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:36:23Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:34:54Z",
"id": 85065
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:36:24Z",
"started": "2023-11-26T13:36:24Z",
"ended": "2023-11-26T13:36:24Z",
"duration": "00:00:00.0017382",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:36:24Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85066
},
{
"name": "RefreshMonitoredDownloads",
"commandName": "Refresh Monitored Downloads",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "RefreshMonitoredDownloads",
"lastExecutionTime": "2023-11-26T13:36:24Z",
"lastStartTime": "2023-11-26T13:36:23Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:37:53Z",
"started": "2023-11-26T13:37:53Z",
"ended": "2023-11-26T13:37:54Z",
"duration": "00:00:00.1400546",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:37:53Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:36:24Z",
"id": 85068
},
{
"name": "ProcessMonitoredDownloads",
"commandName": "Process Monitored Downloads",
"message": "Completed",
"body": {
"requiresDiskAccess": true,
"isLongRunning": true,
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"isExclusive": false,
"name": "ProcessMonitoredDownloads",
"trigger": "unspecified",
"suppressMessages": false
},
"priority": "high",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:37:54Z",
"started": "2023-11-26T13:37:54Z",
"ended": "2023-11-26T13:37:54Z",
"duration": "00:00:00.0044049",
"trigger": "unspecified",
"stateChangeTime": "2023-11-26T13:37:54Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"id": 85069
},
{
"name": "ImportListSync",
"commandName": "Import List Sync",
"message": "Completed",
"body": {
"sendUpdatesToClient": true,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "ImportListSync",
"lastExecutionTime": "2023-11-26T13:29:53Z",
"lastStartTime": "2023-11-26T13:29:53Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "low",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:34:53Z",
"started": "2023-11-26T13:34:53Z",
"ended": "2023-11-26T13:34:53Z",
"duration": "00:00:00.0031707",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:34:53Z",
"sendUpdatesToClient": true,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:29:53Z",
"id": 85061
},
{
"name": "MessagingCleanup",
"commandName": "Messaging Cleanup",
"message": "Completed",
"body": {
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"isLongRunning": false,
"name": "MessagingCleanup",
"lastExecutionTime": "2023-11-26T13:30:23Z",
"lastStartTime": "2023-11-26T13:30:23Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "low",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:35:23Z",
"started": "2023-11-26T13:35:23Z",
"ended": "2023-11-26T13:35:23Z",
"duration": "00:00:00.0158679",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:35:23Z",
"sendUpdatesToClient": false,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:30:23Z",
"id": 85064
},
{
"name": "RssSync",
"commandName": "Rss Sync",
"message": "Completed",
"body": {
"sendUpdatesToClient": true,
"isLongRunning": true,
"updateScheduledTask": true,
"completionMessage": "Completed",
"requiresDiskAccess": false,
"isExclusive": false,
"name": "RssSync",
"lastExecutionTime": "2023-11-26T13:21:26Z",
"lastStartTime": "2023-11-26T13:21:23Z",
"trigger": "scheduled",
"suppressMessages": false
},
"priority": "low",
"status": "completed",
"result": "successful",
"queued": "2023-11-26T13:36:53Z",
"started": "2023-11-26T13:36:53Z",
"ended": "2023-11-26T13:36:56Z",
"duration": "00:00:02.2460582",
"trigger": "scheduled",
"stateChangeTime": "2023-11-26T13:36:53Z",
"sendUpdatesToClient": true,
"updateScheduledTask": true,
"lastExecutionTime": "2023-11-26T13:21:26Z",
"id": 85067
}
]%
Command status: 400
Well that's interesting. It's expecting a status (started/queued/completed), not a numeric. And it should be able to extract the command ID regardless of the status message, as well. I suspect this is the root of the problem, I need to find out what sonarr is returning when the refresh series command is issued, as it's clearly not the JSON I was expecting.
Thanks for the helpful info, more to come.
Give it a try now, @schumi4. I've tested it in my makeshift v4 sandbox environment with success and reverse compatibility with v3, hopefully this squares away the issue for you.
Worked as expected, thank you for the quick fixes!
Running Sonarr v4 beta.
Would love to provide verbose logs, but script fails to run at all after cancelling the above log. Immediately exits after start, not sure what the problem is.