search

fossar / selfoss

multipurpose rss reader, live stream, mashup, aggregation web application
https://selfoss.aditu.de
GNU General Public License v3.0
2.37k stars 343 forks source link

Reddit feed update fails on r/freeebooks #1104

Closed Flameborn closed 5 years ago

Flameborn commented 5 years ago

I subscribed to r/freeebooks via the Reddit spout. Currently, the update fails when cliupdate.php is executed via Cron or manually.

The relevant debug log:

[2019-05-14 11:38:37] selfoss.DEBUG: start insertion of new item "Newly Free Hobbies Kindle Book Lists for 2019-05-13"
[2019-05-14 11:38:37] selfoss.DEBUG: item content sanitized
[2019-05-14 11:43:42] selfoss.DEBUG: set cookie on rss.DOMAIN.com/ expiring in 2592000 seconds
[2019-05-14 11:43:42] selfoss.DEBUG: logged in using valid session
[2019-05-14 11:43:42] selfoss.DEBUG: Establish database connection

The last three lines keep repeating in the log, even after hours of script execution.

The issue also happens with a brand new database, after importing an OPML feed.

I am running PHP 7.3.5, on Arch Linux ARM, on a Raspberry Pi 3, using sqlite as the database.

The page is reachable at http://ogres-crypt.com/Kindle/Free-Hobbies-Books.html

jtojnar commented 5 years ago

What version of selfoss are you using? There have been some improvements to reddit spot on master, do you think you could try that? https://bintray.com/fossar/selfoss/selfoss-git/2.19-0ea67f9#files

jtojnar commented 5 years ago

It works for me on master. One thing that I noticed that some posts have "thumbnail": "self" or "thumbnail": "default". We should probably handle that.

Flameborn commented 5 years ago

I tried with 2.18, and a snapshot, 2.19-0ea67f9. I was able to replicate the issue in both cases.

I am going to try with the current master branch and report back with the results.

Flameborn commented 5 years ago

I have just tried adding the reddit source again, using the latest Master branch. Unfortunately, the problem still persists, though now with a different Kindle book list.

jtojnar commented 5 years ago

Your log does not really tell us much. The last three lines are logged whenever a web request is made against selfoss.

I would expect to see some log lines related to icons or thumbnails before “item inserted” is printed.

Flameborn commented 5 years ago

The log snippet I posted above happens when fetching from this particular reddit source. After the particular item is sanitized, the item is not inserted, the entire updating process does not continue, i.e. no insertion of later items or database optimisation or cleanup happens, as it does with an update without the reddit source.

On the main Selfoss page, I get a message stating that Selfoss was unable to refresh sources: timeout.

I have turned on DEBUG on line 17 of common.php, unfortunately I do not have anything extra added in the logs.

jtojnar commented 5 years ago

Fixed the thumbnail-less warnings in 39679556180d7162411f8c564550d819cef2068b.

I can reproduce the refresh timeout in source refresh on master but the update still works in the background:

