Extremely slow after upgrade from 2.2 to 2.6

56 views
Skip to first unread message

Elias Pereira

unread,
Mar 22, 2024, 8:55:45 PM3/22/24
to bacu...@googlegroups.com
hello,

After upgrading from version 2.2 to 2.6, it's extremely slow when I click on any menu. I've checked the logs and there's nothing there.

How do I debug the issue?

--
Elias Pereira

Marcin Haba

unread,
Mar 23, 2024, 12:25:55 AM3/23/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

Thanks for reporting to us this performance problem that you experienced.

In this case it is good to start from reviewing the web server access
log to localize what request exactly takes the most time. To help in
localizing the request, I would propose to add the request time
property to the access log format.

If you use Apache, then in the main config (httpd.conf or
apache2.conf) you can add the %{ms}Tms property to LogFormat
directive, like here:

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\"
\"%{User-Agent}i\" %{ms}Tms" combined

After that you need to reload the configuration.

If you use Nginx, then in the main config (nginx.conf) you can add the
"$request_time sec." property to the log_format directive like here:

log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for"
"$request_time sec."';

After that you need to use this new format in Bacularis web server
config at the end 'main' word which is name of the changed log format:

access_log /var/log/nginx/bacularis-access.log main;

At the end please reload the web server configuration.

Once you have the request time in the access log, you can do a walk
through the Bacularis web interface by clicking on pages that you
think takes most time. And you can share with us the results, of
course.

Thanks in advance for trying.

Best regards,
Marcin Haba (gani)
> --
> You received this message because you are subscribed to the Google Groups "bacularis" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to bacularis+...@googlegroups.com.
> To view this discussion on the web, visit https://groups.google.com/d/msgid/bacularis/CAHdxDAH7nLqOTjTMqyTwGGXAsZ3FbtvN65EKes%3DS9tJh2tRQJw%40mail.gmail.com.
> For more options, visit https://groups.google.com/d/optout.



--

"Greater love hath no man than this, that a man lay down his life for
his friends." Jesus Christ

"Większej miłości nikt nie ma nad tę, jak gdy kto życie swoje kładzie
za przyjaciół swoich." Jezus Chrystus

Elias Pereira

unread,
Mar 23, 2024, 8:59:22 AM3/23/24
to Marcin Haba, bacu...@googlegroups.com
Hello Marcin, thanks for the help!!!

The final time after clicking to show the "jobs" took more than 2 minutes for the list to appear.

Below is the log.

