[SOLVED] No EMail when backkup job finisched

muekno

Member
Dec 15, 2023
164
11
18
I have two backup jobs, one daily backup 2 VMs runs fine every night send finished often, but sometimes to another not existing target, what resulst in mailer error no such recipient.
The second job for more VMs runs every sunday night, runs fine but no EMAil at all, no delivery failure.

Code:
Mail Delivery System <MAILER-DAEMON@pverh.muekno.de>
23.06.2024, 01:26
Undelivered Mail Returned to Sender
<root@pverh.muekno.de>
Rainer Müller-Knoche

PBS is latest version, latest update.

I had a look at the backup config file in /etc/pve the email adrsses there are correct and both the same everything else looks fine and is equal without the different scedule and VM numbers.

Code:
etc/pve# cat jobs.cfg
vzdump: backup-3b637589-99df
    schedule sun 01:00
    enabled 1
    fleecing 0
    mailnotification always
    mailto mk@muekno.de
    mode snapshot
    node pverh
    notes-template {{guestname}} Monthly keep 2
    prune-backups keep-last=2
    storage backup
    vmid 500,501,510,503,504,502,505

vzdump: backup-574250c6-3f79
    schedule 3:00
    enabled 1
    fleecing 0
    mailnotification always
    mailto mk@muekno.de
    mode snapshot
    node pverh
    notes-template {{guestname}} Daily keep 2
    prune-backups keep-last=2
    storage backup
    vmid 507,508
Please help, thanks
 
Code:
pveversion -a
Unknown option: a
USAGE: pveversion [--verbose]
root@pverh:~# pveversion -v
proxmox-ve: 8.2.0 (running kernel: 6.8.8-1-pve)
pve-manager: 8.2.4 (running version: 8.2.4/faa83925c9641325)
proxmox-kernel-helper: 8.1.0
proxmox-kernel-6.8: 6.8.8-1
proxmox-kernel-6.8.8-1-pve-signed: 6.8.8-1
proxmox-kernel-6.8.4-3-pve-signed: 6.8.4-3
proxmox-kernel-6.5.13-5-pve-signed: 6.5.13-5
proxmox-kernel-6.5: 6.5.13-5
proxmox-kernel-6.5.11-4-pve-signed: 6.5.11-4
ceph-fuse: 17.2.7-pve1
corosync: 3.1.7-pve3
criu: 3.17.1-2
glusterfs-client: 10.3-5
ifupdown2: 3.2.0-1+pmx8
ksm-control-daemon: 1.5-1
libjs-extjs: 7.0.0-4
libknet1: 1.28-pve1
libproxmox-acme-perl: 1.5.1
libproxmox-backup-qemu0: 1.4.1
libproxmox-rs-perl: 0.3.3
libpve-access-control: 8.1.4
libpve-apiclient-perl: 3.3.2
libpve-cluster-api-perl: 8.0.7
libpve-cluster-perl: 8.0.7
libpve-common-perl: 8.2.1
libpve-guest-common-perl: 5.1.3
libpve-http-server-perl: 5.1.0
libpve-network-perl: 0.9.8
libpve-rs-perl: 0.8.9
libpve-storage-perl: 8.2.2
libspice-server1: 0.15.1-1
lvm2: 2.03.16-2
lxc-pve: 6.0.0-1
lxcfs: 6.0.0-pve2
novnc-pve: 1.4.0-3
proxmox-backup-client: 3.2.4-1
proxmox-backup-file-restore: 3.2.4-1
proxmox-firewall: 0.4.2
proxmox-kernel-helper: 8.1.0
proxmox-mail-forward: 0.2.3
proxmox-mini-journalreader: 1.4.0
proxmox-offline-mirror-helper: 0.6.6
proxmox-widget-toolkit: 4.2.3
pve-cluster: 8.0.7
pve-container: 5.1.12
pve-docs: 8.2.2
pve-edk2-firmware: 4.2023.08-4
pve-esxi-import-tools: 0.7.1
pve-firewall: 5.0.7
pve-firmware: 3.12-1
pve-ha-manager: 4.0.5
pve-i18n: 3.2.2
pve-qemu-kvm: 8.1.5-6
pve-xtermjs: 5.3.0-3
qemu-server: 8.2.1
smartmontools: 7.3-pve1
spiceterm: 3.3.0
swtpm: 0.8.0+pve1
vncterm: 1.8.0
zfsutils-linux: 2.2.4-pve1
root@pverh:~#

Code:
Details
VMID    Name    Status    Time    Size    Filename
507    fs1-172-16-1-233    ok    5min 22s    600 GiB    vm/507/2024-06-24T01:00:04Z
508    GW1A-172-16-1-232    ok    21s    50 GiB    vm/508/2024-06-24T01:05:26Z
Total running time: 5min 43s
Total size: 650 GiB
Logs
vzdump 507 508 --quiet 1 --mode snapshot --mailnotification always --prune-backups 'keep-last=2' --storage backup --node pverh --fleecing 0 --notes-template '{{guestname}} Daily keep 2' --mailto mk@muekno.de