[2019-05-16 01:12:53] selfoss.DEBUG: Establish database connection  
[2019-05-16 01:12:55] selfoss.DEBUG: Establish database connection  
[2019-05-16 01:12:55] selfoss.DEBUG: ---  
[2019-05-16 01:12:55] selfoss.DEBUG: start fetching source "r/freeebooks (id: 154)   
[2019-05-16 01:12:55] selfoss.DEBUG: spout successfully loaded: spouts\reddit\reddit2  
[2019-05-16 01:12:55] selfoss.DEBUG: fetch content  
[2019-05-16 01:12:55] selfoss.DEBUG: [2019-05-15T23:12:55+00:00] "GET /r/freeebooks.json HTTP/1.1" 200  
[2019-05-16 01:12:55] selfoss.DEBUG: minimum date: 2016-08-19 01:12:55  
[2019-05-16 01:12:55] selfoss.DEBUG: start item fetching  
[2019-05-16 01:12:55] selfoss.DEBUG: start insertion of new item "The Library of Congress has made a collection of 100 children's books from a century or more ago available free online"  
[2019-05-16 01:12:55] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:12:56] selfoss.DEBUG: [2019-05-15T23:12:56+00:00] "GET /collections/childrens-book-selections/about-this-collection/ HTTP/1.1" 200  
[2019-05-16 01:12:57] selfoss.DEBUG: [2019-05-15T23:12:57+00:00] "GET /collections/childrens-book-selections/about-this-collection/ HTTP/1.1" 200  
[2019-05-16 01:12:57] selfoss.DEBUG: [2019-05-15T23:12:57+00:00] "GET /favicon.ico HTTP/1.1" 301  
[2019-05-16 01:12:57] selfoss.DEBUG: [2019-05-15T23:12:57+00:00] "GET /static/images/favicons/favicon.ico HTTP/1.1" 200  
[2019-05-16 01:12:58] selfoss.DEBUG: [2019-05-15T23:12:58+00:00] "GET /A9U7OP8N83SQkYANjX3yJE3bnD4fVrrLGyMydKZT3c4.jpg HTTP/1.1" 200  
[2019-05-16 01:12:58] selfoss.DEBUG: Thumbnail generated: https://a.thumbs.redditmedia.com/A9U7OP8N83SQkYANjX3yJE3bnD4fVrrLGyMydKZT3c4.jpg  
[2019-05-16 01:12:58] selfoss.DEBUG: [2019-05-15T23:12:58+00:00] "GET /collections/childrens-book-selections/about-this-collection/ HTTP/1.1" 200  
[2019-05-16 01:12:59] selfoss.DEBUG: [2019-05-15T23:12:59+00:00] "GET /collections/childrens-book-selections/about-this-collection/ HTTP/1.1" 200  
[2019-05-16 01:13:00] selfoss.DEBUG: [2019-05-15T23:13:00+00:00] "GET /favicon.ico HTTP/1.1" 301  
[2019-05-16 01:13:00] selfoss.DEBUG: [2019-05-15T23:13:00+00:00] "GET /static/images/favicons/favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:00] selfoss.DEBUG: [2019-05-15T23:13:00+00:00] "GET /favicon.ico HTTP/1.1" 301  
[2019-05-16 01:13:00] selfoss.DEBUG: [2019-05-15T23:13:00+00:00] "GET /static/images/favicons/favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:00] selfoss.DEBUG: Icon generated: https://www.loc.gov/favicon.ico  
[2019-05-16 01:13:00] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:00] selfoss.DEBUG: Memory usage: 5338968  
[2019-05-16 01:13:00] selfoss.DEBUG: Memory peak usage: 5711424  
[2019-05-16 01:13:00] selfoss.DEBUG: start insertion of new item "100 free ebooks about plants & gardening from Project Gutenberg, most of these are older texts originally published in the 1800s or early 1900s. Lots of them are about vegetable gardening."  
[2019-05-16 01:13:00] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:01] selfoss.DEBUG: [2019-05-15T23:13:01+00:00] "GET /r/FreeEBOOKS/comments/bnr36n/100_free_ebooks_about_plants_gardening_from/ HTTP/1.1" 200  
[2019-05-16 01:13:03] selfoss.DEBUG: [2019-05-15T23:13:03+00:00] "GET /r/FreeEBOOKS/comments/bnr36n/100_free_ebooks_about_plants_gardening_from/ HTTP/1.1" 200  
[2019-05-16 01:13:03] selfoss.DEBUG: [2019-05-15T23:13:03+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:13:05] selfoss.DEBUG: [2019-05-15T23:13:05+00:00] "GET /r/FreeEBOOKS/comments/bnr36n/100_free_ebooks_about_plants_gardening_from/ HTTP/1.1" 200  
[2019-05-16 01:13:06] selfoss.DEBUG: [2019-05-15T23:13:06+00:00] "GET /r/FreeEBOOKS/comments/bnr36n/100_free_ebooks_about_plants_gardening_from/ HTTP/1.1" 200  
[2019-05-16 01:13:06] selfoss.DEBUG: [2019-05-15T23:13:06+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:13:06] selfoss.DEBUG: [2019-05-15T23:13:06+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:13:06] selfoss.WARNING: Unable to store icon: https://www.redditstatic.com/desktop2x/img/favicon/apple-icon-57x57.png. Please check permissions of data/favicons.  
[2019-05-16 01:13:06] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:06] selfoss.DEBUG: Memory usage: 5376640  
[2019-05-16 01:13:06] selfoss.DEBUG: Memory peak usage: 8009072  
[2019-05-16 01:13:06] selfoss.DEBUG: start insertion of new item "Happy Birthday L. Frank Baum!"  
[2019-05-16 01:13:06] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:07] selfoss.DEBUG: [2019-05-15T23:13:07+00:00] "GET /r/FreeEBOOKS/comments/bow1z3/happy_birthday_l_frank_baum/ HTTP/1.1" 200  
[2019-05-16 01:13:09] selfoss.DEBUG: [2019-05-15T23:13:09+00:00] "GET /r/FreeEBOOKS/comments/bow1z3/happy_birthday_l_frank_baum/ HTTP/1.1" 200  
[2019-05-16 01:13:09] selfoss.DEBUG: [2019-05-15T23:13:09+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:13:10] selfoss.DEBUG: [2019-05-15T23:13:10+00:00] "GET /r/FreeEBOOKS/comments/bow1z3/happy_birthday_l_frank_baum/ HTTP/1.1" 200  
[2019-05-16 01:13:11] selfoss.DEBUG: [2019-05-15T23:13:11+00:00] "GET /r/FreeEBOOKS/comments/bow1z3/happy_birthday_l_frank_baum/ HTTP/1.1" 200  
[2019-05-16 01:13:11] selfoss.DEBUG: [2019-05-15T23:13:11+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:13:11] selfoss.DEBUG: use last icon: https://www.redditstatic.com/desktop2x/img/favicon/apple-icon-57x57.png  
[2019-05-16 01:13:11] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:11] selfoss.DEBUG: Memory usage: 5361512  
[2019-05-16 01:13:11] selfoss.DEBUG: Memory peak usage: 8009072  
[2019-05-16 01:13:11] selfoss.DEBUG: start insertion of new item "“When the Elves are Gone” by J.B. Allen. Free through Friday! Dark fantasy novel about a destitute dwarf and his half ogre companion"  
[2019-05-16 01:13:11] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:12] selfoss.DEBUG: [2019-05-15T23:13:12+00:00] "GET /When-Elves-Gone-J-B-Allen-ebook/dp/B07RC8GWPM/ref=sr_1_3?crid=2JO3MAUAGBGFM&keywords=when+the+elves+are+gone&qid=1557848902&s=digital-text&sprefix=when+the+elv%2Cdigital-text%2C164&sr=1-3-catcorr HTTP/1.1" 200  
[2019-05-16 01:13:13] selfoss.DEBUG: [2019-05-15T23:13:13+00:00] "GET /When-Elves-Gone-J-B-Allen-ebook/dp/B07RC8GWPM/ref=sr_1_3?crid=2JO3MAUAGBGFM&keywords=when+the+elves+are+gone&qid=1557848902&s=digital-text&sprefix=when+the+elv%2Cdigital-text%2C164&sr=1-3-catcorr HTTP/1.1" 200  
[2019-05-16 01:13:14] selfoss.DEBUG: [2019-05-15T23:13:14+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:15] selfoss.DEBUG: [2019-05-15T23:13:15+00:00] "GET /When-Elves-Gone-J-B-Allen-ebook/dp/B07RC8GWPM/ref=sr_1_3?crid=2JO3MAUAGBGFM&keywords=when+the+elves+are+gone&qid=1557848902&s=digital-text&sprefix=when+the+elv%2Cdigital-text%2C164&sr=1-3-catcorr HTTP/1.1" 200  
[2019-05-16 01:13:17] selfoss.DEBUG: [2019-05-15T23:13:17+00:00] "GET /When-Elves-Gone-J-B-Allen-ebook/dp/B07RC8GWPM/ref=sr_1_3?crid=2JO3MAUAGBGFM&keywords=when+the+elves+are+gone&qid=1557848902&s=digital-text&sprefix=when+the+elv%2Cdigital-text%2C164&sr=1-3-catcorr HTTP/1.1" 200  
[2019-05-16 01:13:17] selfoss.DEBUG: [2019-05-15T23:13:17+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:17] selfoss.DEBUG: [2019-05-15T23:13:17+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:17] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:13:17] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:17] selfoss.DEBUG: Memory usage: 5364576  
[2019-05-16 01:13:17] selfoss.DEBUG: Memory peak usage: 9113040  
[2019-05-16 01:13:17] selfoss.DEBUG: start insertion of new item "Adventures of Huckleberry Finn by Mark Twain"  
[2019-05-16 01:13:17] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:19] selfoss.DEBUG: [2019-05-15T23:13:19+00:00] "GET /ebooks/76 HTTP/1.1" 200  
[2019-05-16 01:13:21] selfoss.DEBUG: [2019-05-15T23:13:21+00:00] "GET /ebooks/76 HTTP/1.1" 200  
[2019-05-16 01:13:21] selfoss.DEBUG: [2019-05-15T23:13:21+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:21] selfoss.DEBUG: [2019-05-15T23:13:21+00:00] "GET /HF_2nq5yOoMTMhCq_gL4e7zzWCAatAi675DIdklQK9M.jpg HTTP/1.1" 200  
[2019-05-16 01:13:21] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/HF_2nq5yOoMTMhCq_gL4e7zzWCAatAi675DIdklQK9M.jpg  
[2019-05-16 01:13:23] selfoss.DEBUG: [2019-05-15T23:13:23+00:00] "GET /ebooks/76 HTTP/1.1" 200  
[2019-05-16 01:13:24] selfoss.DEBUG: [2019-05-15T23:13:24+00:00] "GET /ebooks/76 HTTP/1.1" 200  
[2019-05-16 01:13:25] selfoss.DEBUG: [2019-05-15T23:13:25+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:25] selfoss.DEBUG: [2019-05-15T23:13:25+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:25] selfoss.DEBUG: Icon generated: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:13:25] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:25] selfoss.DEBUG: Memory usage: 5364496  
[2019-05-16 01:13:25] selfoss.DEBUG: Memory peak usage: 9113040  
[2019-05-16 01:13:25] selfoss.DEBUG: start insertion of new item "Golden Curse (Fantasy and Fairytales Book 1) by M. Lynn"  
[2019-05-16 01:13:25] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:27] selfoss.DEBUG: [2019-05-15T23:13:27+00:00] "GET /Golden-Curse-Fantasy-Fairytales-Book-ebook/dp/B07HYP46DH?_bbid=12321850&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:28] selfoss.DEBUG: [2019-05-15T23:13:28+00:00] "GET /Golden-Curse-Fantasy-Fairytales-Book-ebook/dp/B07HYP46DH?_bbid=12321850&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:29] selfoss.DEBUG: [2019-05-15T23:13:29+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:30] selfoss.DEBUG: [2019-05-15T23:13:30+00:00] "GET /Golden-Curse-Fantasy-Fairytales-Book-ebook/dp/B07HYP46DH?_bbid=12321850&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:32] selfoss.DEBUG: [2019-05-15T23:13:32+00:00] "GET /Golden-Curse-Fantasy-Fairytales-Book-ebook/dp/B07HYP46DH?_bbid=12321850&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:32] selfoss.DEBUG: [2019-05-15T23:13:32+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:33] selfoss.DEBUG: [2019-05-15T23:13:33+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:33] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:13:33] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:33] selfoss.DEBUG: Memory usage: 5364304  
[2019-05-16 01:13:33] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:13:33] selfoss.DEBUG: start insertion of new item "Transmission (The Invasion Chronicles: Book One) by Morgan Rice"  
[2019-05-16 01:13:33] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:34] selfoss.DEBUG: [2019-05-15T23:13:34+00:00] "GET /Transmission-Invasion-Chronicles-Book-One-Thriller-ebook/dp/B07D4PMZ42?_bbid=12335252&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:36] selfoss.DEBUG: [2019-05-15T23:13:36+00:00] "GET /Transmission-Invasion-Chronicles-Book-One-Thriller-ebook/dp/B07D4PMZ42?_bbid=12335252&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:36] selfoss.DEBUG: [2019-05-15T23:13:36+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:37] selfoss.DEBUG: [2019-05-15T23:13:37+00:00] "GET /Transmission-Invasion-Chronicles-Book-One-Thriller-ebook/dp/B07D4PMZ42?_bbid=12335252&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:38] selfoss.DEBUG: [2019-05-15T23:13:38+00:00] "GET /Transmission-Invasion-Chronicles-Book-One-Thriller-ebook/dp/B07D4PMZ42?_bbid=12335252&_bbtype=blog HTTP/1.1" 200  
[2019-05-16 01:13:39] selfoss.DEBUG: [2019-05-15T23:13:39+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:13:39] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:13:39] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:39] selfoss.DEBUG: Memory usage: 5364448  
[2019-05-16 01:13:39] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:13:39] selfoss.DEBUG: start insertion of new item "Beowulf: An Anglo-Saxon Epic Poem by J. Lesslie Hall"  
[2019-05-16 01:13:39] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:41] selfoss.DEBUG: [2019-05-15T23:13:41+00:00] "GET /ebooks/16328 HTTP/1.1" 200  
[2019-05-16 01:13:42] selfoss.DEBUG: [2019-05-15T23:13:42+00:00] "GET /ebooks/16328 HTTP/1.1" 200  
[2019-05-16 01:13:42] selfoss.DEBUG: [2019-05-15T23:13:42+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:42] selfoss.DEBUG: [2019-05-15T23:13:42+00:00] "GET /4C3JPAFmbb-mKBNbO03GeRMkDZ5tcJoAqkE6-4XrzY0.jpg HTTP/1.1" 200  
[2019-05-16 01:13:42] selfoss.DEBUG: Thumbnail generated: https://a.thumbs.redditmedia.com/4C3JPAFmbb-mKBNbO03GeRMkDZ5tcJoAqkE6-4XrzY0.jpg  
[2019-05-16 01:13:44] selfoss.DEBUG: [2019-05-15T23:13:44+00:00] "GET /ebooks/16328 HTTP/1.1" 200  
[2019-05-16 01:13:46] selfoss.DEBUG: [2019-05-15T23:13:46+00:00] "GET /ebooks/16328 HTTP/1.1" 200  
[2019-05-16 01:13:46] selfoss.DEBUG: [2019-05-15T23:13:46+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:46] selfoss.DEBUG: [2019-05-15T23:13:46+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:46] selfoss.DEBUG: Icon generated: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:13:46] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:46] selfoss.DEBUG: Memory usage: 5368592  
[2019-05-16 01:13:46] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:13:46] selfoss.DEBUG: start insertion of new item "A Modest Proposal by Jonathan Swift"  
[2019-05-16 01:13:46] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:48] selfoss.DEBUG: [2019-05-15T23:13:48+00:00] "GET /ebooks/1080 HTTP/1.1" 200  
[2019-05-16 01:13:50] selfoss.DEBUG: [2019-05-15T23:13:50+00:00] "GET /ebooks/1080 HTTP/1.1" 200  
[2019-05-16 01:13:50] selfoss.DEBUG: [2019-05-15T23:13:50+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:50] selfoss.DEBUG: [2019-05-15T23:13:50+00:00] "GET /xo1BzWnJzDxoHo94emPpyGvbmnGA5s1T1-8MkbiTTfA.jpg HTTP/1.1" 200  
[2019-05-16 01:13:50] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/xo1BzWnJzDxoHo94emPpyGvbmnGA5s1T1-8MkbiTTfA.jpg  
[2019-05-16 01:13:52] selfoss.DEBUG: [2019-05-15T23:13:52+00:00] "GET /ebooks/1080 HTTP/1.1" 200  
[2019-05-16 01:13:53] selfoss.DEBUG: [2019-05-15T23:13:53+00:00] "GET /ebooks/1080 HTTP/1.1" 200  
[2019-05-16 01:13:53] selfoss.DEBUG: [2019-05-15T23:13:53+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:53] selfoss.DEBUG: use last icon: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:13:53] selfoss.DEBUG: item inserted  
[2019-05-16 01:13:53] selfoss.DEBUG: Memory usage: 5368656  
[2019-05-16 01:13:53] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:13:53] selfoss.DEBUG: start insertion of new item "In the Wilds of South America by Leo E. Miller Published in 1919"  
[2019-05-16 01:13:53] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:13:55] selfoss.DEBUG: [2019-05-15T23:13:55+00:00] "GET /ebooks/59512 HTTP/1.1" 200  
[2019-05-16 01:13:57] selfoss.DEBUG: [2019-05-15T23:13:57+00:00] "GET /ebooks/59512 HTTP/1.1" 200  
[2019-05-16 01:13:57] selfoss.DEBUG: [2019-05-15T23:13:57+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:13:57] selfoss.DEBUG: [2019-05-15T23:13:57+00:00] "GET /7pokVoYTEXrMJALHmBMt9h5eghjnwyPrG8qPlWx8jEo.jpg HTTP/1.1" 200  
[2019-05-16 01:13:57] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/7pokVoYTEXrMJALHmBMt9h5eghjnwyPrG8qPlWx8jEo.jpg  
[2019-05-16 01:13:58] selfoss.DEBUG: [2019-05-15T23:13:58+00:00] "GET /ebooks/59512 HTTP/1.1" 200  
[2019-05-16 01:14:00] selfoss.DEBUG: [2019-05-15T23:14:00+00:00] "GET /ebooks/59512 HTTP/1.1" 200  
[2019-05-16 01:14:00] selfoss.DEBUG: [2019-05-15T23:14:00+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:14:00] selfoss.DEBUG: use last icon: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:14:00] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:00] selfoss.DEBUG: Memory usage: 5368688  
[2019-05-16 01:14:00] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:00] selfoss.DEBUG: start insertion of new item "Newly Free Horror Kindle Book Lists for 2019-05-15"  
[2019-05-16 01:14:00] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:02] selfoss.DEBUG: [2019-05-15T23:14:02+00:00] "GET /Kindle/Free-Horror-Books.html HTTP/1.1" 200  
[2019-05-16 01:14:03] selfoss.DEBUG: [2019-05-15T23:14:03+00:00] "GET /Kindle/Free-Horror-Books.html HTTP/1.1" 200  
[2019-05-16 01:14:03] selfoss.DEBUG: [2019-05-15T23:14:03+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:03] selfoss.DEBUG: [2019-05-15T23:14:03+00:00] "GET /N1gi6WhnvOxIgow0xbRibLWRS1cEBO8WAsvi6lrsUa8.jpg HTTP/1.1" 200  
[2019-05-16 01:14:03] selfoss.DEBUG: Thumbnail generated: https://a.thumbs.redditmedia.com/N1gi6WhnvOxIgow0xbRibLWRS1cEBO8WAsvi6lrsUa8.jpg  
[2019-05-16 01:14:04] selfoss.DEBUG: [2019-05-15T23:14:04+00:00] "GET /Kindle/Free-Horror-Books.html HTTP/1.1" 200  
[2019-05-16 01:14:04] selfoss.DEBUG: [2019-05-15T23:14:04+00:00] "GET /Kindle/Free-Horror-Books.html HTTP/1.1" 200  
[2019-05-16 01:14:05] selfoss.DEBUG: [2019-05-15T23:14:05+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:05] selfoss.DEBUG: [2019-05-15T23:14:05+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:05] selfoss.DEBUG: Icon generated: http://ogres-crypt.com/favicon.ico  
[2019-05-16 01:14:05] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:05] selfoss.DEBUG: Memory usage: 5368560  
[2019-05-16 01:14:05] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:05] selfoss.DEBUG: start insertion of new item "Java Parsing Collection XML JSON: Map List XML JSON Transform by Yang Hu"  
[2019-05-16 01:14:05] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:06] selfoss.DEBUG: [2019-05-15T23:14:06+00:00] "GET /dp/B07QZLPCBZ/ref=cm_sw_r_other_apa_i_DWb3CbK88CKQJ HTTP/1.1" 200  
[2019-05-16 01:14:07] selfoss.DEBUG: [2019-05-15T23:14:07+00:00] "GET /dp/B07QZLPCBZ/ref=cm_sw_r_other_apa_i_DWb3CbK88CKQJ HTTP/1.1" 200  
[2019-05-16 01:14:08] selfoss.DEBUG: [2019-05-15T23:14:08+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:09] selfoss.DEBUG: [2019-05-15T23:14:09+00:00] "GET /dp/B07QZLPCBZ/ref=cm_sw_r_other_apa_i_DWb3CbK88CKQJ HTTP/1.1" 200  
[2019-05-16 01:14:10] selfoss.DEBUG: [2019-05-15T23:14:10+00:00] "GET /dp/B07QZLPCBZ/ref=cm_sw_r_other_apa_i_DWb3CbK88CKQJ HTTP/1.1" 200  
[2019-05-16 01:14:11] selfoss.DEBUG: [2019-05-15T23:14:11+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:11] selfoss.DEBUG: [2019-05-15T23:14:11+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:11] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:14:11] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:11] selfoss.DEBUG: Memory usage: 5372480  
[2019-05-16 01:14:11] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:11] selfoss.DEBUG: start insertion of new item "Easy Learning JDBC + Oracle: JDBC for Beginner's Guide by Yang Hu"  
[2019-05-16 01:14:11] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:13] selfoss.DEBUG: [2019-05-15T23:14:13+00:00] "GET /dp/B07QZBKQ5C/ref=cm_sw_r_other_apa_i_5Xb3CbZGEHYDX HTTP/1.1" 200  
[2019-05-16 01:14:15] selfoss.DEBUG: [2019-05-15T23:14:15+00:00] "GET /dp/B07QZBKQ5C/ref=cm_sw_r_other_apa_i_5Xb3CbZGEHYDX HTTP/1.1" 200  
[2019-05-16 01:14:15] selfoss.DEBUG: [2019-05-15T23:14:15+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:16] selfoss.DEBUG: [2019-05-15T23:14:16+00:00] "GET /dp/B07QZBKQ5C/ref=cm_sw_r_other_apa_i_5Xb3CbZGEHYDX HTTP/1.1" 200  
[2019-05-16 01:14:17] selfoss.DEBUG: [2019-05-15T23:14:17+00:00] "GET /dp/B07QZBKQ5C/ref=cm_sw_r_other_apa_i_5Xb3CbZGEHYDX HTTP/1.1" 200  
[2019-05-16 01:14:18] selfoss.DEBUG: [2019-05-15T23:14:18+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:18] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:14:18] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:18] selfoss.DEBUG: Memory usage: 5372592  
[2019-05-16 01:14:18] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:18] selfoss.DEBUG: start insertion of new item "70 FREE Kindle eBook Downloads (5/14/19)"  
[2019-05-16 01:14:18] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /70-free-kindle-ebook-downloads-5-14-19/ HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /70-free-kindle-ebook-downloads-5-14-19/ HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /wp-content/uploads/2018/09/fav.png HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /e55v-yoL65_PqQ7kFfV8N_0IXIIKhSNfMajTU0Ac5Kc.jpg HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/e55v-yoL65_PqQ7kFfV8N_0IXIIKhSNfMajTU0Ac5Kc.jpg  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /70-free-kindle-ebook-downloads-5-14-19/ HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /70-free-kindle-ebook-downloads-5-14-19/ HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /wp-content/uploads/2018/09/fav.png HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: [2019-05-15T23:14:20+00:00] "GET /wp-content/uploads/2018/09/fav.png HTTP/1.1" 200  
[2019-05-16 01:14:20] selfoss.DEBUG: Icon generated: https://www.freebiechief.com/wp-content/uploads/2018/09/fav.png  
[2019-05-16 01:14:20] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:20] selfoss.DEBUG: Memory usage: 5372720  
[2019-05-16 01:14:20] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:20] selfoss.DEBUG: start insertion of new item "70 FREE Kindle eBook Downloads (5/15/19)"  
[2019-05-16 01:14:20] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:21] selfoss.DEBUG: [2019-05-15T23:14:21+00:00] "GET /70-free-kindle-ebook-downloads-5-15-19/ HTTP/1.1" 200  
[2019-05-16 01:14:21] selfoss.DEBUG: [2019-05-15T23:14:21+00:00] "GET /70-free-kindle-ebook-downloads-5-15-19/ HTTP/1.1" 200  
[2019-05-16 01:14:21] selfoss.DEBUG: [2019-05-15T23:14:21+00:00] "GET /wp-content/uploads/2018/09/fav.png HTTP/1.1" 200  
[2019-05-16 01:14:21] selfoss.DEBUG: [2019-05-15T23:14:21+00:00] "GET /g2H74h32me-fde1QBmbd1ligoG8yr2yc25-d3wyR4M0.jpg HTTP/1.1" 200  
[2019-05-16 01:14:21] selfoss.DEBUG: Thumbnail generated: https://a.thumbs.redditmedia.com/g2H74h32me-fde1QBmbd1ligoG8yr2yc25-d3wyR4M0.jpg  
[2019-05-16 01:14:22] selfoss.DEBUG: [2019-05-15T23:14:22+00:00] "GET /70-free-kindle-ebook-downloads-5-15-19/ HTTP/1.1" 200  
[2019-05-16 01:14:22] selfoss.DEBUG: [2019-05-15T23:14:22+00:00] "GET /70-free-kindle-ebook-downloads-5-15-19/ HTTP/1.1" 200  
[2019-05-16 01:14:22] selfoss.DEBUG: [2019-05-15T23:14:22+00:00] "GET /wp-content/uploads/2018/09/fav.png HTTP/1.1" 200  
[2019-05-16 01:14:22] selfoss.DEBUG: use last icon: https://www.freebiechief.com/wp-content/uploads/2018/09/fav.png  
[2019-05-16 01:14:22] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:22] selfoss.DEBUG: Memory usage: 5372816  
[2019-05-16 01:14:22] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:22] selfoss.DEBUG: start insertion of new item "Learn Android Basic (Volume I): Learn Android Basics (Volume I) by Sumit Saxena"  
[2019-05-16 01:14:22] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:24] selfoss.DEBUG: [2019-05-15T23:14:24+00:00] "GET /dp/B0722GRMWN/ref=cm_sw_r_other_apa_i_Y5b3CbWWQHE8G HTTP/1.1" 200  
[2019-05-16 01:14:25] selfoss.DEBUG: [2019-05-15T23:14:25+00:00] "GET /dp/B0722GRMWN/ref=cm_sw_r_other_apa_i_Y5b3CbWWQHE8G HTTP/1.1" 200  
[2019-05-16 01:14:25] selfoss.DEBUG: [2019-05-15T23:14:25+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:26] selfoss.DEBUG: [2019-05-15T23:14:26+00:00] "GET /dp/B0722GRMWN/ref=cm_sw_r_other_apa_i_Y5b3CbWWQHE8G HTTP/1.1" 200  
[2019-05-16 01:14:28] selfoss.DEBUG: [2019-05-15T23:14:28+00:00] "GET /dp/B0722GRMWN/ref=cm_sw_r_other_apa_i_Y5b3CbWWQHE8G HTTP/1.1" 200  
[2019-05-16 01:14:28] selfoss.DEBUG: [2019-05-15T23:14:28+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:28] selfoss.DEBUG: [2019-05-15T23:14:28+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:28] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:14:28] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:28] selfoss.DEBUG: Memory usage: 5376576  
[2019-05-16 01:14:28] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:28] selfoss.DEBUG: start insertion of new item "3D Recording and Interpretation for Maritime Archaeology (Coastal Research Library Book 31) by John K. Mccarthy, Jonathan Benjamin, Trevor Winton and Wendy van Duivenvoorde"  
[2019-05-16 01:14:28] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:29] selfoss.DEBUG: [2019-05-15T23:14:29+00:00] "GET /dp/B07PGXRS4F/ref=cm_sw_r_other_apa_i_i0b3Cb1GBADA0 HTTP/1.1" 200  
[2019-05-16 01:14:31] selfoss.DEBUG: [2019-05-15T23:14:31+00:00] "GET /dp/B07PGXRS4F/ref=cm_sw_r_other_apa_i_i0b3Cb1GBADA0 HTTP/1.1" 200  
[2019-05-16 01:14:31] selfoss.DEBUG: [2019-05-15T23:14:31+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:32] selfoss.DEBUG: [2019-05-15T23:14:32+00:00] "GET /dp/B07PGXRS4F/ref=cm_sw_r_other_apa_i_i0b3Cb1GBADA0 HTTP/1.1" 200  
[2019-05-16 01:14:33] selfoss.DEBUG: [2019-05-15T23:14:33+00:00] "GET /dp/B07PGXRS4F/ref=cm_sw_r_other_apa_i_i0b3Cb1GBADA0 HTTP/1.1" 200  
[2019-05-16 01:14:34] selfoss.DEBUG: [2019-05-15T23:14:34+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:34] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:14:34] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:34] selfoss.DEBUG: Memory usage: 5376816  
[2019-05-16 01:14:34] selfoss.DEBUG: Memory peak usage: 9538912  
[2019-05-16 01:14:34] selfoss.DEBUG: start insertion of new item "White Fang by Jack London"  
[2019-05-16 01:14:34] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:36] selfoss.DEBUG: [2019-05-15T23:14:36+00:00] "GET /dp/B072B62DBT HTTP/1.1" 200  
[2019-05-16 01:14:37] selfoss.DEBUG: [2019-05-15T23:14:37+00:00] "GET /dp/B072B62DBT HTTP/1.1" 200  
[2019-05-16 01:14:37] selfoss.DEBUG: [2019-05-15T23:14:37+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:39] selfoss.DEBUG: [2019-05-15T23:14:39+00:00] "GET /dp/B072B62DBT HTTP/1.1" 200  
[2019-05-16 01:14:40] selfoss.DEBUG: [2019-05-15T23:14:40+00:00] "GET /dp/B072B62DBT HTTP/1.1" 200  
[2019-05-16 01:14:41] selfoss.DEBUG: [2019-05-15T23:14:41+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:41] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:14:41] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:41] selfoss.DEBUG: Memory usage: 5376584  
[2019-05-16 01:14:41] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:14:41] selfoss.DEBUG: start insertion of new item "Ulysses by James Joyce"  
[2019-05-16 01:14:41] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:42] selfoss.DEBUG: [2019-05-15T23:14:42+00:00] "GET /ebooks/4300 HTTP/1.1" 200  
[2019-05-16 01:14:44] selfoss.DEBUG: [2019-05-15T23:14:44+00:00] "GET /ebooks/4300 HTTP/1.1" 200  
[2019-05-16 01:14:44] selfoss.DEBUG: [2019-05-15T23:14:44+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:14:44] selfoss.DEBUG: [2019-05-15T23:14:44+00:00] "GET /-wQSysZvZwbEQQQ476Ys4KYkAn1PyhciuHSBDqMOGtE.jpg HTTP/1.1" 200  
[2019-05-16 01:14:44] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/-wQSysZvZwbEQQQ476Ys4KYkAn1PyhciuHSBDqMOGtE.jpg  
[2019-05-16 01:14:46] selfoss.DEBUG: [2019-05-15T23:14:46+00:00] "GET /ebooks/4300 HTTP/1.1" 200  
[2019-05-16 01:14:47] selfoss.DEBUG: [2019-05-15T23:14:47+00:00] "GET /ebooks/4300 HTTP/1.1" 200  
[2019-05-16 01:14:48] selfoss.DEBUG: [2019-05-15T23:14:48+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:14:48] selfoss.DEBUG: [2019-05-15T23:14:48+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:14:48] selfoss.DEBUG: Icon generated: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:14:48] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:48] selfoss.DEBUG: Memory usage: 5376736  
[2019-05-16 01:14:48] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:14:48] selfoss.DEBUG: start insertion of new item "The Odyssey by Homer"  
[2019-05-16 01:14:48] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:50] selfoss.DEBUG: [2019-05-15T23:14:50+00:00] "GET /dp/B06XTFRGYQ HTTP/1.1" 200  
[2019-05-16 01:14:51] selfoss.DEBUG: [2019-05-15T23:14:51+00:00] "GET /dp/B06XTFRGYQ HTTP/1.1" 200  
[2019-05-16 01:14:52] selfoss.DEBUG: [2019-05-15T23:14:52+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:53] selfoss.DEBUG: [2019-05-15T23:14:53+00:00] "GET /dp/B06XTFRGYQ HTTP/1.1" 200  
[2019-05-16 01:14:54] selfoss.DEBUG: [2019-05-15T23:14:54+00:00] "GET /dp/B06XTFRGYQ HTTP/1.1" 200  
[2019-05-16 01:14:54] selfoss.DEBUG: [2019-05-15T23:14:54+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:54] selfoss.DEBUG: [2019-05-15T23:14:54+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:14:54] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:14:54] selfoss.DEBUG: item inserted  
[2019-05-16 01:14:54] selfoss.DEBUG: Memory usage: 5380544  
[2019-05-16 01:14:54] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:14:54] selfoss.DEBUG: start insertion of new item "World War II: 1943 (One Hour WW II History Books Book 5) by History by the Hour"  
[2019-05-16 01:14:54] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:14:57] selfoss.DEBUG: [2019-05-15T23:14:57+00:00] "GET /dp/B07QDQ7QQ1/ref=cm_sw_r_other_apa_i_Ftb3CbBAQS0R9 HTTP/1.1" 200  
[2019-05-16 01:14:58] selfoss.DEBUG: [2019-05-15T23:14:58+00:00] "GET /dp/B07QDQ7QQ1/ref=cm_sw_r_other_apa_i_Ftb3CbBAQS0R9 HTTP/1.1" 200  
[2019-05-16 01:14:59] selfoss.DEBUG: [2019-05-15T23:14:59+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:00] selfoss.DEBUG: [2019-05-15T23:15:00+00:00] "GET /dp/B07QDQ7QQ1/ref=cm_sw_r_other_apa_i_Ftb3CbBAQS0R9 HTTP/1.1" 200  
[2019-05-16 01:15:01] selfoss.DEBUG: [2019-05-15T23:15:01+00:00] "GET /dp/B07QDQ7QQ1/ref=cm_sw_r_other_apa_i_Ftb3CbBAQS0R9 HTTP/1.1" 200  
[2019-05-16 01:15:02] selfoss.DEBUG: [2019-05-15T23:15:02+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:02] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:15:02] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:02] selfoss.DEBUG: Memory usage: 5380800  
[2019-05-16 01:15:02] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:02] selfoss.DEBUG: start insertion of new item "USDA Farmers' Bulletin No. 175: Home Manufacture and Use of Unfermented Grape"  
[2019-05-16 01:15:02] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:04] selfoss.DEBUG: [2019-05-15T23:15:04+00:00] "GET /ebooks/59503 HTTP/1.1" 200  
[2019-05-16 01:15:05] selfoss.DEBUG: [2019-05-15T23:15:05+00:00] "GET /ebooks/59503 HTTP/1.1" 200  
[2019-05-16 01:15:05] selfoss.DEBUG: [2019-05-15T23:15:05+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:15:05] selfoss.DEBUG: [2019-05-15T23:15:05+00:00] "GET /GIcYiE3tXkyvBNRbSDXaLJrz_2w30KYQDrQI7yS3XrQ.jpg HTTP/1.1" 200  
[2019-05-16 01:15:05] selfoss.DEBUG: Thumbnail generated: https://b.thumbs.redditmedia.com/GIcYiE3tXkyvBNRbSDXaLJrz_2w30KYQDrQI7yS3XrQ.jpg  
[2019-05-16 01:15:07] selfoss.DEBUG: [2019-05-15T23:15:07+00:00] "GET /ebooks/59503 HTTP/1.1" 200  
[2019-05-16 01:15:08] selfoss.DEBUG: [2019-05-15T23:15:08+00:00] "GET /ebooks/59503 HTTP/1.1" 200  
[2019-05-16 01:15:09] selfoss.DEBUG: [2019-05-15T23:15:09+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:15:09] selfoss.DEBUG: [2019-05-15T23:15:09+00:00] "GET /pics/apple-touch-icon HTTP/1.1" 200  
[2019-05-16 01:15:09] selfoss.DEBUG: Icon generated: http://www.gutenberg.org/pics/apple-touch-icon  
[2019-05-16 01:15:09] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:09] selfoss.DEBUG: Memory usage: 5380912  
[2019-05-16 01:15:09] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:09] selfoss.DEBUG: start insertion of new item "Gaijin Girl: Stories of a Curly-Haired Sensei, by Beth Matuska, a humorous look at life as a foreigner in small-town Japan. Free worldwide! The first of seven books by the author."  
[2019-05-16 01:15:09] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:10] selfoss.DEBUG: [2019-05-15T23:15:10+00:00] "GET /Gaijin-Girl-Stories-Curly-Haired-Sensei-ebook/dp/B074TY12L9/ref=tmm_kin_swatch_0?_encoding=UTF8&qid=1557893306&sr=8-2 HTTP/1.1" 200  
[2019-05-16 01:15:12] selfoss.DEBUG: [2019-05-15T23:15:12+00:00] "GET /Gaijin-Girl-Stories-Curly-Haired-Sensei-ebook/dp/B074TY12L9/ref=tmm_kin_swatch_0?_encoding=UTF8&qid=1557893306&sr=8-2 HTTP/1.1" 200  
[2019-05-16 01:15:12] selfoss.DEBUG: [2019-05-15T23:15:12+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:13] selfoss.DEBUG: [2019-05-15T23:15:13+00:00] "GET /Gaijin-Girl-Stories-Curly-Haired-Sensei-ebook/dp/B074TY12L9/ref=tmm_kin_swatch_0?_encoding=UTF8&qid=1557893306&sr=8-2 HTTP/1.1" 200  
[2019-05-16 01:15:14] selfoss.DEBUG: [2019-05-15T23:15:14+00:00] "GET /Gaijin-Girl-Stories-Curly-Haired-Sensei-ebook/dp/B074TY12L9/ref=tmm_kin_swatch_0?_encoding=UTF8&qid=1557893306&sr=8-2 HTTP/1.1" 200  
[2019-05-16 01:15:15] selfoss.DEBUG: [2019-05-15T23:15:15+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:15] selfoss.DEBUG: [2019-05-15T23:15:15+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:15] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:15:15] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:15] selfoss.DEBUG: Memory usage: 5380864  
[2019-05-16 01:15:15] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:15] selfoss.DEBUG: start insertion of new item "Devil's Presents: Gift Wrapped volume One. Tales and Poems by W. Edith Gilead"  
[2019-05-16 01:15:15] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:16] selfoss.DEBUG: [2019-05-15T23:15:16+00:00] "GET /r/FreeEBOOKS/comments/boztle/devils_presents_gift_wrapped_volume_one_tales_and/ HTTP/1.1" 200  
[2019-05-16 01:15:17] selfoss.DEBUG: [2019-05-15T23:15:17+00:00] "GET /r/FreeEBOOKS/comments/boztle/devils_presents_gift_wrapped_volume_one_tales_and/ HTTP/1.1" 200  
[2019-05-16 01:15:17] selfoss.DEBUG: [2019-05-15T23:15:17+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:15:18] selfoss.DEBUG: [2019-05-15T23:15:18+00:00] "GET /r/FreeEBOOKS/comments/boztle/devils_presents_gift_wrapped_volume_one_tales_and/ HTTP/1.1" 200  
[2019-05-16 01:15:18] selfoss.DEBUG: [2019-05-15T23:15:18+00:00] "GET /r/FreeEBOOKS/comments/boztle/devils_presents_gift_wrapped_volume_one_tales_and/ HTTP/1.1" 200  
[2019-05-16 01:15:18] selfoss.DEBUG: [2019-05-15T23:15:18+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:15:18] selfoss.DEBUG: [2019-05-15T23:15:18+00:00] "GET /desktop2x/img/favicon/apple-icon-57x57.png HTTP/1.1" 200  
[2019-05-16 01:15:18] selfoss.WARNING: Unable to store icon: https://www.redditstatic.com/desktop2x/img/favicon/apple-icon-57x57.png. Please check permissions of data/favicons.  
[2019-05-16 01:15:18] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:18] selfoss.DEBUG: Memory usage: 5386768  
[2019-05-16 01:15:18] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:18] selfoss.DEBUG: start insertion of new item "[Kindle] The God AI by Daniel Frost (Free on May 15th)"  
[2019-05-16 01:15:18] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:20] selfoss.DEBUG: [2019-05-15T23:15:20+00:00] "GET /God-AI-Daniel-Frost-ebook/dp/B076GVQLX6 HTTP/1.1" 200  
[2019-05-16 01:15:21] selfoss.DEBUG: [2019-05-15T23:15:21+00:00] "GET /God-AI-Daniel-Frost-ebook/dp/B076GVQLX6 HTTP/1.1" 200  
[2019-05-16 01:15:22] selfoss.DEBUG: [2019-05-15T23:15:22+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:23] selfoss.DEBUG: [2019-05-15T23:15:23+00:00] "GET /God-AI-Daniel-Frost-ebook/dp/B076GVQLX6 HTTP/1.1" 200  
[2019-05-16 01:15:25] selfoss.DEBUG: [2019-05-15T23:15:25+00:00] "GET /God-AI-Daniel-Frost-ebook/dp/B076GVQLX6 HTTP/1.1" 200  
[2019-05-16 01:15:25] selfoss.DEBUG: [2019-05-15T23:15:25+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:26] selfoss.DEBUG: [2019-05-15T23:15:26+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:26] selfoss.WARNING: Unable to store icon: https://www.amazon.com/favicon.ico. Please check permissions of data/favicons.  
[2019-05-16 01:15:26] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:26] selfoss.DEBUG: Memory usage: 5384720  
[2019-05-16 01:15:26] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:26] selfoss.DEBUG: start insertion of new item "The Wild's Call (Aspect of Crow) Kindle Edition FREE"  
[2019-05-16 01:15:26] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:27] selfoss.DEBUG: [2019-05-15T23:15:27+00:00] "GET /dp/B001VLXML6/?ref=idea_lv_dp_vv_d HTTP/1.1" 200  
[2019-05-16 01:15:28] selfoss.DEBUG: [2019-05-15T23:15:28+00:00] "GET /dp/B001VLXML6/?ref=idea_lv_dp_vv_d HTTP/1.1" 200  
[2019-05-16 01:15:29] selfoss.DEBUG: [2019-05-15T23:15:29+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:30] selfoss.DEBUG: [2019-05-15T23:15:30+00:00] "GET /dp/B001VLXML6/?ref=idea_lv_dp_vv_d HTTP/1.1" 200  
[2019-05-16 01:15:31] selfoss.DEBUG: [2019-05-15T23:15:31+00:00] "GET /dp/B001VLXML6/?ref=idea_lv_dp_vv_d HTTP/1.1" 200  
[2019-05-16 01:15:31] selfoss.DEBUG: [2019-05-15T23:15:31+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:31] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:15:31] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:31] selfoss.DEBUG: Memory usage: 5384848  
[2019-05-16 01:15:31] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:31] selfoss.DEBUG: start insertion of new item "The Pizza Prophet -- A pizza delivery expert brings more to the table than pepperoni in this hilarious send-up to the courier crowd from David Belisle."  
[2019-05-16 01:15:31] selfoss.DEBUG: item content sanitized  
[2019-05-16 01:15:33] selfoss.DEBUG: [2019-05-15T23:15:33+00:00] "GET /gp/product/B07GBJXSS9 HTTP/1.1" 200  
[2019-05-16 01:15:34] selfoss.DEBUG: [2019-05-15T23:15:34+00:00] "GET /gp/product/B07GBJXSS9 HTTP/1.1" 200  
[2019-05-16 01:15:34] selfoss.DEBUG: [2019-05-15T23:15:34+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:35] selfoss.DEBUG: [2019-05-15T23:15:35+00:00] "GET /gp/product/B07GBJXSS9 HTTP/1.1" 200  
[2019-05-16 01:15:36] selfoss.DEBUG: [2019-05-15T23:15:36+00:00] "GET /gp/product/B07GBJXSS9 HTTP/1.1" 200  
[2019-05-16 01:15:37] selfoss.DEBUG: [2019-05-15T23:15:37+00:00] "GET /favicon.ico HTTP/1.1" 200  
[2019-05-16 01:15:37] selfoss.DEBUG: use last icon: https://www.amazon.com/favicon.ico  
[2019-05-16 01:15:37] selfoss.DEBUG: item inserted  
[2019-05-16 01:15:37] selfoss.DEBUG: Memory usage: 5389040  
[2019-05-16 01:15:37] selfoss.DEBUG: Memory peak usage: 9636392  
[2019-05-16 01:15:37] selfoss.DEBUG: destroy spout object  
[2019-05-16 01:15:37] selfoss.DEBUG: cleanup orphaned and old items  
[2019-05-16 01:15:37] selfoss.DEBUG: cleanup orphaned and old items finished  
[2019-05-16 01:15:37] selfoss.DEBUG: delete orphaned thumbnails  
[2019-05-16 01:15:38] selfoss.DEBUG: thumbnail not found: 4a2b10be4e63b96c074d7512013adca9.jpg  
[2019-05-16 01:15:42] selfoss.DEBUG: delete orphaned thumbnails finished  
[2019-05-16 01:15:42] selfoss.DEBUG: delete orphaned icons