10.10.70.2 - - [23/Mar/2024:09:42:26 -0300] "GET /web/ HTTP/1.1" 200 10108 "http://bacula.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:42:26 -0300] "GET /api/v2/jobs/?age=0&director=bacula-dir HTTP/1.1" 200 1926712 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3283 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/pools?director=bacula-dir HTTP/1.1" 200 4528 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/jobs/totals?director=bacula-dir HTTP/1.1" 200 490 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/dbsize?director=bacula-dir HTTP/1.1" 200 260 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:44:30 -0300] "GET /api/v2/jobs/show/?output=json&director=bacula-dir HTTP/1.1" 200 45140 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:42:26 -0300] "POST /web/monitor/ HTTP/1.1" 200 355057 "http://bacula.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
10.10.70.2 - - [23/Mar/2024:09:42:32 -0300] "GET /web/job/ HTTP/1.1" 200 27542 "http://bacula.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:44:31 -0300] "GET /api/v2/jobs/?limit=15000&director=bacula-dir HTTP/1.1" 200 1926733 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:46:35 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:45:12 -0300] "GET /web/client/ HTTP/1.1" 200 10493 "http://bacula.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
10.10.70.2 - - [23/Mar/2024:09:44:31 -0300] "POST /web/monitor/ HTTP/1.1" 200 203246 "http://bacula.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:46:35 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3283 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:46:36 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:46:36 -0300] "GET /api/v2/jobs/?jobstatus=CR&director=bacula-dir HTTP/1.1" 200 222 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:46:35 -0300] "POST /web/monitor/ HTTP/1.1" 200 11899 "http://bacula.intra:9097/web/client/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:47:36 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3283 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:47:36 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:47:36 -0300] "GET /api/v2/jobs/?jobstatus=CR&director=bacula-dir HTTP/1.1" 200 222 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:47:36 -0300] "POST /web/monitor/ HTTP/1.1" 200 11900 "http://bacula.intra:9097/web/client/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:09 -0300] "GET /api/v2/config/dir/Client/bacula-fd?director=bacula-dir HTTP/1.1" 200 432 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:48:09 -0300] "GET /api/v2/config/dir?director=bacula-dir HTTP/1.1" 200 32808 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:48:09 -0300] "POST /web/client/ HTTP/1.1" 200 15622 "http://bacula.intra:9097/web/client/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:37 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3283 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:48:37 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:48:37 -0300] "GET /api/v2/jobs/?jobstatus=CR&director=bacula-dir HTTP/1.1" 200 222 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:48:37 -0300] "POST /web/monitor/ HTTP/1.1" 200 11900 "http://bacula.intra:9097/web/client/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:53 -0300] "GET /api/v2/storages?director=bacula-dir HTTP/1.1" 200 423 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:48:53 -0300] "GET /web/storage/ HTTP/1.1" 200 10255 "http://bacula.intra:9097/web/client/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:53 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:48:53 -0300] "GET /api/v2/jobs/?jobstatus=CR&director=bacula-dir HTTP/1.1" 200 222 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:48:53 -0300] "POST /web/monitor/ HTTP/1.1" 200 11490 "http://bacula.intra:9097/web/storage/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:56 -0300] "GET /api/v2/jobs/show/?output=json&director=bacula-dir HTTP/1.1" 200 45140 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:48:56 -0300] "GET /web/job/ HTTP/1.1" 200 27541 "http://bacula.intra:9097/web/storage/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:48:57 -0300] "GET /api/v2/jobs/?limit=15000&director=bacula-dir HTTP/1.1" 200 1926712 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:51:00 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:50:29 -0300] "GET /web/ HTTP/1.1" 200 10108 "http://bacula.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
10.10.70.2 - - [23/Mar/2024:09:48:57 -0300] "POST /web/monitor/ HTTP/1.1" 200 94220 "http://bacula.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:51:00 -0300] "GET /api/v2/jobs/?age=0&director=bacula-dir HTTP/1.1" 200 1926712 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:53:05 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3283 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:53:05 -0300] "GET /api/v2/pools?director=bacula-dir HTTP/1.1" 200 4528 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:53:05 -0300] "GET /api/v2/jobs/totals?director=bacula-dir HTTP/1.1" 200 490 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:53:05 -0300] "GET /api/v2/dbsize?director=bacula-dir HTTP/1.1" 200 260 "-" "-"
127.0.0.1 - - [23/Mar/2024:09:53:05 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 245 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:51:00 -0300] "POST /web/monitor/ HTTP/1.1" 200 355057 "http://bacula.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
127.0.0.1 - - [23/Mar/2024:09:53:06 -0300] "GET /api/v2/jobs/show/?output=json&director=bacula-dir HTTP/1.1" 200 45140 "-" "-"
10.10.70.2 - - [23/Mar/2024:09:51:14 -0300] "GET /web/job/ HTTP/1.1" 200 27542 "http://bacula.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36"
--
Elias Pereira

Elias Pereira

unread,
Mar 23, 2024, 9:20:54 AM3/23/24
to Marcin Haba, bacu...@googlegroups.com
Sorry, I forgot to enter the settings.

debian 12

# bconsole
Connecting to director 200.xxx.xxx.xxx:9101
1000 OK: 10002 bacula.sertao.ifrs.edu.br-dir Version: 13.0.3 (May 02, 2023)