507: 2024-06-24 03:00:04 INFO: Starting Backup of VM 507 (qemu)
507: 2024-06-24 03:00:04 INFO: status = running
507: 2024-06-24 03:00:04 INFO: VM Name: fs1-172-16-1-233
507: 2024-06-24 03:00:04 INFO: include disk 'scsi0' 'VM_Space:vm-507-disk-0' 600G
507: 2024-06-24 03:00:04 INFO: backup mode: snapshot
507: 2024-06-24 03:00:04 INFO: ionice priority: 7
507: 2024-06-24 03:00:04 INFO: creating Proxmox Backup Server archive 'vm/507/2024-06-24T01:00:04Z'
507: 2024-06-24 03:00:04 INFO: issuing guest-agent 'fs-freeze' command
507: 2024-06-24 03:00:05 INFO: issuing guest-agent 'fs-thaw' command
507: 2024-06-24 03:00:05 INFO: started backup task 'e64d113b-dfc1-4022-828a-6a8d9174c957'
507: 2024-06-24 03:00:05 INFO: resuming VM again
507: 2024-06-24 03:00:05 INFO: scsi0: dirty-bitmap status: OK (21.3 GiB of 600.0 GiB dirty)
507: 2024-06-24 03:00:05 INFO: using fast incremental mode (dirty-bitmap), 21.3 GiB dirty of 600.0 GiB total
507: 2024-06-24 03:00:08 INFO:   1% (300.0 MiB of 21.3 GiB) in 3s, read: 100.0 MiB/s, write: 98.7 MiB/s
507: 2024-06-24 03:00:11 INFO:   2% (628.0 MiB of 21.3 GiB) in 6s, read: 109.3 MiB/s, write: 106.7 MiB/s
507: 2024-06-24 03:00:14 INFO:   4% (932.0 MiB of 21.3 GiB) in 9s, read: 101.3 MiB/s, write: 98.7 MiB/s
507: 2024-06-24 03:00:17 INFO:   5% (1.2 GiB of 21.3 GiB) in 12s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:00:20 INFO:   6% (1.4 GiB of 21.3 GiB) in 15s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:00:23 INFO:   7% (1.7 GiB of 21.3 GiB) in 18s, read: 88.0 MiB/s, write: 86.7 MiB/s
507: 2024-06-24 03:00:26 INFO:   9% (2.0 GiB of 21.3 GiB) in 21s, read: 89.3 MiB/s, write: 89.3 MiB/s
507: 2024-06-24 03:00:29 INFO:  10% (2.2 GiB of 21.3 GiB) in 24s, read: 80.0 MiB/s, write: 80.0 MiB/s
507: 2024-06-24 03:00:32 INFO:  11% (2.4 GiB of 21.3 GiB) in 27s, read: 60.0 MiB/s, write: 60.0 MiB/s
507: 2024-06-24 03:00:35 INFO:  12% (2.6 GiB of 21.3 GiB) in 30s, read: 84.0 MiB/s, write: 84.0 MiB/s
507: 2024-06-24 03:00:38 INFO:  13% (2.9 GiB of 21.3 GiB) in 33s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:00:41 INFO:  14% (3.1 GiB of 21.3 GiB) in 36s, read: 89.3 MiB/s, write: 89.3 MiB/s
507: 2024-06-24 03:00:44 INFO:  15% (3.4 GiB of 21.3 GiB) in 39s, read: 86.7 MiB/s, write: 86.7 MiB/s
507: 2024-06-24 03:00:47 INFO:  17% (3.7 GiB of 21.3 GiB) in 42s, read: 89.3 MiB/s, write: 89.3 MiB/s
507: 2024-06-24 03:00:50 INFO:  18% (3.9 GiB of 21.3 GiB) in 45s, read: 86.7 MiB/s, write: 76.0 MiB/s
507: 2024-06-24 03:00:53 INFO:  19% (4.2 GiB of 21.3 GiB) in 48s, read: 89.3 MiB/s, write: 89.3 MiB/s
507: 2024-06-24 03:00:56 INFO:  20% (4.4 GiB of 21.3 GiB) in 51s, read: 86.7 MiB/s, write: 86.7 MiB/s
507: 2024-06-24 03:00:59 INFO:  21% (4.7 GiB of 21.3 GiB) in 54s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:01:02 INFO:  23% (4.9 GiB of 21.3 GiB) in 57s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:01:05 INFO:  24% (5.2 GiB of 21.3 GiB) in 1m, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:01:08 INFO:  25% (5.5 GiB of 21.3 GiB) in 1m 3s, read: 86.7 MiB/s, write: 86.7 MiB/s
507: 2024-06-24 03:01:11 INFO:  26% (5.7 GiB of 21.3 GiB) in 1m 6s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:01:14 INFO:  27% (5.9 GiB of 21.3 GiB) in 1m 9s, read: 80.0 MiB/s, write: 80.0 MiB/s
507: 2024-06-24 03:01:17 INFO:  28% (6.2 GiB of 21.3 GiB) in 1m 12s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:01:20 INFO:  29% (6.3 GiB of 21.3 GiB) in 1m 15s, read: 62.7 MiB/s, write: 62.7 MiB/s
507: 2024-06-24 03:01:23 INFO:  30% (6.4 GiB of 21.3 GiB) in 1m 18s, read: 16.0 MiB/s, write: 16.0 MiB/s
507: 2024-06-24 03:01:29 INFO:  31% (6.7 GiB of 21.3 GiB) in 1m 24s, read: 48.7 MiB/s, write: 48.7 MiB/s
507: 2024-06-24 03:01:32 INFO:  32% (6.9 GiB of 21.3 GiB) in 1m 27s, read: 92.0 MiB/s, write: 92.0 MiB/s
507: 2024-06-24 03:01:35 INFO:  33% (7.2 GiB of 21.3 GiB) in 1m 30s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:01:38 INFO:  35% (7.5 GiB of 21.3 GiB) in 1m 33s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:01:41 INFO:  36% (7.7 GiB of 21.3 GiB) in 1m 36s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:01:44 INFO:  37% (8.0 GiB of 21.3 GiB) in 1m 39s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:01:47 INFO:  38% (8.2 GiB of 21.3 GiB) in 1m 42s, read: 72.0 MiB/s, write: 72.0 MiB/s
507: 2024-06-24 03:01:50 INFO:  39% (8.4 GiB of 21.3 GiB) in 1m 45s, read: 70.7 MiB/s, write: 70.7 MiB/s
507: 2024-06-24 03:01:53 INFO:  40% (8.6 GiB of 21.3 GiB) in 1m 48s, read: 72.0 MiB/s, write: 72.0 MiB/s
507: 2024-06-24 03:01:56 INFO:  41% (8.8 GiB of 21.3 GiB) in 1m 51s, read: 62.7 MiB/s, write: 62.7 MiB/s
507: 2024-06-24 03:01:59 INFO:  42% (9.0 GiB of 21.3 GiB) in 1m 54s, read: 64.0 MiB/s, write: 64.0 MiB/s
507: 2024-06-24 03:02:02 INFO:  43% (9.2 GiB of 21.3 GiB) in 1m 57s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:02:05 INFO:  44% (9.4 GiB of 21.3 GiB) in 2m, read: 76.0 MiB/s, write: 76.0 MiB/s
507: 2024-06-24 03:02:08 INFO:  45% (9.6 GiB of 21.3 GiB) in 2m 3s, read: 53.3 MiB/s, write: 53.3 MiB/s
507: 2024-06-24 03:02:11 INFO:  46% (9.8 GiB of 21.3 GiB) in 2m 6s, read: 76.0 MiB/s, write: 76.0 MiB/s
507: 2024-06-24 03:02:14 INFO:  47% (10.0 GiB of 21.3 GiB) in 2m 9s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:02:18 INFO:  48% (10.3 GiB of 21.3 GiB) in 2m 13s, read: 58.0 MiB/s, write: 58.0 MiB/s
507: 2024-06-24 03:02:21 INFO:  49% (10.5 GiB of 21.3 GiB) in 2m 16s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:02:24 INFO:  50% (10.7 GiB of 21.3 GiB) in 2m 19s, read: 77.3 MiB/s, write: 77.3 MiB/s
507: 2024-06-24 03:02:27 INFO:  51% (10.9 GiB of 21.3 GiB) in 2m 22s, read: 61.3 MiB/s, write: 61.3 MiB/s
507: 2024-06-24 03:02:30 INFO:  52% (11.1 GiB of 21.3 GiB) in 2m 25s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:02:33 INFO:  53% (11.3 GiB of 21.3 GiB) in 2m 28s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:02:36 INFO:  54% (11.5 GiB of 21.3 GiB) in 2m 31s, read: 64.0 MiB/s, write: 64.0 MiB/s
507: 2024-06-24 03:02:39 INFO:  55% (11.7 GiB of 21.3 GiB) in 2m 34s, read: 72.0 MiB/s, write: 72.0 MiB/s
507: 2024-06-24 03:02:42 INFO:  56% (11.9 GiB of 21.3 GiB) in 2m 37s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:02:46 INFO:  57% (12.2 GiB of 21.3 GiB) in 2m 41s, read: 55.0 MiB/s, write: 55.0 MiB/s
507: 2024-06-24 03:02:49 INFO:  58% (12.4 GiB of 21.3 GiB) in 2m 44s, read: 72.0 MiB/s, write: 72.0 MiB/s
507: 2024-06-24 03:02:52 INFO:  59% (12.6 GiB of 21.3 GiB) in 2m 47s, read: 76.0 MiB/s, write: 76.0 MiB/s
507: 2024-06-24 03:02:56 INFO:  60% (12.8 GiB of 21.3 GiB) in 2m 51s, read: 65.0 MiB/s, write: 65.0 MiB/s
507: 2024-06-24 03:02:59 INFO:  61% (13.1 GiB of 21.3 GiB) in 2m 54s, read: 72.0 MiB/s, write: 72.0 MiB/s
507: 2024-06-24 03:03:02 INFO:  62% (13.3 GiB of 21.3 GiB) in 2m 57s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:03:05 INFO:  63% (13.4 GiB of 21.3 GiB) in 3m, read: 54.7 MiB/s, write: 52.0 MiB/s
507: 2024-06-24 03:03:08 INFO:  64% (13.6 GiB of 21.3 GiB) in 3m 3s, read: 70.7 MiB/s, write: 45.3 MiB/s
507: 2024-06-24 03:03:11 INFO:  65% (13.9 GiB of 21.3 GiB) in 3m 6s, read: 84.0 MiB/s, write: 84.0 MiB/s
507: 2024-06-24 03:03:14 INFO:  66% (14.2 GiB of 21.3 GiB) in 3m 9s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:03:17 INFO:  67% (14.3 GiB of 21.3 GiB) in 3m 12s, read: 61.3 MiB/s, write: 61.3 MiB/s
507: 2024-06-24 03:03:25 INFO:  68% (14.6 GiB of 21.3 GiB) in 3m 20s, read: 30.5 MiB/s, write: 30.5 MiB/s
507: 2024-06-24 03:03:28 INFO:  69% (14.8 GiB of 21.3 GiB) in 3m 23s, read: 88.0 MiB/s, write: 88.0 MiB/s
507: 2024-06-24 03:03:31 INFO:  70% (15.1 GiB of 21.3 GiB) in 3m 26s, read: 94.7 MiB/s, write: 94.7 MiB/s
507: 2024-06-24 03:03:34 INFO:  72% (15.4 GiB of 21.3 GiB) in 3m 29s, read: 92.0 MiB/s, write: 92.0 MiB/s
507: 2024-06-24 03:03:37 INFO:  73% (15.6 GiB of 21.3 GiB) in 3m 32s, read: 89.3 MiB/s, write: 89.3 MiB/s
507: 2024-06-24 03:03:40 INFO:  74% (15.9 GiB of 21.3 GiB) in 3m 35s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:03:43 INFO:  75% (16.1 GiB of 21.3 GiB) in 3m 38s, read: 68.0 MiB/s, write: 68.0 MiB/s
507: 2024-06-24 03:03:47 INFO:  76% (16.2 GiB of 21.3 GiB) in 3m 42s, read: 51.0 MiB/s, write: 51.0 MiB/s
507: 2024-06-24 03:03:50 INFO:  77% (16.4 GiB of 21.3 GiB) in 3m 45s, read: 68.0 MiB/s, write: 68.0 MiB/s
507: 2024-06-24 03:03:53 INFO:  78% (16.7 GiB of 21.3 GiB) in 3m 48s, read: 70.7 MiB/s, write: 70.7 MiB/s
507: 2024-06-24 03:03:56 INFO:  79% (16.8 GiB of 21.3 GiB) in 3m 51s, read: 62.7 MiB/s, write: 62.7 MiB/s
507: 2024-06-24 03:03:59 INFO:  80% (17.1 GiB of 21.3 GiB) in 3m 54s, read: 77.3 MiB/s, write: 77.3 MiB/s
507: 2024-06-24 03:04:02 INFO:  81% (17.3 GiB of 21.3 GiB) in 3m 57s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:04:06 INFO:  82% (17.5 GiB of 21.3 GiB) in 4m 1s, read: 62.0 MiB/s, write: 62.0 MiB/s
507: 2024-06-24 03:04:09 INFO:  83% (17.7 GiB of 21.3 GiB) in 4m 4s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:04:12 INFO:  84% (18.0 GiB of 21.3 GiB) in 4m 7s, read: 74.7 MiB/s, write: 74.7 MiB/s
507: 2024-06-24 03:04:15 INFO:  85% (18.1 GiB of 21.3 GiB) in 4m 10s, read: 58.7 MiB/s, write: 58.7 MiB/s
507: 2024-06-24 03:04:19 INFO:  86% (18.4 GiB of 21.3 GiB) in 4m 14s, read: 68.0 MiB/s, write: 68.0 MiB/s
507: 2024-06-24 03:04:22 INFO:  87% (18.6 GiB of 21.3 GiB) in 4m 17s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:04:25 INFO:  88% (18.8 GiB of 21.3 GiB) in 4m 20s, read: 60.0 MiB/s, write: 60.0 MiB/s
507: 2024-06-24 03:04:28 INFO:  89% (19.0 GiB of 21.3 GiB) in 4m 23s, read: 69.3 MiB/s, write: 69.3 MiB/s
507: 2024-06-24 03:04:31 INFO:  90% (19.2 GiB of 21.3 GiB) in 4m 26s, read: 73.3 MiB/s, write: 73.3 MiB/s
507: 2024-06-24 03:04:34 INFO:  91% (19.4 GiB of 21.3 GiB) in 4m 29s, read: 66.7 MiB/s, write: 66.7 MiB/s
507: 2024-06-24 03:04:38 INFO:  92% (19.7 GiB of 21.3 GiB) in 4m 33s, read: 65.0 MiB/s, write: 65.0 MiB/s
507: 2024-06-24 03:04:41 INFO:  93% (19.9 GiB of 21.3 GiB) in 4m 36s, read: 76.0 MiB/s, write: 76.0 MiB/s
507: 2024-06-24 03:04:44 INFO:  94% (20.1 GiB of 21.3 GiB) in 4m 39s, read: 64.0 MiB/s, write: 64.0 MiB/s
507: 2024-06-24 03:04:48 INFO:  95% (20.3 GiB of 21.3 GiB) in 4m 43s, read: 65.0 MiB/s, write: 65.0 MiB/s
507: 2024-06-24 03:04:56 INFO:  96% (20.5 GiB of 21.3 GiB) in 4m 51s, read: 20.5 MiB/s, write: 20.5 MiB/s
507: 2024-06-24 03:04:59 INFO:  97% (20.7 GiB of 21.3 GiB) in 4m 54s, read: 90.7 MiB/s, write: 90.7 MiB/s
507: 2024-06-24 03:05:02 INFO:  98% (21.0 GiB of 21.3 GiB) in 4m 57s, read: 86.7 MiB/s, write: 86.7 MiB/s
507: 2024-06-24 03:05:05 INFO:  99% (21.3 GiB of 21.3 GiB) in 5m, read: 93.3 MiB/s, write: 64.0 MiB/s
507: 2024-06-24 03:05:08 INFO: 100% (21.3 GiB of 21.3 GiB) in 5m 3s, read: 14.7 MiB/s, write: 4.0 MiB/s
507: 2024-06-24 03:05:08 INFO: Waiting for server to finish backup validation...
507: 2024-06-24 03:05:25 INFO: backup was done incrementally, reused 578.94 GiB (96%)
507: 2024-06-24 03:05:25 INFO: transferred 21.31 GiB in 320 seconds (68.2 MiB/s)
507: 2024-06-24 03:05:25 INFO: adding notes to backup
507: 2024-06-24 03:05:25 INFO: prune older backups with retention: keep-last=2
507: 2024-06-24 03:05:26 INFO: running 'proxmox-backup-client prune' for 'vm/507'
507: 2024-06-24 03:05:26 INFO: pruned 1 backup(s) not covered by keep-retention policy
507: 2024-06-24 03:05:26 INFO: Finished Backup of VM 507 (00:05:22)