(this with logger_level=DEBUG and $f3->set('DEBUG', 0);)

jtojnar commented 5 years ago

Fixed the timeout in https://github.com/SSilence/selfoss/commit/5c5bebaa1fd7ee1035785cb53450f9c98a003b1c

Could you try to refresh just the single source with the snapshot?

Flameborn commented 5 years ago

The timeout error does not happen with the latest changes. My log entries are unfortunately the same, with the DEBUG log level and DEBUG set to 1.

...
[2019-05-16 00:45:45] selfoss.DEBUG: item "Java Parsing Collection XML JSON: Map
 List XML JSON Transform by Yang Hu" already in database.
[2019-05-16 00:45:45] selfoss.DEBUG: start insertion of new item "Newly Free Horror Kindle Book Lists for 2019-05-15"
[2019-05-16 00:45:45] selfoss.DEBUG: item content sanitized
jtojnar commented 5 years ago

That is weird, I would expect at least a message about a HTTP request. Do you see those for previous items? Could you try the following patch for more granular logging?

--- a/helpers/ContentLoader.php
+++ b/helpers/ContentLoader.php
@@ -185,6 +185,7 @@
                 return;
             }

+            \F3::get('logger')->debug('cl:newitem');
             $newItem = [
                 'title' => $title,
                 'content' => $content,
@@ -198,12 +199,15 @@
             ];

             // save thumbnail
