search

evilhero / mylar

An automated Comic Book downloader (cbr/cbz) for use with SABnzbd, NZBGet and torrents
GNU General Public License v3.0
977 stars 172 forks source link

QNAP and QSabNZB stuck on Fetch #1838

Closed miroresh closed 3 years ago

miroresh commented 6 years ago

Hi,

I have checked #1060 and #1055 but I can't figure this out.

My current version is: Mylar Version: master -- source build 053626a96bd1a8601b2ca87066261408e8c1cd30. Python Version : 2.7.13

SabNZB version is: 2.3.2 [1cac579]

Mylar sends the nzb file to SAB but it gets stuck doing a Fetch, retries multiple times and then fails. When I send the nzb directly to SAB it downloads just fine, Sonarr and Couchpotato both send and automate with SAB just fine as well.

The configuration on those Sonarr and Couchpotato are the same as far as using host IPs, they are both set to: 192.168.1.2:8282 and the API key is recognized and tested on that IP address by all 3, including Mylar.

If I change the IP in Mylar to http://0.0.0.0:8282 and says Successfully verified API Key and it sends the nzbs to SAB but still gets stuck in Fetch.

Both SAB and Mylar reside inside the QNAP, so they are the same machine.

What am I missing? :(

Thanks in advance for the help!

evilhero commented 6 years ago

The debug log in this case would be helpful so I could see what the link is that's being generated for sab.

If it's failing on the fetch, it usually has to do with the ip address not resolving properly for some reason. The reason being is that Mylar has already downloaded the nzb, so there's no point in making an additional api call to retrieve it again. So the download url that's submitted to sab to retrieve is actually requesting an api session from Mylar in order to retrieve the nzb and use that. The error is roughly indicating that the sab instance cannot connect to your mylar instance to retrieve the nzb.

Do you have more than one ip assigned to the machine? When Mylar starts up, it indicates what the ip is that it detects.

miroresh commented 6 years ago

Hi @evilhero ,

Thanks for the quick reply. Please see below for both parts of the debug log. One is the error, the second is the start up IP that you mentioned.

`

2018-01-06 21:53:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:53:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:53:21 INFO there are 0 files.
2018-01-06 21:53:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:53:21 INFO Update complete
2018-01-06 21:52:47 INFO setting the alternate nzbname for this download grabbed by nzbgeek (newznab) in the nzblog to : Batman-White.Knight.02..of.08...2018...2.covers...Digital...Zone-Empire.
-- -- --
2018-01-06 21:52:47 INFO setting the nzbid for this download grabbed by nzbgeek (newznab) in the nzblog to : e5835844788413f50bdd54xxxxxxxxxx
2018-01-06 21:52:47 INFO Successfully sent nzb file to SABnzbd
2018-01-06 21:52:47 INFO {u'status': True, u'nzo_ids': [u'SABnzbd_nzo_U40uqC']}
2018-01-06 21:52:47 INFO sending now to http://0.0.0.0:8282/api
2018-01-06 21:52:47 INFO parameters set to {'nzbname': u'Batman.-.White.Knight.02.of.08.2018.2.covers.Digital.Zone-Empire.nzb', 'apikey': u'1d91ab1b4c936c4b50fc2exxxxxxxxxx', 'name': u'http://192.168.1.22:8090/api?apikey=c5dd84a144e5c951eb33b1xxxxxxxxxx&cmd=downloadNZB&nzbname=Batman.-.White.Knight.02.of.08.2018.2.covers.Digital.Zone-Empire.nzb', 'cmd': 'downloadNZB', 'priority': '-100', 'mode': 'addurl', 'output': 'json'}
2018-01-06 21:52:47 INFO filen: Batman-White.Knight.02..of.08...2018...2.covers...Digital...Zone-Empire..nzb -- nzbname: Batman.-.White.Knight.02.of.08.2018.2.covers.Digital.Zone-Empire are not identical. Storing extra value as : Batman-White.Knight.02..of.08...2018...2.covers...Digital...Zone-Empire.
2018-01-06 21:52:47 INFO download-retrieved headers: {'content-length': '6218', 'content-disposition': 'attachment; filename=Batman-White.Knight.02.(of.08).(2018).(2.covers).(Digital).(Zone-Empire).nzb', 'x-powered-by': 'PHP/5.5.9-1ubuntu4.21', 'strict-transport-security': 'max-age=63072000; includeSubDomains, max-age=63072000; includeSubDomains', 'keep-alive': 'timeout=5, max=100', 'server': 'Apache/2.4.7 (Ubuntu)', 'connection': 'Keep-Alive', 'x-dnzb-moreinfo': '', 'date': 'Sun, 07 Jan 2018 03:52:47 GMT', 'content-type': 'application/x-nzb'}
2018-01-06 21:52:46 INFO Download URL: https://api.nzbgeek.info//api?apikey=8157xxxxxxxxxx&t=get&id=e5835844788413f50bdd54xxxxxxxxxx [VerifySSL:False]
2018-01-06 21:52:46 INFO [FAILED_DOWNLOAD_CHECKER] Successfully marked this download as Good for downloadable content
2018-01-06 21:52:46 INFO prov : nzbgeek (newznab)[e5835844788413f50bdd542eb2e87eac]
2018-01-06 21:52:46 INFO Found Batman: White Knight (2017) issue: 2 using nzbgeek (newznab)
2018-01-06 21:52:46 INFO link : https://api.nzbgeek.info//api?apikey=8157xxxxxxxxxx&t=get&id=e5835844788413f50bdd54xxxxxxxxxx
2018-01-06 21:52:46 INFO newznab detected as : nzbgeek @ https://api.nzbgeek.info/
2018-01-06 21:52:46 INFO fetched via newnzab. Retrying the send.
2018-01-06 21:52:46 INFO --Referencing : newznab @ 2018-01-06 17:38:31
2018-01-06 21:52:46 INFO Located snatched download:
2018-01-06 21:52:46 INFO Retrying : 634506
2018-01-06 21:52:46 INFO ComicID:104775
2018-01-06 21:52:15 INFO Verbose toggled, set to False
2018-01-06 21:48:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:53:21
2018-01-06 21:48:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:48:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:48:21 INFO there are 0 files.
2018-01-06 21:48:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:48:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:48:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:48:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:48:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:48:21 INFO Update complete
2018-01-06 21:48:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:53:21
2018-01-06 21:48:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:43:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:48:21
2018-01-06 21:43:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:43:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:43:21 INFO there are 0 files.
2018-01-06 21:43:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:43:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:43:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:43:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:43:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:43:21 INFO Update complete
2018-01-06 21:43:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:48:21
2018-01-06 21:43:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:38:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:43:21
2018-01-06 21:38:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:38:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:38:21 INFO there are 0 files.
2018-01-06 21:38:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:38:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:38:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:38:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:38:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:38:21 INFO Update complete
2018-01-06 21:38:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:43:21
2018-01-06 21:38:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:33:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:38:21
2018-01-06 21:33:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:33:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:33:21 INFO there are 0 files.
2018-01-06 21:33:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:33:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:33:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:33:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:33:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:33:21 INFO Update complete
2018-01-06 21:33:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:38:21
2018-01-06 21:33:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:28:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:33:21
2018-01-06 21:28:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:28:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:28:21 INFO there are 0 files.
2018-01-06 21:28:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:28:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:28:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:28:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:28:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:28:21 INFO Update complete
2018-01-06 21:28:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:33:21
2018-01-06 21:28:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:23:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:28:21
2018-01-06 21:23:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:23:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:23:21 INFO there are 0 files.
2018-01-06 21:23:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:23:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:23:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:23:21 DEBUG [POST-PROCESSING] nzb name: Manual Run
2018-01-06 21:23:21 INFO [FOLDER-CHECK] Checking folder /share/Download/Complete for newly snatched downloads
2018-01-06 21:23:21 INFO Update complete
2018-01-06 21:23:21 DEBUG ReScheduled job: DB Updater to 2018-01-07 03:28:21
2018-01-06 21:23:21 DEBUG Refresh sequence set to fire every 5 minutes for 7 day(s)
2018-01-06 21:18:21 DEBUG ReScheduled job: Folder Monitor to 2018-01-07 03:23:21
2018-01-06 21:18:21 INFO [FOLDER-CHECK] Finished checking for newly snatched downloads
2018-01-06 21:18:21 WARNING There were no files located - check the debugging logs if you think this is in error.
2018-01-06 21:18:21 INFO there are 0 files.
2018-01-06 21:18:21 DEBUG [POST-PROCESSING] Manual Run initiated
2018-01-06 21:18:21 DEBUG [POST-PROCESSING] Not using SABnzbd : Manual Run
2018-01-06 21:18:21 DEBUG [POST-PROCESSING] nzb folder: /share/Download/Complete
2018-01-06 21:18:21 DEBUG [POST-PROCESSING] nzb name: Manual Run

`

`

2018-01-06 19:38:21 INFO Background Schedulers successfully started...
2018-01-06 19:38:21 INFO Firing up the Background Schedulers now....
2018-01-06 19:38:21 INFO [FOLDER MONITOR] Enabling folder monitor for : /share/Download/Complete every 5 minutes.
2018-01-06 19:38:21 DEBUG [WEEKLY] Scheduling next run for @ 2018-01-07 05:33:47.916709 every 24 hours
2018-01-06 19:38:21 INFO [WEEKLY] Checking for existance of Weekly Comic listing...
2018-01-06 19:38:21 DEBUG [AUTO-SEARCH]Auto-Search set to a delay of one minute before initialization as it has been 458.147295117 minutes since the last run
2018-01-06 19:38:21 DEBUG [AUTO-SEARCH] Search last run @ 2018-01-06 18:00:12.286678
2018-01-06 19:38:21 INFO Starting Mylar on http://0.0.0.0:48090/
2018-01-06 19:38:21 INFO Starting Mylar on forced port: 48090
2018-01-06 19:38:21 INFO Daemonized to PID: 32507
2018-01-06 19:38:20 INFO Sucessfully ordered 103 series in your watchlist.
2018-01-06 19:38:20 INFO Remapping the sorting to allow for new additions.
2018-01-06 19:38:20 INFO Mylar is up to date
2018-01-06 19:38:20 DEBUG Comparing currently installed version [053626a96bd1a8601b2ca87066261408e8c1cd30] with latest github version [053626a96bd1a8601b2ca87066261408e8c1cd30]
2018-01-06 19:38:20 INFO Retrieving latest version information from github
2018-01-06 19:38:20 INFO Correcting Null entries that make the main page break on startup.
2018-01-06 19:38:20 INFO Ensuring DB integrity - Removing all Erroneous Comics (ie. named None)
2018-01-06 19:38:20 INFO Populating Custom Exception listings into Mylar....
2018-01-06 19:38:20 INFO Populating Base Exception listings into Mylar....
2018-01-06 19:38:19 INFO Checking to see if the database has all tables....
2018-01-06 19:38:19 INFO Branch detected & set to : master
2018-01-06 19:38:19 INFO Config GIT Branch: master
2018-01-06 19:38:19 DEBUG Logger set to use : Rotational Log Handler (default)
2018-01-06 19:38:19 INFO Successfully discovered local IP and locking it in as : 192.168.1.22
2018-01-06 19:38:19 DEBUG Log dir: /share/CACHEDEV1_DATA/.qpkg/Mylar/mylar-master/logs
2018-01-06 19:38:19 DEBUG Provider Order is now set : {'0': u'nzbgeek'}
2018-01-06 19:38:19 DEBUG Provider sequence already pre-exists. Re-loading and adding/remove any new entries
2018-01-06 19:38:19 DEBUG Original provider_order sequence: 0, nzbgeek
2018-01-06 19:38:19 INFO Initializing startup sequence....
2018-01-06 19:38:19 INFO [DIRECTORY-CHECK] Found comic directory: /share/CACHEDEV1_DATA/.qpkg/Mylar/mylar-master

`

evilhero commented 6 years ago

It looks like your startup port for Mylar is set to 48090, but the link that's being sent to SABnzbd is saying Mylar is on port 8090.

Somewhere it's being forced to the incorrect one - do you have a value set for your return_host in the config.ini?

miroresh commented 6 years ago

I don't believe so: `

sab_to_mylar False
sab_priority Default
sab_password None
sab_host http://0.0.0.0:8282
sab_directory None
sab_client_post_processing False
sab_category None

...

http_root /
http_port 8090
http_password None
http_host 0.0.0.0
host_return None
highcount 0

`

evilhero commented 6 years ago

How bout this - when you start mylar up what port do you use to access it from the web browser - 8090, or 48090?

Do you force the port on your startup command (using the -p option)?

miroresh commented 6 years ago

I don't start it from the command line, it auto boots up when the QNAP boots up; I'm not using any switches on boot up. I do see this on the IP when I open the web interface: http://192.168.1.22:48090/logs Looks like it is using the 48090 port?

How can I check if there are any options being thrown on boot?

Here is the link of your program from the QNAP Club store: https://www.qnapclub.eu/en/qpkg/461

evilhero commented 6 years ago

Yep that's the port alright. The QNap installation is forcing the port number. But it looks like Mylar isn't storing the port # that's being forcibly set - or something is happening on the backend that's messing up the ports. I'll have to check into this more, as this is the first I've seen of this type of thing happening...

The quick fix for this would be to set your port in mylar to coincide to what is being forced - so set the mylar port in the GUI to 48090. Then save the config and restart. That should fix things (I think at least)

miroresh commented 6 years ago

Thanks @evilhero I'll give that a shot and report back.

miroresh commented 6 years ago

Well, that worked! :)

But is this the right solution?

evilhero commented 6 years ago

Yep, it's a backend code problem - if the port is forced on startup, it should be forcing it to the same in the GUI. Either it's not, or changing the port in the GUI is not enforcing the port upon a restart.

So the fix that you just did should remain - any fix that goes into Mylar at this point will be to address the port changing problem, it won't affect things going forward for you.