508: 2024-06-24 03:05:26 INFO: Starting Backup of VM 508 (qemu)
508: 2024-06-24 03:05:26 INFO: status = running
508: 2024-06-24 03:05:26 INFO: VM Name: GW1A-172-16-1-232
508: 2024-06-24 03:05:26 INFO: include disk 'scsi0' 'VM_Space:vm-508-disk-0' 50G
508: 2024-06-24 03:05:26 INFO: backup mode: snapshot
508: 2024-06-24 03:05:26 INFO: ionice priority: 7
508: 2024-06-24 03:05:26 INFO: creating Proxmox Backup Server archive 'vm/508/2024-06-24T01:05:26Z'
508: 2024-06-24 03:05:26 INFO: issuing guest-agent 'fs-freeze' command
508: 2024-06-24 03:05:26 INFO: issuing guest-agent 'fs-thaw' command
508: 2024-06-24 03:05:27 INFO: started backup task 'e0898bcc-3a89-41bb-a736-aca769d8df90'
508: 2024-06-24 03:05:27 INFO: resuming VM again
508: 2024-06-24 03:05:27 INFO: scsi0: dirty-bitmap status: OK (1.3 GiB of 50.0 GiB dirty)
508: 2024-06-24 03:05:27 INFO: using fast incremental mode (dirty-bitmap), 1.3 GiB dirty of 50.0 GiB total
508: 2024-06-24 03:05:30 INFO:  21% (284.0 MiB of 1.3 GiB) in 3s, read: 94.7 MiB/s, write: 94.7 MiB/s
508: 2024-06-24 03:05:33 INFO:  41% (556.0 MiB of 1.3 GiB) in 6s, read: 90.7 MiB/s, write: 90.7 MiB/s
508: 2024-06-24 03:05:36 INFO:  61% (828.0 MiB of 1.3 GiB) in 9s, read: 90.7 MiB/s, write: 88.0 MiB/s
508: 2024-06-24 03:05:39 INFO:  83% (1.1 GiB of 1.3 GiB) in 12s, read: 98.7 MiB/s, write: 96.0 MiB/s
508: 2024-06-24 03:05:42 INFO: 100% (1.3 GiB of 1.3 GiB) in 15s, read: 74.7 MiB/s, write: 73.3 MiB/s
508: 2024-06-24 03:05:42 INFO: Waiting for server to finish backup validation...
508: 2024-06-24 03:05:47 INFO: backup was done incrementally, reused 48.70 GiB (97%)
508: 2024-06-24 03:05:47 INFO: transferred 1.32 GiB in 20 seconds (67.4 MiB/s)
508: 2024-06-24 03:05:47 INFO: adding notes to backup
508: 2024-06-24 03:05:47 INFO: prune older backups with retention: keep-last=2
508: 2024-06-24 03:05:47 INFO: running 'proxmox-backup-client prune' for 'vm/508'
508: 2024-06-24 03:05:47 INFO: pruned 1 backup(s) not covered by keep-retention policy
508: 2024-06-24 03:05:47 INFO: Finished Backup of VM 508 (00:00:21)