+            \F3::get('logger')->debug('cl:fetchthumb');
             $newItem = $this->fetchThumbnail($item->getThumbnail(), $newItem);

             // save icon
+            \F3::get('logger')->debug('cl:fetchicon');
             $newItem = $this->fetchIcon($item->getIcon(), $newItem, $lasticon);

             // insert new item
+            \F3::get('logger')->debug('cl:add');
             $this->itemsDao->add($newItem);
             \F3::get('logger')->debug('item inserted');

--- a/spouts/reddit/reddit2.php
+++ b/spouts/reddit/reddit2.php
@@ -253,9 +253,11 @@
     public function getIcon() {
         $imageHelper = $this->getImageHelper();
         $htmlUrl = $this->getHtmlUrl();
+        \F3::get('logger')->debug('reddit:getIcon:start');
         if ($htmlUrl && $imageHelper->fetchFavicon($htmlUrl)) {
             $this->faviconUrl = $imageHelper->getFaviconUrl();
         }
+        \F3::get('logger')->debug('reddit:getIcon:end');

         return $this->faviconUrl;
     }
Flameborn commented 5 years ago

Thank you. Here is my new log:

[2019-05-16 09:43:05] selfoss.DEBUG: Memory usage: 1484016
[2019-05-16 09:43:05] selfoss.DEBUG: Memory peak usage: 7998856
[2019-05-16 09:43:05] selfoss.DEBUG: start insertion of new item "Newly Free Horror Kindle Book Lists for 2019-05-15"
[2019-05-16 09:43:05] selfoss.DEBUG: item content sanitized
[2019-05-16 09:43:05] selfoss.DEBUG: reddit:getIcon:start
jtojnar commented 5 years ago

