Agent_proxmox_ve error when backup reuse is 100%

I’m trying to get my first checkmk and Proxmox VE & PBS system working. While I’ve been able to add other generic Linux hosts to checkmk, I have not been able to add Proxmox cluster nodes. It appears to me that agent_proxmox_ve throws an error when a backup has 0.0 dirty bytes. Does my conclusion sound right? Any suggestions for how to fix this?

CMK version:: 2.3.0.cre
OS version:: Ubuntu 22.04
Error message:

ERROR 2024-05-01 12:12:20 root: Error in log at line 17: LogParseWarning(17, "End of VM '105' while still information is missing (we have: {'started_time', 'total_duration'})")
ERROR 2024-05-01 12:12:20 agent_proxmox_ve: Parsing the log for UPID='UPID:dc1pve1:000C1210:00C7F02E:663220B1:vzdump::root@pam:' resulted in a error(s) - write log content to '/omd/sites/monitoring/tmp/check_mk/special_agents/agent_proxmox_ve/erroneous-UPID:dc1pve1:000C1210:00C7F02E:663220B1:vzdump::root@pam:.log'

Example: Log that causes error (0.0 B)

INFO: using fast incremental mode (dirty-bitmap), 0.0 B dirty of 32.0 GiB total
INFO: 100% (0.0 B of 0.0 B) in 3s, read: 0 B/s, write: 0 B/s
INFO: backup was done incrementally, reused 32.00 GiB (100%)
INFO: adding notes to backup

Example: Log without error (>0.0 B)

INFO: using fast incremental mode (dirty-bitmap), 56.0 MiB dirty of 32.0 GiB total
INFO: 100% (56.0 MiB of 56.0 MiB) in 3s, read: 18.7 MiB/s, write: 18.7 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 31.95 GiB (99%)
INFO: transferred 56.00 MiB in 4 seconds (14.0 MiB/s)
INFO: adding notes to backup

Log files with “(100%)” in them.

root@dc1pve1:/var/log/pve/tasks# grep -r "(100%)" *
0/UPID:dc1pve1:000132F9:0012A9AD:663050A0:vzdump::root@pam::INFO: backup was done incrementally, reused 32.00 GiB (100%)
1/UPID:dc1pve1:000C1210:00C7F02E:663220B1:vzdump::root@pam::INFO: backup was done incrementally, reused 32.00 GiB (100%)
5/UPID:dc1pve1:002EBEEC:0CBB21A5:66301865:vzdump::root@pam::INFO: backup was done incrementally, reused 32.00 GiB (100%)

Output of “cmk --debug -vvn hostname”: (If it is a problem with checks or plugins)

OMD[monitoring]:~$ cmk --debug -vvn dc1pve1.paradetech.com
value store: synchronizing
Trying to acquire lock on /omd/sites/monitoring/tmp/check_mk/counters/dc1pve1.paradetech.com
Got lock on /omd/sites/monitoring/tmp/check_mk/counters/dc1pve1.paradetech.com
value store: loading from disk
Releasing lock on /omd/sites/monitoring/tmp/check_mk/counters/dc1pve1.paradetech.com
Released lock on /omd/sites/monitoring/tmp/check_mk/counters/dc1pve1.paradetech.com
Checkmk version 2.3.0
+ FETCHING DATA
  Source: SourceInfo(hostname='dc1pve1.paradetech.com', ipaddress='192.168.8.2', ident='special_proxmox_ve', fetcher_type=<FetcherType.SPECIAL_AGENT: 6>, source_type=<SourceType.HOST: 1>)
[cpu_tracking] Start [7f155bf39520]
Read from cache: AgentFileCache(dc1pve1.paradetech.com, path_template=/omd/sites/monitoring/tmp/check_mk/data_source_cache/special_proxmox_ve/{hostname}, max_age=MaxAge(checking=0, discovery=90.0, inventory=90.0), simulation=False, use_only_cache=False, file_cache_mode=6)
Not using cache (does not exist)
Calling: /omd/sites/monitoring/share/check_mk/agents/special/agent_proxmox_ve --pwstore=4@0@/omd/sites/monitoring/var/check_mk/passwords_merged@uuide9eaa92a-b125-4ce5-9036-41f3dc70bcac -u checkmk@pve -p '*************' --port 8006 --no-cert-check dc1pve1.paradetech.com
Get data from program
[cpu_tracking] Stop [7f155bf39520 - Snapshot(process=posix.times_result(user=0.009999999999999787, system=0.0, children_user=24.26, children_system=0.89, elapsed=60.79000000283122))]
  Source: SourceInfo(hostname='dc1pve1.paradetech.com', ipaddress='192.168.8.2', ident='piggyback', fetcher_type=<FetcherType.PIGGYBACK: 4>, source_type=<SourceType.HOST: 1>)
[cpu_tracking] Start [7f155ae91a90]
Read from cache: NoCache(dc1pve1.paradetech.com, path_template=/dev/null, max_age=MaxAge(checking=0.0, discovery=0.0, inventory=0.0), simulation=False, use_only_cache=False, file_cache_mode=1)
No piggyback files for 'dc1pve1.paradetech.com'. Skip processing.
No piggyback files for '192.168.8.2'. Skip processing.
Get piggybacked data
[cpu_tracking] Stop [7f155ae91a90 - Snapshot(process=posix.times_result(user=0.0, system=0.0, children_user=0.0, children_system=0.0, elapsed=0.0))]
[cpu_tracking] Start [7f155c0c7380]
+ PARSE FETCHER RESULTS
  HostKey(hostname='dc1pve1.paradetech.com', source_type=<SourceType.HOST: 1>)  -> Add sections: []
