You should probably define DAEMON_EXTENDED_DEBUG as true in your config.php file then output the logging to a file so you can see where, exactly, the script is failing.
gbcox
8
Thanks for the tip, I’ll do that and report back.
gbcox
9
No, I’m running update.php --feeds. update_daemon2.php is what fails, no matter if I run it from systemd or a terminal window. What is happening with update_daemon2.php is that initially it runs fine, everything updates - but after about 30 minutes or so the child process start to hang, and they just stack up in the lock directory. I just turned on extended debug as suggested in another comment. Hopefully, that will give a clue as to what is happening.
gbcox
10
Well, here is what I put into my config.php:
define(‘LOG_DESTINATION’, ‘syslog’);
define(‘DAEMON_EXTENDED_DEBUG’, ‘true’);
and here is the output from: journalctl -u ttrss-update.service
Jul 17 09:35:00 charon systemd[1]: Started ttrss_backend.
If anyone has any comments on how to trace this stuff, I’d appreciate it.
fox
11
you set tt-rss internal error logging to syslog, while your systemd unit likely outputs standard output to journald (output which has nothing to do with tt-rss error logging in the first place)
maybe you should look up how all this shit actually works because right now you’re basically pushing levers which are not connected in any way whatsoever
we already told you, define the aforementioned constant in config.php and capture daemon output
if your systemd unit which you never posted here ignores stdout or redirects it to /dev/null for whatever retarded reason just run the daemon under screen or tee or something
e: fedora users.txt
e2: well tbf i guess config.php doesn’t mention that this is strictly error logging
t7r5s
12
I’ve just found this issues as well on a newly created system. Ill try and debug too and get some info.
Im running on debian 8, php 5.6.30, Tiny Tiny RSS v17.4 (c053b97).
You cat use perf trace or strace for stuck processes, but if you dont know how do it, and what can you see, its unnecessary, imho.
Also something strange, cause without --quiet option update daemon should write to stdout and systemd must catch it.
Something like that:
# systemctl status tt-rss
● tt-rss.service - Tiny Tiny RSS feeds update daemon
Loaded: loaded (/etc/systemd/system/tt-rss.service; enabled)
Active: active (running) since Вт 2017-07-18 08:22:01 MSK; 13s ago
Main PID: 25161 (php)
CGroup: /system.slice/lxc.service/system.slice/tt-rss.service
├─25161 php /home/vhosts/rss.vhost.run/htdocs/update_daemon2.php --tasks 5
├─25166 php /home/vhosts/rss.vhost.run/htdocs/update_daemon2.php --tasks 5
├─25169 php /home/vhosts/rss.vhost.run/htdocs/update_daemon2.php --tasks 5
├─25170 sh -c /usr/bin/php update.php --daemon-loop --task 3 --pidlock 25166
├─25173 sh -c /usr/bin/php update.php --daemon-loop --task 4 --pidlock 25169
├─25174 /usr/bin/php update.php --daemon-loop --task 3 --pidlock 25166
└─25176 /usr/bin/php update.php --daemon-loop --task 4 --pidlock 25169
июл 18 08:22:10 tt-rss update_daemon2.php[25161]: [05:22:10/25175] Feedbrowser updated, 64 feeds processed.
июл 18 08:22:11 tt-rss update_daemon2.php[25161]: [05:22:11/25175] Purged 5 orphaned posts.
июл 18 08:22:11 tt-rss update_daemon2.php[25161]: [05:22:11/25175] Removed 0 (feeds) 0 (cats) orphaned counter cache entries.
июл 18 08:22:12 tt-rss update_daemon2.php[25161]: [05:22:12/25161] [reap_children] child 25162 reaped.
июл 18 08:22:12 tt-rss update_daemon2.php[25161]: [05:22:12/25161] [SIGCHLD] jobs left: 3
июл 18 08:22:12 tt-rss update_daemon2.php[25161]: [05:22:12/25171] Scheduled 0 feeds to update...
июл 18 08:22:12 tt-rss update_daemon2.php[25161]: [05:22:12/25171] Sending digests, batch of max 15 users, headline limit = 1000
июл 18 08:22:12 tt-rss update_daemon2.php[25161]: [05:22:12/25171] All done.
июл 18 08:22:13 tt-rss update_daemon2.php[25161]: [05:22:13/25161] [reap_children] child 25164 reaped.
июл 18 08:22:13 tt-rss update_daemon2.php[25161]: [05:22:13/25161] [SIGCHLD] jobs left: 2
try to run from console(with stopped tt-rss servise) update_daemon2.php(with sudo as correct user(www-data?)). Will you see smth at stdout?
PS As for me, working fine at:
# cat /etc/debian_version
8.8
# php -v
PHP 5.6.30-0+deb8u1 (cli) (built: Feb 8 2017 08:50:21)
Copyright (c) 1997-2016 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2016 Zend Technologies
with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2016, by Zend Technologies
# mysql --version
mysql Ver 14.14 Distrib 5.5.55, for debian-linux-gnu (x86_64) using readline 6.3
# systemd --version
systemd 215
+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR
gbcox
14
Thanks for the tip about using tee, I’m running that now - just waiting for it to fail now…
I’ll look into wtf is happening to syslog after…
gbcox
15
Thanks for the reply… I’m using Fox’s suggestion to tee the output. I’ll look into what is happening with systemd… probably some default setting in Fedora-land…
gbcox
16
The define{‘DAEMON_EXTENDED_DEBUG’, ‘true’) didn’t really help. It printed out all kinds of information about what the process was doing, but when it failed, nothing more than I already knew:
[16:46:38/25321] [MASTER] spawned client 0 [PID:25324]…
[16:46:38/25326] Lock: update_daemon-25324.lock
[17:16:53/25321] [MASTER] child process 25324 seems to be stuck, aborting…
[17:16:53/25321] [reap_children] child 25324 reaped.
Yeah, the process is stuck, but why?
fox
17
any idea what was that PID doing before it got stuck? updating some specific feed?
also i’m not sure why it is getting killed and reaped but going by your earlier post the process actually stays. i think something is broken with your php or w/e.
What if after you get a hung process you go into the database and query for the last updated feed (MAX(last_updated) or something). Once you know the feed, go to the TT-RSS web interface, select that feed and run the feed debugger f D to see how that handles it.
e: More specific query:
SELECT title FROM ttrss_feeds ORDER BY last_update_started DESC LIMIT 2;
Does Fedora do SELinux? I wonder if it’s running into some bizarre permissions thing.
gbcox
20
Yes, it does, but I de-activate it.
gbcox
21
I actually re-initialized the postgresql database and was running with only the default ttrss feed, and that hung also, so yeah, something isn’t working with F26. Guess I’ll just wait for a few updates and try again.
fox
22
when i was writing tt-irc i had to rewrite process management in java because php fork/exec/etc was very unreliable, it mostly worked for tt-rss but maybe php devs broke everything completely with 7.1
e: i remember someone running into similar issues because of php modules (i.e. .so files) enabled in php.ini. either duplicates or something like that. maybe try digging in that direction? disable everything for php CLI except for bare minimum, etc.
Re: .so files - one thing to check is that you don’t somehow have more than one op cache loading. I accidentally had this after a Debian upgrade (because I’d previously enabled one and then the upgrade default enabled a different one). That causes all sorts of issues.
gbcox
24
I downgraded from 7.1 to 7.0 and it appears to be working… and apparently 7.0 causes issues also. I didn’t pay attention before because it seemed to run ok, but when I checked now, noticed it was throwing out errors.
E_WARNING (2) classes/db/pgsql.php:63 pg_fetch_result() expects parameter 1 to be resource, boolean given1. classes/db/pgsql.php(63): pg_fetch_result(, 0, unread)
2. classes/db.php(82): fetch_result(, 0, unread)
3. include/db.php(21): fetch_result(, 0, unread)
4. classes/feeds.php(1469): db_fetch_result(, 0, unread)
5. classes/handler/public.php(270): getFeedArticles(-3, , 1, 2)
6. public.php(50): getUnread()
14:31
E_USER_ERROR (256) classes/db/pgsql.php:48 Query SELECT count(int_id) AS unread FROM ttrss_user_entries,ttrss_entries WHERE unread = true AND ttrss_entries.id = ttrss_user_entries.ref_id AND (unread = true AND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) AND ttrss_user_entries.owner_uid = 2 failed: ERROR: invalid input syntax for type interval: " hour" LINE 3: …ND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) … ^1. classes/db/pgsql.php(48): user_error(Query SELECT count(int_id) AS unread
FROM ttrss_user_entries,ttrss_entries WHERE
unread = true AND ttrss_entries.id = ttrss_user_entries.ref_id AND (unread = true AND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) AND ttrss_user_entries.owner_uid = 2 failed: ERROR: invalid input syntax for type interval: " hour"
LINE 3: …ND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) …
^, 256)
2. classes/db.php(70): query(SELECT count(int_id) AS unread
FROM ttrss_user_entries,ttrss_entries WHERE
unread = true AND ttrss_entries.id = ttrss_user_entries.ref_id AND (unread = true AND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) AND ttrss_user_entries.owner_uid = 2, 1)
3. include/db.php(8): query(SELECT count(int_id) AS unread
FROM ttrss_user_entries,ttrss_entries WHERE
unread = true AND ttrss_entries.id = ttrss_user_entries.ref_id AND (unread = true AND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) AND ttrss_user_entries.owner_uid = 2, 1)
4. classes/feeds.php(1459): db_query(SELECT count(int_id) AS unread
FROM ttrss_user_entries,ttrss_entries WHERE
unread = true AND ttrss_entries.id = ttrss_user_entries.ref_id AND (unread = true AND score >= 0 AND date_entered > NOW() - INTERVAL ’ hour’ ) AND ttrss_user_entries.owner_uid = 2)
5. classes/handler/public.php(270): getFeedArticles(-3, , 1, 2)
6. public.php(50): getUnread()
14:31
E_USER_WARNING (512) classes/db/prefs.php:106 Fatal error, unknown preferences key: FRESH_ARTICLE_MAX_AGE (owner: 2)1. classes/db/prefs.php(106): user_error(Fatal error, unknown preferences key: FRESH_ARTICLE_MAX_AGE (owner: 2), 512)
2. include/db-prefs.php(5): read(FRESH_ARTICLE_MAX_AGE, 2, )
3. classes/feeds.php(1415): get_pref(FRESH_ARTICLE_MAX_AGE, 2)
4. classes/handler/public.php(270): getFeedArticles(-3, , 1, 2)
5. public.php(50): getUnread()
fox
25
7.0 should be fine, it could be something with your database
for example you need to log in at least once so that preferences are initialized
gbcox
26
Yup… I had re-initialized the database when I switched back to 7.0, the messages only appeared one time. 7.1 has issues however…