I would expect at least a message about a HTTP request. Do you see those for previous items?

jtojnar commented 5 years ago

Here is even more detailed logging:

--- a/helpers/ContentLoader.php
+++ b/helpers/ContentLoader.php
@@ -185,6 +185,7 @@
                 return;
             }

+            \F3::get('logger')->debug('cl:newitem');
             $newItem = [
                 'title' => $title,
                 'content' => $content,
@@ -198,12 +199,15 @@
             ];

             // save thumbnail
+            \F3::get('logger')->debug('cl:fetchthumb');
             $newItem = $this->fetchThumbnail($item->getThumbnail(), $newItem);

             // save icon
+            \F3::get('logger')->debug('cl:fetchicon');
             $newItem = $this->fetchIcon($item->getIcon(), $newItem, $lasticon);

             // insert new item
+            \F3::get('logger')->debug('cl:add');
             $this->itemsDao->add($newItem);
             \F3::get('logger')->debug('item inserted');

--- a/helpers/Image.php
+++ b/helpers/Image.php
@@ -42,6 +42,7 @@
      */
     public function fetchFavicon($url, $isHtmlUrl = false, $width = null, $height = null) {
         // try given url
+        \F3::get('logger')->debug('img:favicon:try given url');
         if ($isHtmlUrl === false) {
             $faviconAsPng = $this->loadImage($url, $width, $height);
             if ($faviconAsPng !== null) {
@@ -54,6 +55,7 @@
         $urlElements = parse_url($url);

         // search on base page for <link rel="shortcut icon" url...
+        \F3::get('logger')->debug('img:favicon:search on base page for <link rel="shortcut icon" url...');
         $html = null;
         try {
             $html = \helpers\WebClient::request($url);
@@ -61,7 +63,12 @@
             \F3::get('logger')->debug('icon: failed to get html page: ', ['exception' => $e]);
         }

+        // parse
+        \F3::get('logger')->debug('img:favicon:parse');
         $shortcutIcon = $this->parseShortcutIcon($html);
+
+        // try to load the discovered icon
+        \F3::get('logger')->debug('img:favicon:try to load the discovered icon');
         if ($shortcutIcon !== null) {
             $shortcutIcon = (string) UriResolver::resolve(new Uri($url), new Uri($shortcutIcon));

@@ -74,6 +81,7 @@
         }

         // search domain/favicon.ico
+        \F3::get('logger')->debug('img:favicon:search domain/favicon.ico');
         if (isset($urlElements['scheme']) && isset($urlElements['host'])) {
             $url = $urlElements['scheme'] . '://' . $urlElements['host'] . '/favicon.ico';
             $faviconAsPng = $this->loadImage($url, $width, $height);
@@ -99,6 +107,7 @@
      */
     public function loadImage($url, $extension = 'png', $width = null, $height = null) {
         // load image
+        \F3::get('logger')->debug('img:loadimage:load image');
         try {
             $data = \helpers\WebClient::request($url);
         } catch (\Exception $e) {
@@ -108,6 +117,7 @@
         }

         // get image type
+        \F3::get('logger')->debug('img:loadimage:get image type');
         $imgInfo = @getimagesizefromstring($data);
         if (in_array(strtolower($imgInfo['mime']), self::$faviconMimeTypes, true)) {
             $type = 'ico';
@@ -124,6 +134,7 @@
         }

         // convert ico to png
+        \F3::get('logger')->debug('img:loadimage:convert ico to png');
         if ($type === 'ico') {
             $loader = new IcoFileService();
             try {
@@ -156,6 +167,7 @@
         }

         // parse image for saving it later
+        \F3::get('logger')->debug('img:loadimage:parse image for saving it later');
         try {
             $wideImage = WideImage::load($data);
         } catch (\Exception $e) {
@@ -163,6 +175,7 @@
         }

         // resize
+        \F3::get('logger')->debug('img:loadimage:resize');
         if ($width !== null && $height !== null) {
             if (($height !== null && $wideImage->getHeight() > $height) ||
                ($width !== null && $wideImage->getWidth() > $width)) {
@@ -171,6 +184,7 @@
         }

         // return image as jpg or png
+        \F3::get('logger')->debug('img:loadimage:return image as jpg or png');
         if ($extension === 'jpg') {
             $data = $wideImage->asString('jpg', 75);
         } else {
--- a/spouts/reddit/reddit2.php
+++ b/spouts/reddit/reddit2.php
@@ -253,9 +253,11 @@
     public function getIcon() {
         $imageHelper = $this->getImageHelper();
         $htmlUrl = $this->getHtmlUrl();
+        \F3::get('logger')->debug('reddit:getIcon:start');
         if ($htmlUrl && $imageHelper->fetchFavicon($htmlUrl)) {
             $this->faviconUrl = $imageHelper->getFaviconUrl();
         }
+        \F3::get('logger')->debug('reddit:getIcon:end');

         return $this->faviconUrl;
     }
Flameborn commented 5 years ago

Yes, I receive HTTP request messages about previous entries.

The log now contains:

[2019-05-16 11:33:38] selfoss.DEBUG: start insertion of new item "Newly Free Horror Kindle Book Lists for 2019-05-15"
[2019-05-16 11:33:38] selfoss.DEBUG: item content sanitized
[2019-05-16 11:33:38] selfoss.DEBUG: reddit:getIcon:start
[2019-05-16 11:33:38] selfoss.DEBUG: img:favicon:try given url
[2019-05-16 11:33:38] selfoss.DEBUG: img:loadimage:load image
jtojnar commented 5 years ago

Looks like it cannot load the amazon page. I will try to write in-Guzzle logging for even more details.

For now, you could you try to play with timeout, connect_timeout and read_timeout. We ought to be setting them anyway:

--- a/helpers/WebClient.php
+++ b/helpers/WebClient.php
@@ -42,6 +42,7 @@
                     'User-Agent' => self::getUserAgent(),
                 ],
                 'handler' => $stack,
+                'timeout' => 60, // in seconds
             ]);

             self::$httpClient = $httpClient;
Flameborn commented 5 years ago

Thank you very much. It seems like this has solved the issue. I am getting errors as some of the images returned are null, but this is to be expected, as I think a lot of entries use Amazon, especially in this reddit feed.

Would it be possible to have a configuration option that does not retrieve and store favicons and thumbnails at all?

I noticed that we have a show_thumbnails option available in the Selfoss configuration file, however, I think images are still stored if it is set to 0.

Please let me know if I should raise an issue regarding this.

jtojnar commented 5 years ago

Yeah, I think it should be possible to opt to use reddit favicon instead of site icon or the image. I would actually prefer it but some people might not. I am thinking about making it a selfoss extension or something.

Using timeouts by default is definitely a good idea, otherwise one bad feed can block everything indefinitely as we saw here. We had them previously in some code paths but during the Guzzle port, I missed them. We will need to come up with some values that will work the majority of time. Maybe we could even do something like iterative deepening.

We should also try to fetch multiple feeds in parallel to speed everything up but that will require wider redesign of internals, one that I have planned bud did not yet have time to carry out.

Last but not least, the favicon routine is not very efficient either (it downloads the same page up to three times). We should add some caching.

jtojnar commented 5 years ago

Let's make this issue about the timeouts. I can create issues for the other improvements.