UNSUPPORTED SETUP: Tiny Tiny RSS Updater Seems to Get Stuck

  • [ ] I’m using stock docker compose setup, unmodified.

  • [ ] I’m using docker compose setup, with modifications (modified .yml files, third party plugins/themes, etc.) - if so, describe your modifications in your post. Before reporting, see if your issue can be reproduced on the unmodified setup.

  • [ ] I’m not using docker on my primary instance, but my issue can be reproduced on the aforementioned docker setup and/or official demo.

  • [X] I’m not using docker on my primary instance, I’m asking if anyone has encountered this before but I fully understand and accept I’m 100% on my own here and if my thread gets locked and I get banned I deserved it!


I’m running :

Debian 12.2

Tiny Tiny RSS v23.10-1be1564 (Unsupported) © 2005-2023 Andrew Dolgov

PHP 8.2.7 (cli) (built: Jun  9 2023 19:37:27) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.2.7, Copyright (c) Zend Technologies
    with Zend OPcache v8.2.7, Copyright (c), by Zend Technologies

[PHP Modules]
bcmath
calendar
cgi-fcgi
Core
ctype
curl
date
dom
exif
FFI
fileinfo
filter
ftp
gd
gettext
gmp
hash
iconv
intl
json
libxml
mbstring
mysqli
mysqlnd
openssl
pcre
PDO
pdo_mysql
pdo_sqlite
Phar
posix
random
readline
Reflection
session
shmop
SimpleXML
sockets
sodium
SPL
sqlite3
standard
sysvmsg
sysvsem
sysvshm
tidy
tokenizer
xml
xmlreader
xmlwriter
xsl
Zend OPcache
zip
zlib

[Zend Modules]
Zend OPcache

mysql  Ver 15.1 Distrib 10.11.4-MariaDB, for debian-linux-gnu (x86_64) using  EditLine wrapper

The contents of my config.php:

putenv('TTRSS_DB_HOST=localhost');
putenv('TTRSS_DB_NAME=ttrss');
putenv('TTRSS_DB_USER=ttrss');
putenv('TTRSS_DB_PASS=<REMOVED>');
putenv('TTRSS_SELF_URL_PATH=https://<REMOVED>');
putenv('TTRSS_DB_TYPE=mysql');
putenv('TTRSS_DB_PORT=3306');
putenv('TTRSS_SMTP_FROM_NAME=My Tiny Tiny RSS');
putenv('TTRSS_SMTP_FROM_ADDRESS=reader@<REMOVED>);

# I do this manually using git
putenv('TTRSS_CHECK_FOR_UPDATES=false');

Plugins I have enabled:

auth_internal
af_readability
cdm_no_move_on_expand
close_button
favicon_unread
af_comics
af_zz_vidmute
auto_assign_labels
cache_starred_images
hotkeys_swap_jk
note
share
toggle_sidebar

I have Apache talking to php-fpm and it works great - TinyTinyRSS reader is running really well.
This is how I run my updater:

cd /var/www/reader && php ./update_daemon2.php --tasks 6 > /var/log/tt-rss.log 2>&1 &

The problem I have is that after ~24 hours or so, the updater seems to get stuck:

www-data  972839  0.0  0.0   8256  2676 pts/2    S    Oct30   0:00 -bash
www-data  972840  0.0  0.3 146532 25180 pts/2    S    Oct30   0:30  \_ php ./update_daemon2.php --tasks 6
www-data 1245325  0.0  0.1 146532 15080 pts/2    S    09:50   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245326  0.0  0.0   2580  1536 pts/2    S    09:50   0:00      |   \_ sh -c /usr/bin/php update.php --daemon-loop   --task 0 --pidlock 1245325
www-data 1245328  0.0  0.4 148580 39896 pts/2    S    09:50   0:00      |       \_ /usr/bin/php update.php --daemon-loop --task 0 --pidlock 1245325
www-data 1245351  0.0  0.0   2580  1536 pts/2    S    09:50   0:00      |           \_ sh -c /usr/bin/php update.php --update-feed 1 --pidlock feed-1
www-data 1245352  0.1  0.6 227512 49480 pts/2    S    09:50   0:00      |               \_ /usr/bin/php update.php --update-feed 1 --pidlock feed-1
www-data 1245624  0.0  0.1 146532 15080 pts/2    S    09:52   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245625  0.0  0.0   2580  1408 pts/2    S    09:52   0:00      |   \_ sh -c /usr/bin/php update.php --daemon-loop   --task 1 --pidlock 1245624
www-data 1245626  0.0  0.4 148580 40280 pts/2    S    09:52   0:00      |       \_ /usr/bin/php update.php --daemon-loop --task 1 --pidlock 1245624
www-data 1245627  0.0  0.1 146532 15080 pts/2    S    09:52   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245628  0.0  0.0   2584  1408 pts/2    S    09:52   0:00      |   \_ sh -c /usr/bin/php update.php --daemon-loop   --task 2 --pidlock 1245627
www-data 1245629  0.0  0.4 148580 40152 pts/2    S    09:52   0:00      |       \_ /usr/bin/php update.php --daemon-loop --task 2 --pidlock 1245627
www-data 1245630  0.0  0.1 146532 15080 pts/2    S    09:52   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245631  0.0  0.0   2580  1280 pts/2    S    09:52   0:00      |   \_ sh -c /usr/bin/php update.php --daemon-loop   --task 3 --pidlock 1245630
www-data 1245632  0.0  0.4 148580 40076 pts/2    S    09:52   0:00      |       \_ /usr/bin/php update.php --daemon-loop --task 3 --pidlock 1245630
www-data 1245633  0.0  0.1 146532 15080 pts/2    S    09:52   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245634  0.0  0.0   2580  1536 pts/2    S    09:52   0:00      |   \_ sh -c /usr/bin/php update.php --daemon-loop   --task 4 --pidlock 1245633
www-data 1245635  0.0  0.4 148584 40152 pts/2    S    09:52   0:00      |       \_ /usr/bin/php update.php --daemon-loop --task 4 --pidlock 1245633
www-data 1245636  0.0  0.1 146532 15080 pts/2    S    09:52   0:00      \_ php ./update_daemon2.php --tasks 6
www-data 1245637  0.0  0.0   2580  1536 pts/2    S    09:52   0:00          \_ sh -c /usr/bin/php update.php --daemon-loop   --task 5 --pidlock 1245636
www-data 1245638  0.0  0.4 148580 40152 pts/2    S    09:52   0:00              \_ /usr/bin/php update.php --daemon-loop --task 5 --pidlock 1245636

The last messages in the log file of the updater are:

[20:50:09/972840] Received SIGCHLD, 5 active tasks left.
[20:50:13/1245333] Scheduled 0 feeds to update...
[20:50:13/1245333] Sending digests, batch of max 15 users, headline limit = 1000
[20:50:13/1245333] All done.
[20:50:14/972840] Child process with PID 1245330 reaped.
[20:50:14/972840] Received SIGCHLD, 4 active tasks left.
[20:50:18/1245336] Scheduled 0 feeds to update...
[20:50:18/1245336] Sending digests, batch of max 15 users, headline limit = 1000
[20:50:18/1245336] All done.
[20:50:19/972840] Child process with PID 1245334 reaped.
[20:50:19/972840] Received SIGCHLD, 3 active tasks left.
[20:50:23/1245339] Scheduled 0 feeds to update...
[20:50:23/1245339] Sending digests, batch of max 15 users, headline limit = 1000
[20:50:23/1245339] All done.
[20:50:24/972840] Child process with PID 1245337 reaped.
[20:50:24/972840] Received SIGCHLD, 2 active tasks left.
[20:50:28/1245342] Scheduled 0 feeds to update...
[20:50:28/1245342] Sending digests, batch of max 15 users, headline limit = 1000
[20:50:28/1245342] All done.
[20:50:29/972840] Child process with PID 1245340 reaped.
[20:50:29/972840] Received SIGCHLD, 1 active tasks left.
[20:51:02/972840] 1 active tasks, next spawn at 60 sec.
[20:52:02/972840] 1 active tasks, next spawn at 0 sec.
[20:52:03/972840] Spawned child process with PID 1245624 for task 1.
[20:52:03/972840] Spawned child process with PID 1245627 for task 2.
[20:52:03/972840] Spawned child process with PID 1245630 for task 3.
[20:52:03/972840] Spawned child process with PID 1245633 for task 4.
[20:52:03/972840] Spawned child process with PID 1245636 for task 5.
[20:52:03/1245626] Using task id 1
[20:52:03/1245626] Lock: update_daemon-1245624.lock
[20:52:03/1245626] Waiting before update (5)...
[20:52:03/1245632] Using task id 3
[20:52:03/1245632] Lock: update_daemon-1245630.lock
[20:52:03/1245632] Waiting before update (15)...
[20:52:03/1245635] Using task id 4
[20:52:03/1245635] Lock: update_daemon-1245633.lock
[20:52:03/1245635] Waiting before update (20)...
[20:52:03/1245629] Using task id 2
[20:52:03/1245629] Lock: update_daemon-1245627.lock
[20:52:03/1245629] Waiting before update (10)...
[20:52:03/1245638] Using task id 5
[20:52:03/1245638] Lock: update_daemon-1245636.lock
[20:52:03/1245638] Waiting before update (25)...
[20:52:08/1245626] Scheduled 1 feeds to update...
[20:52:13/1245629] Scheduled 1 feeds to update...
[20:52:18/1245632] Scheduled 1 feeds to update...
[20:52:23/1245635] Scheduled 1 feeds to update...
[20:52:28/1245638] Scheduled 1 feeds to update...
[20:53:03/972840] 6 active tasks, next spawn at 60 sec.
[20:54:03/972840] 6 active tasks, next spawn at 0 sec.
[20:55:04/972840] 6 active tasks, next spawn at 60 sec.
[20:56:04/972840] 6 active tasks, next spawn at 0 sec.
[20:57:05/972840] 6 active tasks, next spawn at 60 sec.
[20:58:05/972840] 6 active tasks, next spawn at 0 sec.
[20:59:06/972840] 6 active tasks, next spawn at 60 sec.
[21:00:06/972840] 6 active tasks, next spawn at 0 sec.

For some reason when the updater gets stuck, it also seems to impact php-fpm so all my other PHP sites on my Linux host break. (This is something I need to figure out though and is unrelated to my help query, I just mention it because it’s how I’ve been noticing when the updater is hanging)

Does anyone have any pointers for what I can do to debug what’s causing the updater to hang/stop updating?
If I restart the updater all seems well again for ~24 hours (or longer) but after a period of time I get stuck in the same situation, I have to kill all php process and restart the updater.

This has been happening since I came back to TinyTinyRSS a few weeks ago - i.e. before the recent PSR-4 update.

Thanks for any inside you can provide - again - I fully understand and accept I am on my own here!!

Tim

You know what? I might have figured this out myself.

[30-Oct-2023 01:12:02] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
[31-Oct-2023 01:14:01] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
[31-Oct-2023 09:51:01] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it

Given that I have a number of other PHP services on the box and I’d set --tasks 6 I think I’ve just been screwing myself. I’ve changed tasks to “2” now and increased max_children to 10.

I’m not saying it’s solved yet but I’m also pretty sure that’s the smoking gun.

i’m not sure though how FPM and a separate PHP CLI instance of updater could affect each other. this could be a red herring, that is, your FPM issues (because you didn’t have enough children) are unrelated to the updater getting stuck. it could be a general resource problem or some kind of database-related lock or something.

in general there’s no need to set task amount this high in the updater. unless you’re trying to run some kind of hosted ‘cloud’ service which tt-rss isn’t designed for.

Yea, it doesn’t make sense to me how CLI and FPM interact - as far as I’m aware they don’t.

You’re probably right - I probably well have some other OS / system level problem going on.

Thanks for looking.

Further to this - it’s a mysql issue.
The issue happens at the same time I’m doing a mysqldump - there appears to be some sort of lock contention or similar. Restarting mysql instantly resolves all issues. I’m investigating what’s going on here, but that’s the root cause.

Unlikley to be be tripped over by anyone else as any sane person should be using postgresql.

Anyway - that’s what the cause was in case anyone else ever has the same misfortune as me.