News: Updates for some feeds fail silently

Created on 20 Mar 2019 · 12Comments · Source: nextcloud/news

IMPORTANT

[x] I have read the CONTRIBUTING.md and followed the provided tips

Explain the Problem

Some feeds are not updated (might be retrieved upon inital creation)

Steps to Reproduce

Add one of the example feeds and wait for a while:

Reddit RSS: https://www.reddit.com/r/all/.rss
TwitRSS: https://twitrss.me/twitter_user_to_rss/?user=test (sometimes also times out, which is an error on their side)

System Information

News app version: 13.1.3
Nextcloud version: 15.0.5
PHP version: 7.2
Database and version: postgres-11
Browser and version: Firefox
Distribution and version: Ubuntu 18.04 LTS

Contents of nextcloud/data/nextcloud.log

None.

0. Needs triage bug

Source

chr4

👍1

All 12 comments

Feed-io itself is able to read both of them. Tested with the cli interface of feed-io same for 4.x and 3.x

Grotax on 21 Mar 2019

While testing with feed-io-cli I got this one:

Client error: `GET https://www.reddit.com/r/all/.rss` resulted in a `429 Too Many Requests` response

Grotax on 21 Mar 2019

I'm also seeing this issue with https://blog.fefe.de/rss.xml?html and http://www.userfriendly.org/rss/uf.rss for example.

The log doesn't show any indication on what is wrong

{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"read access : https:\/\/blog.fefe.de\/rss.xml?html into a feed instance (feed class : FeedIo\\Feed)","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"start reading https:\/\/blog.fefe.de\/rss.xml?html","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"no 'modifiedSince' parameter given, setting it to 01\/01\/1970","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"hitting https:\/\/blog.fefe.de\/rss.xml?html","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"response ok, now turning it into a document","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"the stream is modified, parsing it","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"accurate parser : FeedIo\\Parser\\XmlParser","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"correct last modified date for feed Fefes Blog","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"correct public id for node Fefes Blog","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:46:01+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"Feed https:\/\/blog.fefe.de\/rss.xml?html was modified since last fetch. #0 items","userAgent":"--","version":"15.0.5.3"}

{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"read access : http:\/\/www.userfriendly.org\/rss\/uf.rss into a feed instance (feed class : FeedIo\\Feed)","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"start reading http:\/\/www.userfriendly.org\/rss\/uf.rss","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"no 'modifiedSince' parameter given, setting it to 01\/01\/1970","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"hitting http:\/\/www.userfriendly.org\/rss\/uf.rss","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"response ok, now turning it into a document","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"the stream is modified, parsing it","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"accurate parser : FeedIo\\Parser\\XmlParser","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"correct last modified date for feed User Friendly RSS Feed","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":1,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"correct public id for node User Friendly RSS Feed","userAgent":"--","version":"15.0.5.3"}
{"reqId":"6PWOQ9rehazWRQDkAVZZ","level":0,"time":"2019-03-21T14:45:35+00:00","remoteAddr":"","user":"--","app":"news","method":"","url":"--","message":"Feed http:\/\/www.userfriendly.org\/rss\/uf.rss was modified since last fetch. #0 items","userAgent":"--","version":"15.0.5.3"}

tux93 on 21 Mar 2019

👍1

Reddit has been consistently updating for me for over a day.

SMillerDev on 21 Mar 2019

The issue seems to be in refreshing through cron, when refreshing the feeds through occ news:updater:update-feed new articles show up as expected

tux93 on 21 Mar 2019

(I'm now on News 13.1.3 and NC 15.0.5)

I can confirm that a feed that hasn't updated itself since the 13.1 update, works fine if I trigger it manually with sudo -u www-data php7.1 -f occ news:updater:update-feed 251 myusername.

Triggering sudo -u www-data php7.1 -f /var/www/nextcloud/cron.php instead does not work for "stuck" feeds. Neither manually from the shell, nor from www-data's crontab.

At the same time, a bunch of other feeds update just fine on their own.
Feeds that work (at least since 13.1.3)

feeds.wired.com/wired/index (id 21)
http://www.notcot.org/atom.php (id 71)
https://www.gitlab.com/atom.xml (id 93)
some personal blog thing (id 94)

Feeds that still don't work:

https://www.freefilesync.org/news_feed.php (id 145)
http://www.lunarbaboon.com/comics/rss.xml (id 159)
http://www.heise.de/newsticker/heise-atom.xml (id 169)
some webcomic (id 187)
https://electronjs.org/blog.xml (id 193)

So, for some reason, "low ids" get processed, high IDs don't. I haven't exactly managed to find the breaking point because some of these feeds are really low volume with few updates. Maybe someone else can confirm this behaviour, too. Perhaps someone else coud list working and non-working feeds with their IDs.

ccoenen on 21 Mar 2019

I did toss out a few broken feeds along the way. They didn't seem to be the problem as far as I could tell. At least that didn't fix it for me.

ccoenen on 21 Mar 2019

After updating to 13.1.4, the feeds mentioned above all updated from cron correctly.

ccoenen on 22 Mar 2019

Thanks for the feedback.
I think we can close this. I don't think there is anything we can do about the feeds in the original post. They seem to work but might have a high probability in failing because of ddos protection or timeouts.

Grotax on 22 Mar 2019

They seem to work but might have a high probability in failing because of ddos protection or timeouts.

Well, as soon as I revert back to 13.0.3, all feeds are updating fine. After an upgrade to 13.1.x - a lot of feeds arent updated anymore.

Triggering sudo -u www-data php7.1 -f /var/www/nextcloud/cron.php instead does not work for "stuck" feeds. Neither manually from the shell, nor from www-data's crontab.

I think the issue of @ccoenen (when no feeds are updated via cron at all) can be solved with setting reserved_at back to 0 in the database:

UPDATE oc_jobs SET reserved_at=0 WHERE class='OCA\News\Cron\Updater';

Unfortunately, this only works once, then reserved_at is set again and all further jobs are not run (with 13.1.4)

chr4 on 22 Mar 2019

👍1

Raspian Stretch (latest upgrades)
PHP 7.0
Nginx 1.10.3

Almost the same behavior as @chr4
As soon as I revert back to 13.0.3, all feeds update with cron.
On 13.1.x no feeds are updating with cron.

If have also checked #366 and applied it. The effect is that only one (I assume the first with unread items) is update, which sets reserved_at to a value other than 0 and no other feed are processed.

One addition I just observed:

Stuck in "no update" with 13.1.x
occ app:disable news && "copy 13.0.3 to apps folder" && occ app:enable news
sudo -u www-data php -f /[pathToNextcloud]/cron.php
Feeds are not updated even with 13.0.3
Apply #366 (set reserved_at to 0)
Feed update works again with 13.0.3