Received no piggyback data
No piggyback files for 'dc1pve1.paradetech.com'. Skip processing.
No piggyback files for '192.168.8.2'. Skip processing.
[cpu_tracking] Stop [7f155c0c7380 - Snapshot(process=posix.times_result(user=0.0, system=0.0, children_user=0.0, children_system=0.0, elapsed=0.0))]
[special_proxmox_ve] Agent failed - please submit a crash report! (Crash-ID: 01476c62-07f0-11ef-ae8c-0d882065dc13)(!!), [piggyback] Success (but no data found for this host), execution time 60.8 sec | execution_time=60.790 user_time=0.010 system_time=0.000 children_user_time=24.260 children_system_time=0.890 cmk_time_ds=35.630 cmk_time_agent=0.000
Agent exited with code 1: WARNING 2024-05-01 12:20:27 cmk.special_agents.v0_unstable.misc: Cache: could not find file - start a new one
ERROR 2024-05-01 12:20:29 root: Error in log at line 17: LogParseWarning(17, "End of VM '105' while still information is missing (we have: {'total_duration', 'started_time'})")
ERROR 2024-05-01 12:20:29 agent_proxmox_ve: Parsing the log for UPID='UPID:dc1pve1:000C1210:00C7F02E:663220B1:vzdump::root@pam:' resulted in a error(s) - write log content to '/omd/sites/monitoring/tmp/check_mk/special_agents/agent_proxmox_ve/erroneous-UPID:dc1pve1:000C1210:00C7F02E:663220B1:vzdump::root@pam:.log'
ERROR 2024-05-01 12:20:35 root: Error in log at line 17: LogParseWarning(17, "End of VM '105' while still information is missing (we have: {'total_duration', 'started_time'})")
ERROR 2024-05-01 12:20:35 agent_proxmox_ve: Parsing the log for UPID='UPID:dc1pve1:000132F9:0012A9AD:663050A0:vzdump::root@pam:' resulted in a error(s) - write log content to '/omd/sites/monitoring/tmp/check_mk/special_agents/agent_proxmox_ve/erroneous-UPID:dc1pve1:000132F9:0012A9AD:663050A0:vzdump::root@pam:.log'
ERROR 2024-05-01 12:20:35 root: Error in log at line 18: LogParseWarning(18, "End of VM '105' while still information is missing (we have: {'total_duration', 'started_time'})")
ERROR 2024-05-01 12:20:35 agent_proxmox_ve: Parsing the log for UPID='UPID:dc1pve1:002EBEEC:0CBB21A5:66301865:vzdump::root@pam:' resulted in a error(s) - write log content to '/omd/sites/monitoring/tmp/check_mk/special_agents/agent_proxmox_ve/erroneous-UPID:dc1pve1:002EBEEC:0CBB21A5:66301865:vzdump::root@pam:.log'
Agent failed - please submit a crash report! (Crash-ID: 01476c62-07f0-11ef-ae8c-0d882065dc13)(!!)
OMD[monitoring]:~$

Running the agent with the --debug option I’ve collected some additional information.
agent_proxmox_ve --verbose --debug -u ‘checkmk@pve’ -p ‘******’ --no-cert-check dc1pve1.paradetech.com

...
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-14:00:06', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-13:30:06', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-13:00:05', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-12:30:05', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-12:00:05', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-11:30:04', vms=())
INFO 2024-05-02 09:13:06 agent_proxmox_ve: BackupTask('vzdump', t='2024.04.20-11:00:04', vms=())
Traceback (most recent call last):
  File "/opt/omd/versions/2.3.0.cre/share/check_mk/agents/special/agent_proxmox_ve", line 11, in <module>
    sys.exit(main())
             ^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 868, in main
    return special_agent_main(parse_arguments, agent_proxmox_ve_main)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/v0_unstable/agent_common.py", line 171, in special_agent_main
    return _special_agent_main_core(parse_arguments, main_fn, argv or sys.argv[1:])
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/v0_unstable/agent_common.py", line 148, in _special_agent_main_core
    return main_fn(args)
           ^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 477, in agent_proxmox_ve_main
    logged_backup_data = fetch_backup_data(args, session, data["nodes"])
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 422, in fetch_backup_data
    return collect_vm_backup_info(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 377, in collect_vm_backup_info
    for task in backup_tasks:
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 423, in <genexpr>
    BackupTask(task, backup_log, strict=args.debug, dump_logs=args.dump_logs)
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 109, in __init__
    self.backup_data, errors = self._extract_logs(self._to_lines(logs), strict)
                               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 251, in _extract_logs
    for linenr, line in enumerate(logs):
  File "/omd/sites/monitoring/lib/python3/cmk/special_agents/agent_proxmox_ve.py", line 147, in <genexpr>
    for line in (elem["t"],)
                 ~~~~^^^^^
TypeError: string indices must be integers, not 'str'
OMD[monitoring]:~$

Line 147 is “for line in (elem[“t”],)” in the snippet below.

    @staticmethod
    def _to_lines(lines_with_numbers: LogData) -> Iterable[str]:
        """Extract line data from list of dicts containing redundant line numbers and line data
        >>> list(BackupTask._to_lines([{"n": 1, "t": "line1"}, {"n": 2, "t": "line2"}]))
        ['line1', 'line2']
        """
        # this has been true all the time and is left here for documentation
        # assert all((int(elem["n"]) - 1 == i) for i, elem in enumerate(lines_with_numbers))
        return (
            line
            for elem in lines_with_numbers
            for line in (elem["t"],)
            if isinstance(line, str) and line.strip()
        )  #  #  #  #