Python BConsole Error - sometimes

[Mine Forumski]

Hello everyone,

I monitor Bareos via Zabbix. However, after upgrading to Bareos 23.0.3 (Debian 12), sometimes only
When returned empty, Zabbix was considered a bad value backup. And that several times a day.

I was then able to identify the problem as the Python script that queried the status.

https://github.com/IvanBayan/Zabbix-bareos/blob/master/bareos.job.py

To further narrow down the problem, I wrote a little script.

#! /bin/bash

RED='\033[0;31m'
NC='\033[0m' # No Color

while true; do
    #zabbix_get -s 127.0.0.1 -k bareos.job[last_status,"SRV-File01_DriveE"]
    WERT=$(/etc/zabbix/scripts/bareos.job.py last_status SRV-File01_DriveE)
    if [[ "$WERT" != "T" ]]; then
        echo -e "${RED}Wert stimmt nicht: $WERT ${NC}"
        else
            echo -e "$WERT"
    fi
done

It returns the last job status, normally T.
In this case there is also a Python error and the job status remains empty, which is why Zabbix gives a backup error.
The output then looks like this:

T
T
T
T
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 112, in call_fullresult
    data = json.loads(resultstring.decode("utf-8"))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/etc/zabbix/scripts/bareos.job.py", line 99, in <module>
    args.func(args)
  File "/etc/zabbix/scripts/bareos.job.py", line 26, in last_status
    console = create_console()
              ^^^^^^^^^^^^^^^^
  File "/etc/zabbix/scripts/bareos.job.py", line 19, in create_console
    console = bareos.bsock.DirectorConsoleJson(
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 59, in __init__
    super(DirectorConsoleJson, self).__init__(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsole.py", line 203, in __init__
    self._init_connection()
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 65, in _init_connection
    self.logger.debug(self.call(".api json"))
                      ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 87, in call
    json = self.call_fullresult(command)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 117, in call_fullresult
    raise bareos.exceptions.JsonRpcInvalidJsonReceivedException(data)
bareos.exceptions.JsonRpcInvalidJsonReceivedException: Expecting value: line 1 column 1 (char 0): b'.api: is an invalid command.\n'
Wert stimmt nicht nicht:
T
T
T
T
T
T
Traceback (most recent call last):
  File "/etc/zabbix/scripts/bareos.job.py", line 99, in <module>
    args.func(args)
  File "/etc/zabbix/scripts/bareos.job.py", line 26, in last_status
    console = create_console()
              ^^^^^^^^^^^^^^^^
  File "/etc/zabbix/scripts/bareos.job.py", line 19, in create_console
    console = bareos.bsock.DirectorConsoleJson(
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 59, in __init__
    super(DirectorConsoleJson, self).__init__(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsole.py", line 203, in __init__
    self._init_connection()
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 66, in _init_connection
    self.logger.debug(self.call(".api json compact=yes"))
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/bareos/bsock/directorconsolejson.py", line 93, in call
    raise bareos.exceptions.JsonRpcErrorReceivedException(json)
bareos.exceptions.JsonRpcErrorReceivedException: failed: .api: is an invalid command.

Wert stimmt nicht nicht:
T
T
T

An update to 23.0.4 didn't help either.

Since I don't know anything about Python, I hope you could help me.

Thank you
Robert

[Jörg Steffens]

Hi,

strange. I tried to reproduce this
and also run bareos.job.py in a loop against a test Bareos Director.
Here it now runs for several minutes without problems.

A difference I noticed is that I always get the usual warning:

UserWarning: Connection encryption via TLS-PSK is not available (not
available in 'ssl' and extra module 'sslpsk' is not installed).

as I've not installed sslpsk and my Python version does not support
TLS-PSK natively.

Anyhow, the error you receive is:

.api: is an invalid command.

which should not happen, if you always connect with the same user.

All that said means, I've no idea why it behaves strange in your
environment.

You could check if bareos-audit.log (/usr/log/bareos/bareos-audit.log)
reveals something suspicious.
If not, you can enable debug, to verify which user python connects.
Start with loglevel 50.

bconsole
Enter a period (.) to cancel a command.
*setdebug dir timestamp=1 level=50 trace=1

Regards,
Jörg

On 25.09.24 at 10:18 wrote Mine Forumski:

> --
> You received this message because you are subscribed to the Google
> Groups "bareos-users" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to bareos-users...@googlegroups.com
> <mailto:bareos-users...@googlegroups.com>.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com <https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com?utm_medium=email&utm_source=footer>.

--
Jörg Steffens joerg.s...@bareos.com
Bareos GmbH & Co. KG Phone: +49 221 630693-91
https://www.bareos.com

Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
Komplementär: Bareos Verwaltungs-GmbH
Geschäftsführer: Stephan Dühr, Jörg Steffens, Philipp Storz

[Mine Forumski]

Okay, there it is:

26-Sep-2024 10:48:07.777793 bareos-dir (10): dird/jcr_util.cc:35-0 NewDirectorJcr: configuration_resources_ is at 55cfd82c80f0 2024-09-19_09:43:16
26-Sep-2024 10:48:07.778120 bareos-dir (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <224470988.1727340487@R_DIRECTOR::bareos-dir> ssl=0
26-Sep-2024 10:48:07.778538 26-Sep-2024 10:48:07.778564 bareos-dir (50): lib/cram_md5.cc:61-0 my_name: <R_DIRECTOR::bareos-dir> - challenge_name: <zabbix>
bareos-dir (10): dird/jcr_util.cc:35-0 NewDirectorJcr: configuration_resources_ is at 55cfd82c80f0 2024-09-19_09:43:16
26-Sep-2024 10:48:07.778858 bareos-dir (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <802828123.1727340487@R_DIRECTOR::bareos-dir> ssl=0
26-Sep-2024 10:48:07.779290 bareos-dir (50): lib/cram_md5.cc:61-0 my_name: <R_DIRECTOR::bareos-dir> - challenge_name: <zabbix>
26-Sep-2024 10:48:07.820769 bareos-dir (10): dird/ua_audit.cc:105-0 : Console [zabbix] from [::1], Audit acl failure for Command .api
26-Sep-2024 10:48:07.908700 bareos-dir (10): dird/ua_audit.cc:136-0 : Console [zabbix] from [::1] cmdline llist job="SRV-Odoo01_BL" jobstatus=T last
26-Sep-2024 10:48:07.921328 bareos-dir (50): cats/postgresql.cc:226-0 pg_real_connect ok
26-Sep-2024 10:48:07.921397 bareos-dir (50): cats/postgresql.cc:228-0 db_user=bareos db_name=bareos db_password=*********************
26-Sep-2024 10:48:07.923379 bareos-dir (20): dird/ua_output.cc:618-0 list: llist job="SRV-Odoo01_BL" jobstatus=T last
26-Sep-2024 10:48:08.175195 bareos-dir (10): dird/jcr_util.cc:35-0 NewDirectorJcr: configuration_resources_ is at 55cfd82c80f0 2024-09-19_09:43:16
26-Sep-2024 10:48:08.175510 bareos-dir (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <2083653224.1727340488@R_DIRECTOR::bareos-dir> ssl=0
26-Sep-2024 10:48:08.176364 bareos-dir (50): lib/cram_md5.cc:61-0 my_name: <R_DIRECTOR::bareos-dir> - challenge_name: <zabbix>
26-Sep-2024 10:48:08.308695 bareos-dir (10): dird/ua_audit.cc:136-0 : Console [zabbix] from [::1] cmdline llist job="SRV-File01_DriveF" last
26-Sep-2024 10:48:08.319811 bareos-dir (50): cats/postgresql.cc:226-0 pg_real_connect ok
26-Sep-2024 10:48:08.319864 bareos-dir (50): cats/postgresql.cc:228-0 db_user=bareos db_name=bareos db_password=*********************
26-Sep-2024 10:48:08.321561 bareos-dir (20): dird/ua_output.cc:618-0 list: llist job="SRV-File01_DriveF" last

It says there:
Audit acl failure for Command .api

But my configs seems to be okay for me:
/etc/bareos/bareos-dir.d/console/zabbix.conf

Console {
  Name = "zabbix"
  Password = "*********************"
  Profile = monitoring
  TlsEnable = no
}

/etc/bareos/bareos-dir.d/profile/monitoring.conf
Profile {
  Name = "monitoring"
  CommandACL = list, llist, .jobs, .defaults, show, .clients, .filesets, .jobdefs, .levels, .locations, .media, .mediatypes, .pools, .schedule, .status, .storages, .types, .volstatus, .api, time, estimate, .sql, sqlquery
  Job ACL = *all*
  Schedule ACL = *all*
  Catalog ACL = *all*
  Pool ACL = *all*
  Storage ACL = *all*
  Client ACL = *all*
  FileSet ACL = *all*
  Where ACL = *all*
}

Thanks

Robert

[Mine Forumski]

Thank you for the answer.

It also only happens sporadically. Sometimes there is no problem for hours and then again every half hour or ten minutes per Job. 

But with 150 jobs you can add up to a few Zabbix emails. By this morning, for example, there had been 150 emails on this topic.

 Interestingly, it seems to affect some jobs more than others.

At the moment the debug is running but there is no problem. ;-)

VG

Robert

Jörg Steffens schrieb am Mittwoch, 25. September 2024 um 12:28:05 UTC+2:

[Jörg Steffens]

Hi,

this looks indeed strange. Until now, I've never seen even a similar issue.
Are you, by chance, do a lot a reloads at the Director? From the log, it
doesn't look like that.
What version of bareos-dir are you using? It would be interesting to
see, if this does also happen with the current versions.

What we could try to see if we can get more information about the
connections.
I attached a script that connects again and again to the Director,
gathers some information about the session and repeats that until an
error occurs (sees the "is an invalid command" string).
For that to work, you must add the "help" and ".help" command to your
CommandACL.
You can give it a try. Maybe this reveals something.

Regards,
Jörg

On 26.09.24 at 11:31 wrote Mine Forumski:

> and also run bareos.job.py <http://bareos.job.py> in a loop against

> <http://bareos.job.py> last_status SRV-File01_DriveE)

> <http://bareos.job.py>", line 99, in <module>
> >     args.func(args)
> >   File "/etc/zabbix/scripts/bareos.job.py
> <http://bareos.job.py>", line 26, in last_status

> >     console = create_console()
> >               ^^^^^^^^^^^^^^^^
> >   File "/etc/zabbix/scripts/bareos.job.py

> <http://bareos.job.py>", line 19, in create_console

> <http://bareos.job.py>", line 99, in <module>
> >     args.func(args)
> >   File "/etc/zabbix/scripts/bareos.job.py
> <http://bareos.job.py>", line 26, in last_status

> >     console = create_console()
> >               ^^^^^^^^^^^^^^^^
> >   File "/etc/zabbix/scripts/bareos.job.py

> <http://bareos.job.py>", line 19, in create_console

> https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com <https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com> <https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com?utm_medium=email&utm_source=footer <https://groups.google.com/d/msgid/bareos-users/8f8990ce-226d-4f22-9c38-157ff6c7b2bdn%40googlegroups.com?utm_medium=email&utm_source=footer>>.

>
> --
> Jörg Steffens joerg.s...@bareos.com
> Bareos GmbH & Co. KG Phone: +49 221 630693-91

> <tel:+49%20221%2063069391>
> https://www.bareos.com <https://www.bareos.com>

>
> Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
> Komplementär: Bareos Verwaltungs-GmbH
> Geschäftsführer: Stephan Dühr, Jörg Steffens, Philipp Storz
>
>

> --
> You received this message because you are subscribed to the Google
> Groups "bareos-users" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to bareos-users...@googlegroups.com
> <mailto:bareos-users...@googlegroups.com>.
> To view this discussion on the web visit

> https://groups.google.com/d/msgid/bareos-users/4697fa8b-0a0b-4a62-998f-0f22907d2817n%40googlegroups.com <https://groups.google.com/d/msgid/bareos-users/4697fa8b-0a0b-4a62-998f-0f22907d2817n%40googlegroups.com?utm_medium=email&utm_source=footer>.

[Mine Forumski]

Hi,

and thanks for your help.

I have attached the output of your script. What I see is that .help is unknown.
I ran the script twice. Both times it didn't know .help.

VG

Robert

[Jörg Steffens]

Hi,

Sebastian from Bareos may already have found the problem. He already
fixed it a while ago in master, so it will be part of the upcoming
bareos-24 release.
Currently we're discussing, how/when to backport it to bareos-23.

Regards,
Jörg

[Mine Forumski]

Ahoy,
the release of Bareos 24 won't take that long. In the meantime, I will adjust the regex filter of the Zabbix trigger
so that an empty value is not considered an error.

In this respect, the topic is closed for me for now.

Thank you very much and best regards
Robert