# php -version
PHP 8.2.7 (cli) (built: June 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

# apache2 -version
Server version: Apache/2.4.57 (Debian)
Server built: 2023-04-13T03:26:51
--
Elias Pereira

Marcin Haba

unread,
Mar 23, 2024, 9:33:23 AM3/23/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

Many thanks for providing logs.

I am not seeing in them this time change property in the access log. I
mean adding request time. Without it I can only guess which request
took the most, but it can be not accurate.

On the Jobs page there are sent three request to the API. Here you can
see them in my env with 50k jobs:

127.0.0.1 - - [23/Mar/2024:14:17:22 +0100] "GET
/api/v2/jobs/show/?output=json&director=darkstar-dir HTTP/1.1" 200
2403 "-" "-" 501ms
127.0.0.1 - - [23/Mar/2024:14:17:23 +0100] "GET
/api/v2/jobs/?limit=15000&director=darkstar-dir HTTP/1.1" 200 173013
"-" "-" 953ms
127.0.0.1 - - [23/Mar/2024:14:17:24 +0100] "GET
/api/v2/joblog/messages?director=darkstar-dir HTTP/1.1" 200 66 "-" "-"
261ms

The last value in the access log above is this time request. For these
above it is 501ms, 953ms and 261ms.

Could you add this request time to the access log and try again?
Thanks in advance for trying.

Also could you try something else - I mean going to the application
settings page under gearwheel icon on the top left side of Bacularis
web interface, there could you go to the "Display options" tab and set
"Job age on the dashboard job graphs" directive to a low value, for
example 14 days as shown on the attached screenshot.

Thanks for your trying. Please share with us the new results.

Thanks!

Best regards,
Marcin Haba (gani)

Marcin Haba

unread,
Mar 23, 2024, 9:40:59 AM3/23/24
to Elias Pereira, bacu...@googlegroups.com
I forgot to send a screenshot :-) I am sending it now.

Best regards,
Marcin Haba (gani)

job_age.png

Elias Pereira

unread,
Mar 23, 2024, 9:49:34 AM3/23/24
to Marcin Haba, bacu...@googlegroups.com
Hello, Marcin,

I've set it up as you requested.


LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %{ms}Tms" combined
CustomLog /var/log/bacularis.log combined

Is this correct?
--
Elias Pereira

Marcin Haba

unread,
Mar 23, 2024, 10:02:18 AM3/23/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

Yes, I confirm. It is correct. Thanks.

The only thing that on Debian usually the Apache access log path is:

CustomLog /var/log/apache2/bacularis-access.log combined

but if you are able to read the access log from:

/var/log/bacularis.log

then it is OK as well.

However I don't know why in your access log the request time is
missing. Did you reload the configuration after changing it?

Best regards,
Marcin Haba (gani)

Elias Pereira

unread,
Mar 23, 2024, 10:10:08 AM3/23/24
to Marcin Haba, bacu...@googlegroups.com
bacularis.conf

Listen 0.0.0.0:9097
<VirtualHost *:9097>
        DocumentRoot /usr/share/bacularis/htdocs
        ServerName localhost

        LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %{ms}Tms" combined
        CustomLog /var/log/bacularis.log combined

        <Directory /usr/share/bacularis/htdocs>
                RewriteEngine On
                RewriteCond %{REQUEST_FILENAME} !-d
                RewriteCond %{REQUEST_FILENAME} !-f
                RewriteRule ^(.*)$ index.php/$1 [L]

                # Apache 2.2
                <IfModule !mod_authz_core.c>
                        Order Allow,Deny
                        Allow from all
                </IfModule>
                # Apache 2.4
                <IfModule mod_authz_core.c>
                        Require all granted
                </IfModule>
        </Directory>
</VirtualHost>

I have restored the services below:

systemctl restart apache2 && systemctl restart php8.2-fpm.service
--
Elias Pereira

Marcin Haba

unread,
Mar 23, 2024, 10:20:28 AM3/23/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

OK, I see. Thanks.

You added the LogFormat to the virtual host config. In this case you
need to change the name of this log format from 'combined' to
something else because the 'combined' log format is already defined in
the main Apache config.

So, could you please just change 'combined' into something else, like
'combined1':

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\"
\"%{User-Agent}i\" %{ms}Tms" combined1
CustomLog /var/log/bacularis.log combined1

Best regards,
Marcin Haba (gani)

Elias Pereira

