Duplicate subject header on email notifications

[Pyr-000]

With email notifications enabled, the emails being sent appear to have two subject headers, specifically, one encoded subject and one plain ASCII subject, which can cause them to be rejected by the recipient mailserver. (If header validation is being enforced.)

This seems to happen both for test notifications and 'proper' notifications created after a successful backup.

Sample email header returned in a non-delivery report (some information redacted):

Return-Path: <***>
DKIM-Signature: ***
Content-Type: multipart/mixed; boundary="===============2710534224241857684=="
MIME-Version: 1.0
From: ***
To: ***
Date: Sun, 08 Mar 2026 10:45:31 -0000
LocalDate: Sun, 08 Mar 2026 11:45:31 +0100
X-MS-Reactions: disallow
Message-Id: <177296673126.3896.6871463284819149556@***>
Subject: =?utf-8?q?NetPerfect_Backup_Client_success_report_for_=24=7BMACHINE=5FID=7D_test=5Femail_on_repo_default?=
Subject: NetPerfect Backup Client success report for ${MACHINE_ID} test_email on repo default

From a cursory look, the issue appears to be here: ofunctions/mailer/init.py#L165

[deajan]

I remember when writing the mailer code some years ago that for some reason I needed a double subject depending on the mail client.
I need to do a bit research and see how to make a proper fix for this.
Be aware that the monitoring stuff of NPBackup has been fully rewritten to support prometheus, zabbix, healthchecks.io, webhooks and email support.
NPBackup 3.1 alpha version will be released this week for testing purposes. I'll ping you at that time.

[deajan]

@Pyr-000 So I definitly had some encoding issues back then, and read somewhere that adding an UTF-8 and an ASCII subject would be a great idea. Obviously it wasn't.

NPBackup v3.1 beta is out and uses newer email alerting, including the fix for double subject.
Thank you for reporting this.
Please give the beta a test spin (and do a config file backup before trying, since config file version migration is supported but not enough tested ATM).

[Pyr-000]

I've just pulled the v3.1.0-beta2 to do a test run - The new interface, as well as the fact that the backup notifications come with some additional details, are great. Duplicate subject headers no longer show up (I was previously able to set a validation exclusion for the address used to send the notifications since everything runs on a private mailserver, but I assume not everyone will have that option available).

---

I don't want to derail this issue thread too much, but here's some things I've found in this beta, specifically related to the new email notifications - note that I've been migrating/copying the config from the previous stable build.

Of course, it's a beta, I'm unsure if these are already known / WIP.

---

The previous recipient address ended up being split into single characters in the new version, removing any one of them in the gui application, running under windows, throws an error and crashes:

Log snippet:

2026-03-18 16:52:30,034 :: CRITICAL :: GUI Execution error Column.update() got multiple values for argument 'visible'
2026-03-18 16:52:30,034 :: INFO :: Trace:
Traceback (most recent call last):
  File "(...)\npbackup\gui\__main__.py", line 1448, in main_gui
  File "(...)\npbackup\gui\__main__.py", line 1326, in _main_gui
  File "(...)\npbackup\gui\config.py", line 1305, in config_gui
  File "(...)\npbackup\gui\common_gui_logic.py", line 1311, in handle_gui_events
TypeError: Column.update() got multiple values for argument 'visible'
2026-03-18 16:52:30,042 :: INFO :: ExecTime = 0:01:28.515770, finished, state is: critical.

To fix this, the recipient parameters had to be removed from the config file.

---

Additionally, despite the fact that the immediate log output claims the operation was successful, it seems to be generating failure reports:

Unlock output of a housekeeping operation:

Associated email:

Emails created from a (seemingly successful?) backup run:

[deajan]

Thank you for your feedback, highly appreciated at this point of the developpment.
As it seems, are you running 3.1.0-beta1, so basically I assume I did something bad in the build environment.

As for the emails that get converted to first characters only, there is obviously something wrong in my migration code.
I'll have a fresh check for the migration path

As for the email succes status: it's composite: even if backup succeed, any other error / warning in the process (like failure to update/send monitoring/etc) will mark the whole process as failed, whereas the operation status (eg restic_backup_failure) may still be okay.

I'll post beta3 soon.

[Pyr-000]

That makes sense. The notifications do specify "Status: Warning". The only warnings I see in the logs for a housekeeping operation are:

WARNING :: No recipients configured for snapshots success. Not sending metrics via email.
WARNING :: No recipients configured for check success. Not sending metrics via email.
WARNING :: No recipients configured for prune success. Not sending metrics via email.

