@kaplun opened this Issue on December 5th 2018

I have scheduled Matomo core:archive to run with --concurrent-archivers=5. I am understanding concurrent archivers are running via multiprocessing.

If I check in the log I see:

INFO [2018-12-05 14:19:11] 3066  ---------------------------
INFO [2018-12-05 14:19:11] 3066  START
INFO [2018-12-05 14:19:11] 3066  Starting Matomo reports archiving...
INFO [2018-12-05 14:19:11] 3066  3 out of 5 archivers running currently

However in the current running process I have:

root      3065  0.0  0.0 218572  3532 pts/2    S+   14:19   0:00 sudo -u nginx /var/www/html/piwik/console core:archive --concurrent-archivers=5
nginx     3066  0.0  0.0 353692 23284 pts/2    S+   14:19   0:02 php /var/www/html/piwik/console core:archive --concurrent-archivers=5
nginx     3166  0.0  0.6 478624 148156 pts/2   S+   14:19   0:02 /usr/bin/php -q /var/www/html/piwik/console climulti:request -q --matomo-domain= --superuser module=API&method=API.get&idSite=4&period=day&date=last52&format=php&trigger=archivephp&pid=REDACTED&runid=3066
root     18734  0.0  0.0 112728   968 pts/1    S+   15:03   0:00 grep --color=auto console

Isn't this just one archiver counted three times? (I know from the source code the counting is actually parsing the output of ps).

Also why aren't 2 more archivers also started?

@fdellwing commented on December 5th 2018 Contributor

https://github.com/matomo-org/matomo/blob/0c72250d883a651a1d91263253533c460cdf35ec/core/CliMulti/Process.php#L243-L250
https://github.com/matomo-org/matomo/blob/0c72250d883a651a1d91263253533c460cdf35ec/core/CronArchive.php#L388-L412

After looking at the code, I don't know why it is counting 3. It would be very nice to have each $process printed. Could you add a $this->logger->info($process) to the foreach in your instance and post the output?

Also why aren't 2 more archivers also started?

The option sets the max used archivers, it could also use 1 of 100.

@tsteur commented on December 5th 2018 Member

did you use ps ex 2 @kaplun ? If you know for each archive command you launch, there will be two entries, then I would simply double the limit... sometimes the same archive process might appear multiple times eg exec php ... might list 2 entries in PS in some environments etc.

@fdellwing commented on December 5th 2018 Contributor

@tsteur Isn't the command simply ps ex? The 2>/dev/null part is only there to surpress errors, isn't it?

@tsteur commented on December 5th 2018 Member

true 👍

@kaplun commented on December 5th 2018

The current log output is:

INFO [2018-12-05 21:38:41] 27687  24450 ?        S      9:42 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24451 ?        S      9:45 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24452 ?        S      9:52 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24481 ?        S      9:50 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24628 ?        S      9:49 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24672 ?        S      9:52 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  24682 ?        S      9:55 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  25163 ?        S      9:44 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  25766 ?        S      0:07 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  25785 ?        S      0:08 php-fpm: pool www
INFO [2018-12-05 21:38:41] 27687  27687 pts/3    S+     0:00 php /var/www/html/piwik/console core:archive --concurrent-archivers=5 HOSTNAME=REDACTED TERM=screen HISTSIZE=1000 LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36: USERNAME=root MAIL=/var/spool/mail/root LANG=it_CH.UTF-8 PATH=/sbin:/bin:/usr/sbin:/usr/bin LOGNAME=root USER=root HOME=/var/lib/nginx SHELL=/sbin/nologin SUDO_COMMAND=/var/www/html/piwik/console core:archive --concurrent-archivers=5 SUDO_USER=root SUDO_UID=0 SUDO_GID=0
INFO [2018-12-05 21:38:41] 27687  27757 pts/3    S+     0:00 sh -c ps ex 2>/dev/null HOSTNAME=REDACTED TERM=screen HISTSIZE=1000 LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36: USERNAME=root MAIL=/var/spool/mail/root LANG=it_CH.UTF-8 PATH=/sbin:/bin:/usr/sbin:/usr/bin LOGNAME=root USER=root HOME=/var/lib/nginx SHELL=/sbin/nologin SUDO_COMMAND=/var/www/html/piwik/console core:archive --concurrent-archivers=5 SUDO_USER=root SUDO_UID=0 SUDO_GID=0
INFO [2018-12-05 21:38:41] 27687  27758 pts/3    R+     0:00 ps ex HOSTNAME=REDACTED SHELL=/sbin/nologin TERM=screen HISTSIZE=1000 USER=root LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36: SUDO_USER=root SUDO_UID=0 USERNAME=root PATH=/sbin:/bin:/usr/sbin:/usr/bin MAIL=/var/spool/mail/root PWD=/root LANG=it_CH.UTF-8 SHLVL=1 SUDO_COMMAND=/var/www/html/piwik/console core:archive --concurrent-archivers=5 HOME=/var/lib/nginx LOGNAME=root SUDO_GID=0 _=/bin/ps
INFO [2018-12-05 21:38:41] 27687  31090 ?        Ss     0:00 /bin/sh -c /var/www/html/piwik/console core:archive --concurrent-archivers=5 2>&1 >> /var/log/matomo-archive.log XDG_SESSION_ID=24692 XDG_RUNTIME_DIR=/run/user/498 LANG=en_US.UTF-8 SHELL=/bin/sh HOME=/var/lib/nginx PATH=/usr/bin:/bin LOGNAME=nginx USER=nginx
INFO [2018-12-05 21:38:41] 27687  31091 ?        S      0:03 php /var/www/html/piwik/console core:archive --concurrent-archivers=5 XDG_SESSION_ID=24692 SHELL=/bin/sh USER=nginx PATH=/usr/bin:/bin PWD=/var/lib/nginx LANG=en_US.UTF-8 SHLVL=1 HOME=/var/lib/nginx LOGNAME=nginx XDG_RUNTIME_DIR=/run/user/498 _=/var/www/html/piwik/console
INFO [2018-12-05 21:38:41] 27687  31197 ?        S      6:11 /usr/bin/php -q /var/www/html/piwik/console climulti:request -q --matomo-domain= --superuser module=API&method=API.get&idSite=1&period=day&date=last52&format=php&trigger=archivephp&pid=REDACTED&runid=31091 XDG_SESSION_ID=24692 SHELL=/bin/sh USER=nginx PATH=/usr/bin:/bin _=/usr/bin/php PWD=/var/lib/nginxINFO [2018-12-05 21:38:41] 27687  31197 ?        S      6:11 /usr/bin/php -q /var/www/html/piwik/console climulti:request -q --matomo-domain= --superuser module=API&method=API.get&idSite=1&period=day&date=last52&format=php&trigger=archivephp&pid=REDACTED&runid=31091 XDG_SESSION_ID=24692 SHELL=/bin/sh USER=nginx PATH=/usr/bin:/bin _=/usr/bin/php PWD=/var/lib/nginx LANG=en_US.UTF-8 HOME=/var/lib/nginx SHLVL=2 LOGNAME=nginx XDG_RUNTIME_DIR=/run/user/498
@kaplun commented on December 5th 2018

A bit OT, for this issue, but is there a way to speed up the archiving by indeed having parallel requests for independent reports?

@kaplun commented on December 5th 2018

Ah and it says:

Archiving will stop now because 7 archivers are already running and max 5 are supposed to run at once.
@tsteur commented on December 6th 2018 Member

It'll speed up if you have multiple sites, otherwise there isn't much of a benefit.

@kaplun commented on December 6th 2018

Oh. Is there a plan to parallelize e.g. to run different days in parallel and then recursively different weeks and so on?

@tsteur commented on December 6th 2018 Member

no there are no plans. usually, you would run the archiver every day and it would only archive the current day anyway (from there the week etc)

@tsteur commented on December 10th 2018 Member

@kaplun I think we can close the issue? We could possibly edit the FAQ though that sometimes you may need to double the amount of concurrent archivers if each archive process is listed twice. As far as I can tell it doesn't look like there's some bug otherwise.

@kaplun commented on December 10th 2018

Well, I think it's even counted 3 times, due to the wrong ps filtering. So maybe a smarter filter could be foreseen? Or using pid files?

But yeah otherwise it's not an high priority issue.

@tsteur commented on December 10th 2018 Member

The logic is quite straight forward to count the number of processes. It simply lists each process ps ex and counts how many of those processes include console core:archive. We are using this feature also a lot and it works quite nicely. Is that randomly or always for you?

It might say 3 times because it includes the current core:archive process that is currently running and if you do afterwards ps ex, this process won't be shown anymore.

@kaplun commented on December 10th 2018

It's always due to the fact that I am using a cronjob with this format:

0 2 * * * nginx /var/www/html/piwik/console core:archive -vvv --concurrent-archivers=10 2>&1 >> /var/log/matomo-archive.log

So I guess there is one process for the sudo one for the sh and one for the actual script.

@tsteur commented on December 10th 2018 Member

Sweet. I'll update the docs 👍

Powered by GitHub Issue Mirror