unread,
Mar 23, 2024, 10:41:29 AM3/23/24
to Marcin Haba, bacu...@googlegroups.com
Great!!! Now it works!!!

Here are the new logs.

127.0.0.1 - - [23/Mar/2024:11:27:12 -0300] "GET /api/v2/jobs/show/?output=json&director=bacula-dir HTTP/1.1" 200 44895 "-" "-" 292ms
10.10.70.2 - - [23/Mar/2024:11:27:12 -0300] "GET /web/job/ HTTP/1.1" 200 27179 "http://bacula.sertao.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 486ms
127.0.0.1 - - [23/Mar/2024:11:27:13 -0300] "GET /api/v2/jobs/?limit=15000&director=bacula-dir HTTP/1.1" 200 1924634 "-" "-" 124197ms
127.0.0.1 - - [23/Mar/2024:11:29:17 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 46 "-" "-" 150ms
10.10.70.2 - - [23/Mar/2024:11:27:13 -0300] "POST /web/monitor/ HTTP/1.1" 200 353390 "http://bacula.sertao.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 124577ms
127.0.0.1 - - [23/Mar/2024:11:30:18 -0300] "GET /api/v2/jobs/?limit=15000&director=bacula-dir HTTP/1.1" 200 1924634 "-" "-" 123086ms
127.0.0.1 - - [23/Mar/2024:11:32:21 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 46 "-" "-" 147ms
10.10.70.2 - - [23/Mar/2024:11:32:10 -0300] "GET /web/ HTTP/1.1" 200 9746 "http://bacula.sertao.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 10588ms
10.10.70.2 - - [23/Mar/2024:11:30:18 -0300] "POST /web/monitor/ HTTP/1.1" 200 289745 "http://bacula.sertao.intra:9097/web/job/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 123416ms
127.0.0.1 - - [23/Mar/2024:11:32:21 -0300] "GET /api/v2/jobs/?age=0&director=bacula-dir HTTP/1.1" 200 1924634 "-" "-" 122093ms
127.0.0.1 - - [23/Mar/2024:11:34:23 -0300] "GET /api/v2/clients?director=bacula-dir HTTP/1.1" 200 3083 "-" "-" 173ms
127.0.0.1 - - [23/Mar/2024:11:34:23 -0300] "GET /api/v2/pools?director=bacula-dir HTTP/1.1" 200 4327 "-" "-" 171ms
127.0.0.1 - - [23/Mar/2024:11:34:24 -0300] "GET /api/v2/jobs/totals?director=bacula-dir HTTP/1.1" 200 290 "-" "-" 193ms
127.0.0.1 - - [23/Mar/2024:11:34:24 -0300] "GET /api/v2/dbsize?director=bacula-dir HTTP/1.1" 200 61 "-" "-" 52ms
127.0.0.1 - - [23/Mar/2024:11:34:24 -0300] "GET /api/v2/joblog/messages?director=bacula-dir HTTP/1.1" 200 46 "-" "-" 142ms
10.10.70.2 - - [23/Mar/2024:11:32:21 -0300] "POST /web/monitor/ HTTP/1.1" 200 354340 "http://bacula.sertao.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 123045ms
127.0.0.1 - - [23/Mar/2024:11:34:35 -0300] "GET /api/v2/jobs/8064?director=bacula-dir HTTP/1.1" 200 874 "-" "-" 119859ms
127.0.0.1 - - [23/Mar/2024:11:36:35 -0300] "GET /api/v2/jobs/show/?name=Backup-Bacula-Arquvios&director=bacula-dir HTTP/1.1" 200 5154 "-" "-" 286ms
127.0.0.1 - - [23/Mar/2024:11:36:35 -0300] "GET /api/v2/joblog/8064/?show_time=0&director=bacula-dir HTTP/1.1" 200 2989 "-" "-" 109852ms
127.0.0.1 - - [23/Mar/2024:11:38:25 -0300] "GET /api/v2/schedules/status/?job=Backup-Bacula-Arquvios&days=90&limit=0&director=bacula-dir HTTP/1.1" 200 125108 "-" "-" 221ms
127.0.0.1 - - [23/Mar/2024:11:38:25 -0300] "GET /api/v2/jobs/resnames?director=bacula-dir HTTP/1.1" 200 624 "-" "-" 177ms
10.10.70.2 - - [23/Mar/2024:11:34:35 -0300] "GET /web/job/history/8064/ HTTP/1.1" 200 38188 "http://bacula.sertao.intra:9097/web/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/122.0.0.0 Safari/537.36" 230519ms
--
Elias Pereira

Elias Pereira

unread,
Mar 23, 2024, 8:32:05 PM3/23/24
to Marcin Haba, bacu...@googlegroups.com
hello Marcin,

I ended up removing php8.2 and installing 7.4. I removed bacularis 2.6.0 and installed 2.2.1 and it worked normally again.

Could there be a bug? How can I help you?
--
Elias Pereira

Marcin Haba

unread,
Mar 23, 2024, 11:16:14 PM3/23/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

Yes, the timing in the access log is available. Great, thanks.

Also thanks for the help offer. Yes, I will use it with pleasure, because without your help we will not be able to see what is going on.

It looks that something wrong happens with /api/v2/jobs endpoint.

Since version 2.2.1 the only significant change was in this query below. Could I ask you about logging in to the database using the psql database client (ex. psql -U bacula bacula) and executing these two commands? They are for the PostgreSQL type catalog database.

First one is to enable getting timing:

\timing on

Second one is the query that can be problematic in your env (this is for 15000 jobs):

SELECT Job.*,
pn.prev_jobid AS prev_jobid,
pn.next_jobid AS next_jobid,
Client.Name as client,
Pool.Name as pool,
FileSet.FileSet as fileset,
jm.volumename AS firstvol,
COALESCE(mi.volcount, 0) AS volcount,
CAST(EXTRACT(EPOCH FROM Job.SchedTime) AS INTEGER) AS schedtime_epoch,
CAST(EXTRACT(EPOCH FROM Job.StartTime) AS INTEGER) AS starttime_epoch,
CAST(EXTRACT(EPOCH FROM Job.EndTime) AS INTEGER) AS endtime_epoch,
CAST(EXTRACT(EPOCH FROM Job.RealEndTime) AS INTEGER) AS realendtime_epoch
FROM Job
LEFT JOIN (
SELECT
JobMedia.JobId AS jobid,
Media.VolumeName AS volumename,
ROW_NUMBER() OVER (PARTITION BY JobMedia.JobId ORDER BY JobMedia.JobMediaId) AS jmi
FROM
Media
LEFT JOIN
JobMedia USING (MediaId)
) AS jm ON jm.JobId=Job.JobId AND jm.jmi=1
LEFT JOIN (
SELECT
JobMedia.JobId AS jobid,
COUNT(DISTINCT MediaId) AS volcount
FROM
JobMedia
GROUP BY JobMedia.JobId
) AS mi ON mi.JobId=Job.JobId
LEFT JOIN (
SELECT
JobId AS jobid,
LAG(JobId) OVER (ORDER BY JobId) AS prev_jobid,
LEAD(JobId) OVER (ORDER BY JobId) AS next_jobid
FROM Job
LEFT JOIN Client ON Client.ClientId=Job.ClientId
LEFT JOIN Pool ON Pool.PoolId=Job.PoolId
LEFT JOIN FileSet ON FileSet.FilesetId=Job.FilesetId
) AS pn ON Job.JobId=pn.jobid
LEFT JOIN Client ON Client.ClientId=Job.ClientId
LEFT JOIN Pool ON Pool.PoolId=Job.PoolId
LEFT JOIN FileSet ON FileSet.FilesetId=Job.FilesetId ORDER BY jobid DESC LIMIT 15000;


Once you click enter, please wait on the results and when you see them, please enter 'q' on the keyboard to see the timing at the bottom.

In my environment this query takes ~70 milliseconds.

Time: 71,414 ms

Thanks in advance for helping us to see what is wrong.


Best regards,
Marcin Haba (gani)

Elias Pereira

unread,
Mar 24, 2024, 9:01:51 AM3/24/24
to Marcin Haba, bacu...@googlegroups.com
hello Marcin,

We use mariadb.
--
Elias Pereira

Marcin Haba

unread,
Mar 24, 2024, 8:55:39 PM3/24/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

For MariaDB the SQL query looks like this:

time -p echo "SELECT Job.*,

pn.prev_jobid AS prev_jobid,
pn.next_jobid AS next_jobid,
Client.Name as client,
Pool.Name as pool,
FileSet.FileSet as fileset,
jm.volumename AS firstvol,
COALESCE(mi.volcount, 0) AS volcount,
TIMESTAMPDIFF(SECOND, '1970-01-01 00:00:00', Job.SchedTime) AS schedtime_epoch,
TIMESTAMPDIFF(SECOND, '1970-01-01 00:00:00', Job.StartTime) AS starttime_epoch,
TIMESTAMPDIFF(SECOND, '1970-01-01 00:00:00', Job.EndTime) AS endtime_epoch,
TIMESTAMPDIFF(SECOND, '1970-01-01 00:00:00', Job.RealEndTime) AS realendtime_epoch
LEFT JOIN FileSet ON FileSet.FilesetId=Job.FilesetId ORDER BY jobid DESC LIMIT 15000;" | mysql -u DB_USER -p DB_NAME

Could I ask you about trying it?

Before executing it you need to adapt the DB_USER and DB_NAME to your MariaDB user and database name.

After executing in the last three lines you will be able to see timing, like this:

real 1,77
user 0,01
sys 0,01

Could you share with us this result?

Thanks in advance!


Best regards,
Marcin Haba (gani)

Elias Pereira

unread,
Mar 25, 2024, 7:51:01 AM3/25/24
to Marcin Haba, bacu...@googlegroups.com
Hello Marcin, thanks for helping me!!!

Result:
real 135.31
user 0.03
sys 0.07

The result is extremely high, isn't it?
--
Elias Pereira

Marcin Haba

unread,
Mar 25, 2024, 11:52:33 PM3/25/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

Many thanks for providing us your SQL query results. I did a couple of tests on my side with MariaDB. The results you can find below for 50K and 100K jobs. After tests I tuned the database using MySQLTuner and the results for SQL query test went down about 50%.

For the test results, I think they are quite good. Could you tell me how many jobs you have? Also could you check your system with the database if something does not cause this problem (slow storage, overloaded server, memory...etc.)? Also I would really propose you use the MySQLTuner to perform the database tuning. You can find it here: https://github.com/major/MySQLTuner-perl This is a really great tuner tool.

MariaDB 10.5.23

=== Result for 50K jobs ===

Run the SQL query:

real 2,86
user 0,13
sys 0,41

Job list loading on the web interface (default limit 15000): 4.5 seconds

=== Result for 100K jobs ===

Run the SQL query:

real 3,34
user 0,13
sys 0,39

Job list loading on the web interface (default limit 15000): 4.8 seconds

=== Result for 100K jobs after tuning ====

Run the SQL query:

real 1,37
user 0,16
sys 0,40

Job list loading on the web interface (default limit 15000): 4.6 seconds


So, for summary, my opinion about this case is that you noticed that Bacularis works slower after upgrading to 2.6 because this modified more complex SQL query showed more clearly the db performance problem.

If I can help you somehow else, please let me know. And please send us information if the current advises helped to get better performance.

Thanks.


Best regards,
Marcin Haba (gani)

Elias Pereira

unread,
Mar 26, 2024, 9:47:42 AM3/26/24
to Marcin Haba, bacu...@googlegroups.com
Hello Marcin,

How did you run mysqltuner.pl
--
Elias Pereira

Marcin Haba

unread,
Mar 26, 2024, 2:12:10 PM3/26/24
to Elias Pereira, bacu...@googlegroups.com
Hello Elias,

I used this install instruction:

https://github.com/major/MySQLTuner-perl#downloadinstallation

and I run it by:

perl mysqltuner.pl --host 127.0.0.1


Best regards,
Marcin Haba (gani)
Reply all
Reply to author
Forward
Message has been deleted
0 new messages