Is it possible that these were triggering the failure with a warning state in my case?

[deajan]

Yes, NPBackup "full state" is computed by restic backend result and the "worst log level".
The warnings are pretty normal since I prefer knowing if I did not configure something right, but perhaps I should lower the loglevel to info so this won't trigger an actual bad state in the email subject.

[deajan]

Could you perhaps have a look at beta 6 that is just out ?

[deajan]

Or yet better, v3.1.0-beta7 ?

[Pyr-000]

I've re-tested on beta7, here's what I found:

• When migrating the config, the single recipient email now shows up as one item
• A missing 'success' recipient in the email configuration no longer yields error notifications, looking good!

---

• Removing a recipient email address (either migrated or newly configured in beta7) in the GUI still yields "TypeError: Column.update() got multiple values for argument 'visible'". Updated stack trace with the new lines:

2026-04-01 13:10:58,053 :: CRITICAL :: GUI Execution error Column.update() got multiple values for argument 'visible'
2026-04-01 13:10:58,053 :: INFO :: Trace:
Traceback (most recent call last):
  File "(...)\npbackup\gui\__main__.py", line 1479, in main_gui
  File "(...)\npbackup\gui\__main__.py", line 1357, in _main_gui
  File "(...)\npbackup\gui\config.py", line 1190, in config_gui
  File "(...)\npbackup\gui\common_gui_logic.py", line 1381, in handle_gui_events
TypeError: Column.update() got multiple values for argument 'visible'
2026-04-01 13:10:58,064 :: INFO :: ExecTime = 0:00:14.570716, finished, state is: critical.

---

• I'm still getting a failure report for an otherwise successful backup operation, with logs citing a parsing issue:
  "ERROR :: Backup operation did not return valid parseable data"

[Notification message]

Operation: backup
Repo: (...)
Status: Error
Date: 2026-04-01 12:08:28 UTC
Execution time: 1183.05 seconds
Operation backup status: Success
Detailed backup metrics:
{
    "restic_backup_failure": 0,
    "restic_files": {},
    "restic_dirs": {},
    "npbackup_backup_sub_min_size": 0,
    "npbackup_storage_heuristics_too_low": 0,
    "npbackup_storage_heuristics_too_high": 0,
    "npbackup_storage_heuristics_too_many_modified_files": 0,
    "npbackup_exec_state": 2,
    "npbackup_exec_time": 1183.052674
}
Labels:
instance: 
group: 
backup_job: (...)
tenant_name: 
optional_tag: 
npversion: npbackup3.1.0-beta7-gui
audience: public
os: windows
arch: x64
repo_name: (...)
action: backup
Generated by NetPerfect Backup Client 3.1.0-beta7

[Log output for operation]