The interesting point is, that the mail from the daily job mostly is sent fine, the above i one of the seldom that can not be delivered.
Also running manual single backup jobs, of the weekly job, sends mails correct, the bulk job never sends mail.


Kiund regards

Rainer
 
The interesting point is, that the mail from the daily job mostly is sent fine, the above i one of the seldom that can not be delivered.
Also running manual single backup jobs, of the weekly job, sends mails correct, the bulk job never sends mail.


Kiund regards

Rainer
Thanks for the output, unfortunately this is not the intended backup task log.

You can find and download the task log by selecting the corresponding backup task in the WebUI under <your-node> > Task History > <select-backup-task> > View > Download.
Further, you should also check the systemd journal for errors around the time of the backup, e.g. journalctl --since <DATETIME> --until <DATETIME> will give you a paginated view of the journal for the given timespan. Look out especially for errors/messages related to postfix and/or proxmox-mail-forward.

Also, do you have any custom notifications setup? Check the output of cat /etc/pve/notifications.cfg
 
  • Like
Reactions: Lukas Wagner
Hello Lucas,


I can not see really more information here than in that what i send you.



Code:
INFO: starting new backup job: vzdump 507 508 --quiet 1 --mode snapshot --mailnotification always --prune-backups 'keep-last=2' --storage backup --node pverh --fleecing 0 --notes-template '{{guestname}} Daily keep 2' --mailto mk@muekno.de
INFO: Starting Backup of VM 507 (qemu)
INFO: Backup started at 2024-06-24 03:00:04
INFO: status = running
INFO: VM Name: fs1-172-16-1-233
INFO: include disk 'scsi0' 'VM_Space:vm-507-disk-0' 600G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/507/2024-06-24T01:00:04Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'e64d113b-dfc1-4022-828a-6a8d9174c957'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (21.3 GiB of 600.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 21.3 GiB dirty of 600.0 GiB total
INFO:   1% (300.0 MiB of 21.3 GiB) in 3s, read: 100.0 MiB/s, write: 98.7 MiB/s
INFO:   2% (628.0 MiB of 21.3 GiB) in 6s, read: 109.3 MiB/s, write: 106.7 MiB/s
INFO:   4% (932.0 MiB of 21.3 GiB) in 9s, read: 101.3 MiB/s, write: 98.7 MiB/s
INFO:   5% (1.2 GiB of 21.3 GiB) in 12s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:   6% (1.4 GiB of 21.3 GiB) in 15s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:   7% (1.7 GiB of 21.3 GiB) in 18s, read: 88.0 MiB/s, write: 86.7 MiB/s
INFO:   9% (2.0 GiB of 21.3 GiB) in 21s, read: 89.3 MiB/s, write: 89.3 MiB/s
INFO:  10% (2.2 GiB of 21.3 GiB) in 24s, read: 80.0 MiB/s, write: 80.0 MiB/s
INFO:  11% (2.4 GiB of 21.3 GiB) in 27s, read: 60.0 MiB/s, write: 60.0 MiB/s
INFO:  12% (2.6 GiB of 21.3 GiB) in 30s, read: 84.0 MiB/s, write: 84.0 MiB/s
INFO:  13% (2.9 GiB of 21.3 GiB) in 33s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  14% (3.1 GiB of 21.3 GiB) in 36s, read: 89.3 MiB/s, write: 89.3 MiB/s
INFO:  15% (3.4 GiB of 21.3 GiB) in 39s, read: 86.7 MiB/s, write: 86.7 MiB/s
INFO:  17% (3.7 GiB of 21.3 GiB) in 42s, read: 89.3 MiB/s, write: 89.3 MiB/s
INFO:  18% (3.9 GiB of 21.3 GiB) in 45s, read: 86.7 MiB/s, write: 76.0 MiB/s
INFO:  19% (4.2 GiB of 21.3 GiB) in 48s, read: 89.3 MiB/s, write: 89.3 MiB/s
INFO:  20% (4.4 GiB of 21.3 GiB) in 51s, read: 86.7 MiB/s, write: 86.7 MiB/s
INFO:  21% (4.7 GiB of 21.3 GiB) in 54s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  23% (4.9 GiB of 21.3 GiB) in 57s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  24% (5.2 GiB of 21.3 GiB) in 1m, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  25% (5.5 GiB of 21.3 GiB) in 1m 3s, read: 86.7 MiB/s, write: 86.7 MiB/s
INFO:  26% (5.7 GiB of 21.3 GiB) in 1m 6s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  27% (5.9 GiB of 21.3 GiB) in 1m 9s, read: 80.0 MiB/s, write: 80.0 MiB/s
INFO:  28% (6.2 GiB of 21.3 GiB) in 1m 12s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  29% (6.3 GiB of 21.3 GiB) in 1m 15s, read: 62.7 MiB/s, write: 62.7 MiB/s
INFO:  30% (6.4 GiB of 21.3 GiB) in 1m 18s, read: 16.0 MiB/s, write: 16.0 MiB/s
INFO:  31% (6.7 GiB of 21.3 GiB) in 1m 24s, read: 48.7 MiB/s, write: 48.7 MiB/s
INFO:  32% (6.9 GiB of 21.3 GiB) in 1m 27s, read: 92.0 MiB/s, write: 92.0 MiB/s
INFO:  33% (7.2 GiB of 21.3 GiB) in 1m 30s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  35% (7.5 GiB of 21.3 GiB) in 1m 33s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  36% (7.7 GiB of 21.3 GiB) in 1m 36s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  37% (8.0 GiB of 21.3 GiB) in 1m 39s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  38% (8.2 GiB of 21.3 GiB) in 1m 42s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  39% (8.4 GiB of 21.3 GiB) in 1m 45s, read: 70.7 MiB/s, write: 70.7 MiB/s
INFO:  40% (8.6 GiB of 21.3 GiB) in 1m 48s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  41% (8.8 GiB of 21.3 GiB) in 1m 51s, read: 62.7 MiB/s, write: 62.7 MiB/s
INFO:  42% (9.0 GiB of 21.3 GiB) in 1m 54s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:  43% (9.2 GiB of 21.3 GiB) in 1m 57s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  44% (9.4 GiB of 21.3 GiB) in 2m, read: 76.0 MiB/s, write: 76.0 MiB/s
INFO:  45% (9.6 GiB of 21.3 GiB) in 2m 3s, read: 53.3 MiB/s, write: 53.3 MiB/s
INFO:  46% (9.8 GiB of 21.3 GiB) in 2m 6s, read: 76.0 MiB/s, write: 76.0 MiB/s
INFO:  47% (10.0 GiB of 21.3 GiB) in 2m 9s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  48% (10.3 GiB of 21.3 GiB) in 2m 13s, read: 58.0 MiB/s, write: 58.0 MiB/s
INFO:  49% (10.5 GiB of 21.3 GiB) in 2m 16s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  50% (10.7 GiB of 21.3 GiB) in 2m 19s, read: 77.3 MiB/s, write: 77.3 MiB/s
INFO:  51% (10.9 GiB of 21.3 GiB) in 2m 22s, read: 61.3 MiB/s, write: 61.3 MiB/s
INFO:  52% (11.1 GiB of 21.3 GiB) in 2m 25s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  53% (11.3 GiB of 21.3 GiB) in 2m 28s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  54% (11.5 GiB of 21.3 GiB) in 2m 31s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:  55% (11.7 GiB of 21.3 GiB) in 2m 34s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  56% (11.9 GiB of 21.3 GiB) in 2m 37s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  57% (12.2 GiB of 21.3 GiB) in 2m 41s, read: 55.0 MiB/s, write: 55.0 MiB/s
INFO:  58% (12.4 GiB of 21.3 GiB) in 2m 44s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  59% (12.6 GiB of 21.3 GiB) in 2m 47s, read: 76.0 MiB/s, write: 76.0 MiB/s
INFO:  60% (12.8 GiB of 21.3 GiB) in 2m 51s, read: 65.0 MiB/s, write: 65.0 MiB/s
INFO:  61% (13.1 GiB of 21.3 GiB) in 2m 54s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  62% (13.3 GiB of 21.3 GiB) in 2m 57s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  63% (13.4 GiB of 21.3 GiB) in 3m, read: 54.7 MiB/s, write: 52.0 MiB/s
INFO:  64% (13.6 GiB of 21.3 GiB) in 3m 3s, read: 70.7 MiB/s, write: 45.3 MiB/s
INFO:  65% (13.9 GiB of 21.3 GiB) in 3m 6s, read: 84.0 MiB/s, write: 84.0 MiB/s
INFO:  66% (14.2 GiB of 21.3 GiB) in 3m 9s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  67% (14.3 GiB of 21.3 GiB) in 3m 12s, read: 61.3 MiB/s, write: 61.3 MiB/s
INFO:  68% (14.6 GiB of 21.3 GiB) in 3m 20s, read: 30.5 MiB/s, write: 30.5 MiB/s
INFO:  69% (14.8 GiB of 21.3 GiB) in 3m 23s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  70% (15.1 GiB of 21.3 GiB) in 3m 26s, read: 94.7 MiB/s, write: 94.7 MiB/s
INFO:  72% (15.4 GiB of 21.3 GiB) in 3m 29s, read: 92.0 MiB/s, write: 92.0 MiB/s
INFO:  73% (15.6 GiB of 21.3 GiB) in 3m 32s, read: 89.3 MiB/s, write: 89.3 MiB/s
INFO:  74% (15.9 GiB of 21.3 GiB) in 3m 35s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  75% (16.1 GiB of 21.3 GiB) in 3m 38s, read: 68.0 MiB/s, write: 68.0 MiB/s
INFO:  76% (16.2 GiB of 21.3 GiB) in 3m 42s, read: 51.0 MiB/s, write: 51.0 MiB/s
INFO:  77% (16.4 GiB of 21.3 GiB) in 3m 45s, read: 68.0 MiB/s, write: 68.0 MiB/s
INFO:  78% (16.7 GiB of 21.3 GiB) in 3m 48s, read: 70.7 MiB/s, write: 70.7 MiB/s
INFO:  79% (16.8 GiB of 21.3 GiB) in 3m 51s, read: 62.7 MiB/s, write: 62.7 MiB/s
INFO:  80% (17.1 GiB of 21.3 GiB) in 3m 54s, read: 77.3 MiB/s, write: 77.3 MiB/s
INFO:  81% (17.3 GiB of 21.3 GiB) in 3m 57s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  82% (17.5 GiB of 21.3 GiB) in 4m 1s, read: 62.0 MiB/s, write: 62.0 MiB/s
INFO:  83% (17.7 GiB of 21.3 GiB) in 4m 4s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  84% (18.0 GiB of 21.3 GiB) in 4m 7s, read: 74.7 MiB/s, write: 74.7 MiB/s
INFO:  85% (18.1 GiB of 21.3 GiB) in 4m 10s, read: 58.7 MiB/s, write: 58.7 MiB/s
INFO:  86% (18.4 GiB of 21.3 GiB) in 4m 14s, read: 68.0 MiB/s, write: 68.0 MiB/s
INFO:  87% (18.6 GiB of 21.3 GiB) in 4m 17s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  88% (18.8 GiB of 21.3 GiB) in 4m 20s, read: 60.0 MiB/s, write: 60.0 MiB/s
INFO:  89% (19.0 GiB of 21.3 GiB) in 4m 23s, read: 69.3 MiB/s, write: 69.3 MiB/s
INFO:  90% (19.2 GiB of 21.3 GiB) in 4m 26s, read: 73.3 MiB/s, write: 73.3 MiB/s
INFO:  91% (19.4 GiB of 21.3 GiB) in 4m 29s, read: 66.7 MiB/s, write: 66.7 MiB/s
INFO:  92% (19.7 GiB of 21.3 GiB) in 4m 33s, read: 65.0 MiB/s, write: 65.0 MiB/s
INFO:  93% (19.9 GiB of 21.3 GiB) in 4m 36s, read: 76.0 MiB/s, write: 76.0 MiB/s
INFO:  94% (20.1 GiB of 21.3 GiB) in 4m 39s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:  95% (20.3 GiB of 21.3 GiB) in 4m 43s, read: 65.0 MiB/s, write: 65.0 MiB/s
INFO:  96% (20.5 GiB of 21.3 GiB) in 4m 51s, read: 20.5 MiB/s, write: 20.5 MiB/s
INFO:  97% (20.7 GiB of 21.3 GiB) in 4m 54s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  98% (21.0 GiB of 21.3 GiB) in 4m 57s, read: 86.7 MiB/s, write: 86.7 MiB/s
INFO:  99% (21.3 GiB of 21.3 GiB) in 5m, read: 93.3 MiB/s, write: 64.0 MiB/s
INFO: 100% (21.3 GiB of 21.3 GiB) in 5m 3s, read: 14.7 MiB/s, write: 4.0 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 578.94 GiB (96%)
INFO: transferred 21.31 GiB in 320 seconds (68.2 MiB/s)
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=2
INFO: running 'proxmox-backup-client prune' for 'vm/507'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 507 (00:05:22)
INFO: Backup finished at 2024-06-24 03:05:26
INFO: Starting Backup of VM 508 (qemu)
INFO: Backup started at 2024-06-24 03:05:26
INFO: status = running
INFO: VM Name: GW1A-172-16-1-232
INFO: include disk 'scsi0' 'VM_Space:vm-508-disk-0' 50G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/508/2024-06-24T01:05:26Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'e0898bcc-3a89-41bb-a736-aca769d8df90'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (1.3 GiB of 50.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 1.3 GiB dirty of 50.0 GiB total
INFO:  21% (284.0 MiB of 1.3 GiB) in 3s, read: 94.7 MiB/s, write: 94.7 MiB/s
INFO:  41% (556.0 MiB of 1.3 GiB) in 6s, read: 90.7 MiB/s, write: 90.7 MiB/s
INFO:  61% (828.0 MiB of 1.3 GiB) in 9s, read: 90.7 MiB/s, write: 88.0 MiB/s
INFO:  83% (1.1 GiB of 1.3 GiB) in 12s, read: 98.7 MiB/s, write: 96.0 MiB/s
INFO: 100% (1.3 GiB of 1.3 GiB) in 15s, read: 74.7 MiB/s, write: 73.3 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 48.70 GiB (97%)
INFO: transferred 1.32 GiB in 20 seconds (67.4 MiB/s)
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=2
INFO: running 'proxmox-backup-client prune' for 'vm/508'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 508 (00:00:21)
INFO: Backup finished at 2024-06-24 03:05:47
INFO: Backup job finished successfully
INFO: notified via target `<mk@muekno.de>`
TASK OK



Thats from the job I never get Mails
Code:
INFO: starting new backup job: vzdump 500 501 510 503 504 502 505 --mailto mk@muekno.de --notes-template '{{guestname}} Monthly keep 2' --fleecing 0 --node pverh --storage backup --prune-backups 'keep-last=2' --mode snapshot --mailnotification always --quiet 1
INFO: Starting Backup of VM 500 (qemu)
INFO: Backup started at 2024-06-23 01:00:06
INFO: status = running
INFO: VM Name: proxy-172-16-1-245
INFO: include disk 'scsi0' 'VM_Space:vm-500-disk-0' 16G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/500/2024-06-22T23:00:06Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'f8d3922b-5925-4ac9-8158-0465a929d596'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: created new
INFO:   0% (120.0 MiB of 16.0 GiB) in 3s, read: 40.0 MiB/s, write: 5.3 MiB/s
INFO:   1% (188.0 MiB of 16.0 GiB) in 12s, read: 7.6 MiB/s, write: 2.7 MiB/s
INFO:   2% (364.0 MiB of 16.0 GiB) in 17s, read: 35.2 MiB/s, write: 3.2 MiB/s
INFO:   3% (500.0 MiB of 16.0 GiB) in 21s, read: 34.0 MiB/s, write: 0 B/s
INFO:   4% (664.0 MiB of 16.0 GiB) in 38s, read: 9.6 MiB/s, write: 722.8 KiB/s
INFO:   5% (832.0 MiB of 16.0 GiB) in 51s, read: 12.9 MiB/s, write: 1.8 MiB/s
INFO:   6% (984.0 MiB of 16.0 GiB) in 54s, read: 50.7 MiB/s, write: 6.7 MiB/s
INFO:   7% (1.1 GiB of 16.0 GiB) in 1m 3s, read: 18.7 MiB/s, write: 7.6 MiB/s
INFO:   8% (1.3 GiB of 16.0 GiB) in 1m 18s, read: 10.7 MiB/s, write: 5.3 MiB/s
INFO:   9% (1.5 GiB of 16.0 GiB) in 1m 28s, read: 18.0 MiB/s, write: 409.6 KiB/s
INFO:  10% (1.7 GiB of 16.0 GiB) in 1m 34s, read: 38.0 MiB/s, write: 0 B/s
INFO:  11% (1.8 GiB of 16.0 GiB) in 1m 40s, read: 15.3 MiB/s, write: 0 B/s
INFO:  12% (2.0 GiB of 16.0 GiB) in 1m 44s, read: 54.0 MiB/s, write: 0 B/s
INFO:  13% (2.2 GiB of 16.0 GiB) in 1m 47s, read: 74.7 MiB/s, write: 2.7 MiB/s
INFO:  14% (2.2 GiB of 16.0 GiB) in 1m 50s, read: 17.3 MiB/s, write: 1.3 MiB/s
INFO:  15% (2.4 GiB of 16.0 GiB) in 1m 56s, read: 30.0 MiB/s, write: 682.7 KiB/s
INFO:  16% (2.7 GiB of 16.0 GiB) in 1m 59s, read: 89.3 MiB/s, write: 4.0 MiB/s
INFO:  17% (2.8 GiB of 16.0 GiB) in 2m 2s, read: 42.7 MiB/s, write: 8.0 MiB/s
INFO:  18% (3.0 GiB of 16.0 GiB) in 2m 5s, read: 56.0 MiB/s, write: 6.7 MiB/s
INFO:  20% (3.2 GiB of 16.0 GiB) in 2m 8s, read: 88.0 MiB/s, write: 0 B/s
INFO:  22% (3.6 GiB of 16.0 GiB) in 2m 11s, read: 122.7 MiB/s, write: 1.3 MiB/s
INFO:  23% (3.8 GiB of 16.0 GiB) in 2m 14s, read: 58.7 MiB/s, write: 0 B/s
INFO:  25% (4.0 GiB of 16.0 GiB) in 2m 17s, read: 86.7 MiB/s, write: 0 B/s
INFO:  26% (4.3 GiB of 16.0 GiB) in 2m 20s, read: 97.3 MiB/s, write: 2.7 MiB/s
INFO:  27% (4.4 GiB of 16.0 GiB) in 2m 23s, read: 48.0 MiB/s, write: 0 B/s
INFO:  29% (4.7 GiB of 16.0 GiB) in 2m 26s, read: 97.3 MiB/s, write: 4.0 MiB/s
INFO:  30% (4.8 GiB of 16.0 GiB) in 2m 29s, read: 40.0 MiB/s, write: 1.3 MiB/s
INFO:  32% (5.2 GiB of 16.0 GiB) in 2m 32s, read: 105.3 MiB/s, write: 4.0 MiB/s
INFO:  33% (5.4 GiB of 16.0 GiB) in 2m 35s, read: 69.3 MiB/s, write: 0 B/s
INFO:  35% (5.7 GiB of 16.0 GiB) in 2m 38s, read: 113.3 MiB/s, write: 0 B/s
INFO:  38% (6.1 GiB of 16.0 GiB) in 2m 41s, read: 153.3 MiB/s, write: 1.3 MiB/s
INFO:  39% (6.4 GiB of 16.0 GiB) in 2m 44s, read: 81.3 MiB/s, write: 22.7 MiB/s
INFO:  40% (6.4 GiB of 16.0 GiB) in 2m 47s, read: 14.7 MiB/s, write: 0 B/s
INFO:  41% (6.7 GiB of 16.0 GiB) in 2m 50s, read: 88.0 MiB/s, write: 0 B/s
INFO:  43% (6.9 GiB of 16.0 GiB) in 2m 53s, read: 86.7 MiB/s, write: 0 B/s
INFO:  44% (7.2 GiB of 16.0 GiB) in 2m 56s, read: 85.3 MiB/s, write: 18.7 MiB/s
INFO:  46% (7.4 GiB of 16.0 GiB) in 2m 59s, read: 85.3 MiB/s, write: 9.3 MiB/s
INFO:  47% (7.6 GiB of 16.0 GiB) in 3m 2s, read: 60.0 MiB/s, write: 0 B/s
INFO:  48% (7.8 GiB of 16.0 GiB) in 3m 5s, read: 65.3 MiB/s, write: 0 B/s
INFO:  51% (8.2 GiB of 16.0 GiB) in 3m 8s, read: 136.0 MiB/s, write: 2.7 MiB/s
INFO:  52% (8.5 GiB of 16.0 GiB) in 3m 11s, read: 94.7 MiB/s, write: 1.3 MiB/s
INFO:  54% (8.7 GiB of 16.0 GiB) in 3m 14s, read: 72.0 MiB/s, write: 4.0 MiB/s
INFO:  55% (8.8 GiB of 16.0 GiB) in 3m 17s, read: 54.7 MiB/s, write: 0 B/s
......
INFO: prune older backups with retention: keep-last=2
INFO: running 'proxmox-backup-client prune' for 'vm/510'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 510 (00:02:33)
INFO: Backup finished at 2024-06-23 01:26:19
INFO: Backup job finished successfully
INFO: notified via target `<mk@muekno.de>`
TASK OK

I had to truncate this as it was too large

In my opnion the backup jobs themself are fine, it ist just the notification goes wrong, everytime on the the weekly yob, somtimes on the daily job.
As I administrate my mailsystem too, (postfix als relay, GroupWise at the end - all hosts runing on this PVE), have access to all log files etc. and there I can not find any problems.

Kind Regards


Rainer
 
I can not see really more information here than in that what i send you.

Well there is this additional information I was looking for ;)
INFO: notified via target `<mk@muekno.de>`

Please do also provide the excerpt from the systemd journal, this should hopefully tell more about why the mail could not be send by the PVE host.
 
Thats the syslog part from last Sunday, wehre the daily and weekly job are scheduled

Code:
Jun 23 00:00:03 pverh systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service...
Jun 23 00:00:03 pverh systemd[1]: Starting logrotate.service - Rotate log files...
Jun 23 00:00:03 pverh systemd[1]: dpkg-db-backup.service: Deactivated successfully.
Jun 23 00:00:03 pverh systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service.
Jun 23 00:00:03 pverh systemd[1]: Reloading pveproxy.service - PVE API Proxy Server...
Jun 23 00:00:05 pverh pveproxy[527805]: send HUP to 1402
Jun 23 00:00:05 pverh pveproxy[1402]: received signal HUP
Jun 23 00:00:05 pverh pveproxy[1402]: server closing
Jun 23 00:00:05 pverh pveproxy[1402]: server shutdown (restart)
Jun 23 00:00:05 pverh systemd[1]: Reloaded pveproxy.service - PVE API Proxy Server.
Jun 23 00:00:05 pverh systemd[1]: Reloading spiceproxy.service - PVE SPICE Proxy Server...
Jun 23 00:00:06 pverh spiceproxy[527838]: send HUP to 1407
Jun 23 00:00:06 pverh spiceproxy[1407]: received signal HUP
Jun 23 00:00:06 pverh spiceproxy[1407]: server closing
Jun 23 00:00:06 pverh spiceproxy[1407]: server shutdown (restart)
Jun 23 00:00:06 pverh systemd[1]: Reloaded spiceproxy.service - PVE SPICE Proxy Server.
Jun 23 00:00:06 pverh systemd[1]: Stopping pvefw-logger.service - Proxmox VE firewall logger...
Jun 23 00:00:06 pverh pvefw-logger[134100]: received terminate request (signal)
Jun 23 00:00:06 pverh pvefw-logger[134100]: stopping pvefw logger
Jun 23 00:00:07 pverh systemd[1]: pvefw-logger.service: Deactivated successfully.
Jun 23 00:00:07 pverh systemd[1]: Stopped pvefw-logger.service - Proxmox VE firewall logger.
Jun 23 00:00:07 pverh systemd[1]: pvefw-logger.service: Consumed 12.673s CPU time.
Jun 23 00:00:07 pverh systemd[1]: Starting pvefw-logger.service - Proxmox VE firewall logger...
Jun 23 00:00:07 pverh pvefw-logger[527855]: starting pvefw logger
Jun 23 00:00:07 pverh systemd[1]: Started pvefw-logger.service - Proxmox VE firewall logger.
Jun 23 00:00:07 pverh systemd[1]: logrotate.service: Deactivated successfully.
Jun 23 00:00:07 pverh systemd[1]: Finished logrotate.service - Rotate log files.
Jun 23 00:00:07 pverh spiceproxy[1407]: restarting server
Jun 23 00:00:07 pverh spiceproxy[1407]: starting 1 worker(s)
Jun 23 00:00:07 pverh spiceproxy[1407]: worker 527861 started
Jun 23 00:00:08 pverh pveproxy[1402]: Using '/etc/pve/local/pveproxy-ssl.pem' as certificate for the web interface.
Jun 23 00:00:08 pverh pveproxy[1402]: restarting server
Jun 23 00:00:08 pverh pveproxy[1402]: starting 3 worker(s)
Jun 23 00:00:08 pverh pveproxy[1402]: worker 527864 started
Jun 23 00:00:08 pverh pveproxy[1402]: worker 527865 started
Jun 23 00:00:08 pverh pveproxy[1402]: worker 527866 started
Jun 23 00:00:12 pverh spiceproxy[134108]: worker exit
Jun 23 00:00:12 pverh spiceproxy[1407]: worker 134108 finished
Jun 23 00:00:13 pverh pveproxy[134111]: worker exit
Jun 23 00:00:13 pverh pveproxy[134110]: worker exit
Jun 23 00:00:13 pverh pveproxy[134112]: worker exit
Jun 23 00:00:13 pverh pveproxy[1402]: worker 134112 finished
Jun 23 00:00:13 pverh pveproxy[1402]: worker 134111 finished
Jun 23 00:00:13 pverh pveproxy[1402]: worker 134110 finished
Jun 23 00:17:01 pverh CRON[532530]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 00:17:01 pverh CRON[532531]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Jun 23 00:17:01 pverh CRON[532530]: pam_unix(cron:session): session closed for user root
Jun 23 01:00:06 pverh pvescheduler[544249]: <root@pam> starting task UPID:pverh:00084DFA:00B575A8:66775776:vzdump::root@pam:
Jun 23 01:00:06 pverh pvescheduler[544250]: INFO: starting new backup job: vzdump 500 501 510 503 504 502 505 --mailto mk@muekno.de --notes-template '{{guestname}} Monthly keep 2' --fleecing 0 --node pverh --storage backup --prune-backups 'keep-last=2' --mode snapshot --mailnotification always --quiet 1
Jun 23 01:00:06 pverh pvescheduler[544250]: INFO: Starting Backup of VM 500 (qemu)
Jun 23 01:04:40 pverh kernel: INFO: task txg_sync:724 blocked for more than 122 seconds.
Jun 23 01:04:40 pverh kernel:       Tainted: P           O       6.8.8-1-pve #1
Jun 23 01:04:40 pverh kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jun 23 01:04:40 pverh kernel: task:txg_sync        state:D stack:0     pid:724   tgid:724   ppid:2      flags:0x00004000
Jun 23 01:04:40 pverh kernel: Call Trace:
Jun 23 01:04:40 pverh kernel:  <TASK>
Jun 23 01:04:40 pverh kernel:  __schedule+0x401/0x15e0
Jun 23 01:04:40 pverh kernel:  schedule+0x33/0x110
Jun 23 01:04:40 pverh kernel:  schedule_timeout+0x95/0x170
Jun 23 01:04:40 pverh kernel:  ? __pfx_process_timeout+0x10/0x10
Jun 23 01:04:40 pverh kernel:  io_schedule_timeout+0x51/0x80
Jun 23 01:04:40 pverh kernel:  __cv_timedwait_common+0x140/0x180 [spl]
Jun 23 01:04:40 pverh kernel:  ? __pfx_autoremove_wake_function+0x10/0x10
Jun 23 01:04:40 pverh kernel:  __cv_timedwait_io+0x19/0x30 [spl]
Jun 23 01:04:40 pverh kernel:  zio_wait+0x13a/0x2c0 [zfs]
Jun 23 01:04:40 pverh kernel:  dsl_pool_sync+0xce/0x4e0 [zfs]
Jun 23 01:04:40 pverh kernel:  spa_sync+0x578/0x1030 [zfs]
Jun 23 01:04:40 pverh kernel:  ? spa_txg_history_init_io+0x120/0x130 [zfs]
Jun 23 01:04:40 pverh kernel:  txg_sync_thread+0x207/0x3a0 [zfs]
Jun 23 01:04:40 pverh kernel:  ? __pfx_txg_sync_thread+0x10/0x10 [zfs]
Jun 23 01:04:40 pverh kernel:  ? __pfx_thread_generic_wrapper+0x10/0x10 [spl]
Jun 23 01:04:40 pverh kernel:  thread_generic_wrapper+0x5f/0x70 [spl]
Jun 23 01:04:40 pverh kernel:  kthread+0xf2/0x120
Jun 23 01:04:40 pverh kernel:  ? __pfx_kthread+0x10/0x10
Jun 23 01:04:40 pverh kernel:  ret_from_fork+0x47/0x70
Jun 23 01:04:40 pverh kernel:  ? __pfx_kthread+0x10/0x10
Jun 23 01:04:40 pverh kernel:  ret_from_fork_asm+0x1b/0x30
Jun 23 01:04:40 pverh kernel:  </TASK>
Jun 23 01:06:54 pverh pvescheduler[544250]: INFO: Finished Backup of VM 500 (00:06:48)
Jun 23 01:06:54 pverh pvescheduler[544250]: INFO: Starting Backup of VM 501 (qemu)
Jun 23 01:07:45 pverh pvescheduler[544250]: INFO: Finished Backup of VM 501 (00:00:51)
Jun 23 01:07:45 pverh pvescheduler[544250]: INFO: Starting Backup of VM 502 (qemu)
Jun 23 01:10:58 pverh systemd[1]: Starting apt-daily.service - Daily apt download activities...
Jun 23 01:10:59 pverh systemd[1]: apt-daily.service: Deactivated successfully.
Jun 23 01:10:59 pverh systemd[1]: Finished apt-daily.service - Daily apt download activities.
Jun 23 01:12:01 pverh pvescheduler[544250]: INFO: Finished Backup of VM 502 (00:04:16)
Jun 23 01:12:01 pverh pvescheduler[544250]: INFO: Starting Backup of VM 503 (qemu)
Jun 23 01:14:13 pverh pvescheduler[544250]: INFO: Finished Backup of VM 503 (00:02:12)
Jun 23 01:14:13 pverh pvescheduler[544250]: INFO: Starting Backup of VM 504 (qemu)
Jun 23 01:17:01 pverh CRON[549494]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 01:17:01 pverh CRON[549495]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Jun 23 01:17:01 pverh CRON[549494]: pam_unix(cron:session): session closed for user root
Jun 23 01:17:37 pverh pvescheduler[544250]: INFO: Finished Backup of VM 504 (00:03:24)
Jun 23 01:17:38 pverh pvescheduler[544250]: INFO: Starting Backup of VM 505 (qemu)
Jun 23 01:23:46 pverh pvescheduler[544250]: INFO: Finished Backup of VM 505 (00:06:08)
Jun 23 01:23:46 pverh pvescheduler[544250]: INFO: Starting Backup of VM 510 (qemu)
Jun 23 01:26:19 pverh pvescheduler[544250]: INFO: Finished Backup of VM 510 (00:02:33)
Jun 23 01:26:19 pverh pvescheduler[544250]: INFO: Backup job finished successfully
Jun 23 01:26:20 pverh postfix/pickup[549865]: 12CD5221006: uid=0 from=<root>
Jun 23 01:26:20 pverh postfix/cleanup[552534]: 12CD5221006: message-id=<20240622232620.12CD5221006@pverh.muekno.de>
Jun 23 01:26:20 pverh postfix/qmgr[1351]: 12CD5221006: from=<root@pverh.muekno.de>, size=106887, nrcpt=1 (queue active)
Jun 23 01:26:21 pverh postfix/smtp[552536]: 12CD5221006: to=<mk@muekno.de>, relay=mail.gerdakloos.de[172.16.1.242]:25, delay=1.4, delays=0.08/0.01/0.01/1.3, dsn=5.7.1, status=bounced (host mail.gerdakloos.de[172.16.1.242] said: 554 5.7.1 Spam message rejected (in reply to end of DATA command))
Jun 23 01:26:21 pverh postfix/cleanup[552534]: 693DE22108C: message-id=<20240622232621.693DE22108C@pverh.muekno.de>
Jun 23 01:26:21 pverh postfix/bounce[552537]: 12CD5221006: sender non-delivery notification: 693DE22108C
Jun 23 01:26:21 pverh postfix/qmgr[1351]: 693DE22108C: from=<>, size=2476, nrcpt=1 (queue active)
Jun 23 01:26:21 pverh postfix/qmgr[1351]: 12CD5221006: removed
Jun 23 01:26:21 pverh postfix/pickup[549865]: 7F5AF221006: uid=65534 from=<root>
Jun 23 01:26:21 pverh proxmox-mail-fo[552539]: pverh proxmox-mail-forward[552539]: notified via target `mail-to-root`
Jun 23 01:26:21 pverh postfix/cleanup[552534]: 7F5AF221006: message-id=<20240622232621.693DE22108C@pverh.muekno.de>
Jun 23 01:26:21 pverh postfix/local[552538]: 693DE22108C: to=<root@pverh.muekno.de>, relay=local, delay=0.09, delays=0.02/0.01/0/0.06, dsn=2.0.0, status=sent (delivered to command: /usr/bin/proxmox-mail-forward)
Jun 23 01:26:21 pverh postfix/qmgr[1351]: 693DE22108C: removed
Jun 23 01:26:21 pverh postfix/qmgr[1351]: 7F5AF221006: from=<root@pverh.muekno.de>, size=2665, nrcpt=1 (queue active)
Jun 23 01:26:22 pverh postfix/smtp[552536]: 7F5AF221006: to=<mk@muekno.de>, relay=mail.gerdakloos.de[172.16.1.242]:25, delay=1.2, delays=0.04/0/0.01/1.2, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 882C17F0FD)
Jun 23 01:26:22 pverh postfix/qmgr[1351]: 7F5AF221006: removed
Jun 23 02:17:01 pverh CRON[566329]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 02:17:01 pverh CRON[566330]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Jun 23 02:17:01 pverh CRON[566329]: pam_unix(cron:session): session closed for user root
Jun 23 02:49:58 pverh systemd[1]: Starting man-db.service - Daily man-db regeneration...
Jun 23 02:49:59 pverh systemd[1]: man-db.service: Deactivated successfully.
Jun 23 02:49:59 pverh systemd[1]: Finished man-db.service - Daily man-db regeneration.
Jun 23 03:00:01 pverh pvescheduler[577981]: <root@pam> starting task UPID:pverh:0008D1BE:00C07013:66777391:vzdump::root@pam:
Jun 23 03:00:01 pverh pvescheduler[577982]: INFO: starting new backup job: vzdump 507 508 --storage backup --node pverh --fleecing 0 --mailto mk@muekno.de --notes-template '{{guestname}} Daily keep 2' --quiet 1 --mode snapshot --mailnotification always --prune-backups 'keep-last=2'
Jun 23 03:00:01 pverh pvescheduler[577982]: INFO: Starting Backup of VM 507 (qemu)
Jun 23 03:00:38 pverh pvescheduler[577982]: INFO: Finished Backup of VM 507 (00:00:37)
Jun 23 03:00:38 pverh pvescheduler[577982]: INFO: Starting Backup of VM 508 (qemu)
Jun 23 03:01:23 pverh pvescheduler[577982]: INFO: Finished Backup of VM 508 (00:00:45)
Jun 23 03:01:23 pverh pvescheduler[577982]: INFO: Backup job finished successfully
Jun 23 03:01:23 pverh postfix/pickup[576929]: 404D5220F7D: uid=0 from=<root>
Jun 23 03:01:23 pverh postfix/cleanup[578505]: 404D5220F7D: message-id=<20240623010123.404D5220F7D@pverh.muekno.de>
Jun 23 03:01:23 pverh postfix/qmgr[1351]: 404D5220F7D: from=<root@pverh.muekno.de>, size=14344, nrcpt=1 (queue active)
Jun 23 03:01:24 pverh postfix/smtp[578507]: 404D5220F7D: to=<mk@muekno.de>, relay=mail.gerdakloos.de[172.16.1.242]:25, delay=1.2, delays=0.07/0.02/0.01/1.1, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 650427F4AC)
Jun 23 03:01:24 pverh postfix/qmgr[1351]: 404D5220F7D: removed
Jun 23 03:10:01 pverh CRON[580882]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 03:10:01 pverh CRON[580883]: (root) CMD (test -e /run/systemd/system || SERVICE_MODE=1 /sbin/e2scrub_all -A -r)
Jun 23 03:10:02 pverh CRON[580882]: pam_unix(cron:session): session closed for user root
Jun 23 03:10:58 pverh systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems...
Jun 23 03:10:58 pverh systemd[1]: e2scrub_all.service: Deactivated successfully.
Jun 23 03:10:58 pverh systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems.
Jun 23 03:17:01 pverh CRON[582783]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 03:17:01 pverh CRON[582784]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Jun 23 03:17:01 pverh CRON[582783]: pam_unix(cron:session): session closed for user root
Jun 23 03:30:01 pverh CRON[586304]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 03:30:01 pverh CRON[586305]: (root) CMD (test -e /run/systemd/system || SERVICE_MODE=1 /usr/lib/x86_64-linux-gnu/e2fsprogs/e2scrub_all_cron)
Jun 23 03:30:01 pverh CRON[586304]: pam_unix(cron:session): session closed for user root
Jun 23 04:01:44 pverh kernel: megaraid_sas 0000:01:00.0: 28299 (772423302s/0x0001/FATAL) - Uncorrectable medium error logged for VD 01/1 at 4631296f (on PD 01(e0xfc/s1) at 4631296f)
Jun 23 04:17:01 pverh CRON[599163]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Jun 23 04:17:01 pverh CRON[599164]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
Jun 23 04:17:01 pverh CRON[599163]: pam_unix(cron:session): session closed for user root
Jun 23 04:46:58 pverh systemd[1]: Starting pve-daily-update.service - Daily PVE download activities...
Jun 23 04:47:01 pverh pveupdate[607267]: <root@pam> starting task UPID:pverh:00094443:00CA3BF5:66778CA5:aptupdate::root@pam:
Jun 23 04:47:04 pverh pveupdate[607299]: update new package list: /var/lib/pve-manager/pkgupdates
Jun 23 04:47:09 pverh pveupdate[607267]: <root@pam> end task UPID:pverh:00094443:00CA3BF5:66778CA5:aptupdate::root@pam: OK
Jun 23 04:47:09 pverh systemd[1]: pve-daily-update.service: Deactivated successfully.
Jun 23 04:47:09 pverh systemd[1]: Finished pve-daily-update.service - Daily PVE download activities.
Jun 23 04:47:09 pverh systemd[1]: pve-daily-update.service: Consumed 8.885s CPU time.
root@pverh:~#

Impossible mail is detected as SPAM and rejected. In the postfix config all internal ip adresses are fully trusted.
Sorry to disturb you and thanks for leading me at the right path

Kind Regards

Rainer
 
Impossible mail is detected as SPAM and rejected. In the postfix config all internal ip adresses are fully trusted.
Sorry to disturb you and thanks for leading me at the right path

Kind Regards

Rainer
No worries, glad you could find the root cause and fix the issue!
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!