2026-04-01 13:48:45,271 :: INFO :: Running backup of files and folders: (...) to repo (...)
2026-04-01 13:48:45,271 :: INFO :: Using VSS snapshot to backup
2026-04-01 14:07:03,258 :: INFO :: Backend finished with success
2026-04-01 14:07:03,258 :: INFO :: Restic output:
using parent snapshot fb38673c
creating VSS snapshot for (...)
successfully created snapshot for (...)
creating VSS snapshot for (...)
successfully created snapshot for (...)
creating VSS snapshot for (...)
successfully created snapshot for (...)
Files:         256 new,  2279 changed, 2447589 unmodified
Dirs:           85 new,   255 changed, 225160 unmodified
Added to the repository: 539.163 MiB (513.386 MiB stored)
processed 2450124 files, 10.811 TiB in 18:14
snapshot 7a6b0868 saved
2026-04-01 14:07:03,259 :: INFO :: Processed 10.8 TiB of data
2026-04-01 14:07:03,259 :: INFO :: Operation finished with success
2026-04-01 14:07:03,260 :: INFO :: Running housekeeping after backup
2026-04-01 14:07:03,260 :: INFO :: Running housekeeping
2026-04-01 14:07:03,260 :: INFO :: Unlocking repo default
2026-04-01 14:07:03,801 :: INFO :: Repo successfully unlocked
2026-04-01 14:07:03,801 :: INFO :: Runner took 0.541232 seconds for unlock
2026-04-01 14:07:03,801 :: INFO :: No recipients configured for unlock success. Not sending metrics via email.
2026-04-01 14:07:03,802 :: INFO :: Running metadata consistency check of repository default
2026-04-01 14:07:39,977 :: INFO :: Repo checked successfully
2026-04-01 14:07:39,977 :: INFO :: Runner took 36.175353 seconds for check
2026-04-01 14:07:39,977 :: INFO :: No recipients configured for check success. Not sending metrics via email.
2026-04-01 14:07:39,978 :: INFO :: Forgetting snapshots using retention policy: {'keep-last': 3, 'keep-hourly': 1, 'keep-daily': 1, 'keep-weekly': 4, 'keep-monthly': 3, 'keep-yearly': 3}
2026-04-01 14:07:40,766 :: INFO :: Successfully applied retention policy
2026-04-01 14:07:40,767 :: INFO :: Runner took 0.789288 seconds for forget
2026-04-01 14:07:40,767 :: INFO :: No recipients configured for forget success. Not sending metrics via email.
2026-04-01 14:07:40,767 :: INFO :: Pruning snapshots for repo default
2026-04-01 14:08:28,321 :: INFO :: Successfully pruned repository:
loading indexes...
loading all snapshots...
finding data that is still in use for 8 snapshots
[0:11] 100.00%  8 / 8 snapshots
searching used packs...
collecting packs for deletion and repacking
[0:14] 100.00%  588388 / 588388 packs processed
used:            8990388 blobs / 9.315 TiB
unused:           190291 blobs / 234.716 GiB
total:           9180679 blobs / 9.544 TiB
unused size: 2.40% of total size
to repack:             0 blobs / 0 B
this removes:          0 blobs / 0 B
to delete:             0 blobs / 0 B
total prune:           0 blobs / 0 B
remaining:       9180679 blobs / 9.544 TiB
unused size after prune: 234.716 GiB (2.40% of remaining size)
totally used packs:     557898
partly used packs:       30490
unused packs:                0
to keep:          588388 packs
to repack:             0 packs
to delete:             0 packs
done
2026-04-01 14:08:28,321 :: INFO :: Runner took 47.554034 seconds for prune
2026-04-01 14:08:28,322 :: INFO :: No recipients configured for prune success. Not sending metrics via email.
2026-04-01 14:08:28,322 :: INFO :: Runner took 85.062127 seconds for housekeeping
2026-04-01 14:08:28,322 :: INFO :: No recipients configured for housekeeping success. Not sending metrics via email.
2026-04-01 14:08:28,322 :: INFO :: Runner took 1183.052674 seconds for backup
2026-04-01 14:08:28,323 :: ERROR :: Backup operation did not return valid parseable data
2026-04-01 14:08:28,323 :: INFO :: Sending metrics via email to (...).
2026-04-01 14:08:30,937 :: INFO :: Metrics sent via email.
2026-04-01 14:08:40,302 :: INFO :: Listing snapshots of repo default
2026-04-01 14:08:40,879 :: INFO :: Snapshots listed successfully
2026-04-01 14:08:40,879 :: INFO :: Runner took 0.577476 seconds for snapshots
2026-04-01 14:08:40,880 :: INFO :: No recipients configured for snapshots success. Not sending metrics via email.

---

• I can't get the button to send a test email notification to work, pressing it seems to crash with the following:

2026-04-01 13:09:43,190 :: CRITICAL :: GUI Execution error 'npbackup_exec_time'
2026-04-01 13:09:43,190 :: INFO :: Trace:
Traceback (most recent call last):
  File "(...)\npbackup\gui\__main__.py", line 1479, in main_gui
  File "(...)\npbackup\gui\__main__.py", line 1357, in _main_gui
  File "(...)\npbackup\gui\config.py", line 1190, in config_gui
  File "(...)\npbackup\gui\common_gui_logic.py", line 1603, in handle_gui_events
  File "(...)\npbackup\core\monitoring\email.py", line 148, in send_metrics
  File "(...)\npbackup\core\monitoring\email.py", line 255, in _send_email
KeyError: 'npbackup_exec_time'
2026-04-01 13:09:43,198 :: INFO :: ExecTime = 0:01:02.803569, finished, state is: critical.

[deajan]

Thank you for the feedback.
Had an annoying bug with the UI framework, and still had a "work in progress" marker for the email test sending structure which I didn't complete after rewriting the monitoring parts of NPBackup.
Both fixed.

As for the ERROR :: Backup operation did not return valid parseable data, it looks like the housekeeping operation that is run as part of the backup operation superseedes backup results which obviously will make the backup result parser fail.
I'll have a deeper look this afternoon.

[deajan]

After a deeper look, it seems that this error was already present in v3.0.x series.
Since housekeeping is run randomly (depending on your settings), that error never triggered my tests.
Thank you for reporting. Fix is in master. I'll build beta 8 shortly.