Built in SMBfunctionality over-polls

Hi,
one cannot read the article you link to without an account. Please provide more details.
 
Could you provide more logs/details? Maybe the connection behavior on the Proxmox VE side can be improved, but if TrueNAS crashes just because of frequent connections, the issue is still on their side IMHO.
 
fiona said:
Could you provide more logs/details? Maybe the connection behavior on the Proxmox VE side can be improved, but if TrueNAS crashes just because of frequent connections, the issue is still on their side IMHO.
Click to expand...
you're right, and that is just a (late night) guess without evidence on my part, but they could not diagnose because there's an entry in the syslog from proxmox connecting every 10 seconds, which causes the systemd journal to roll over frequently. so.. it is compounding issues. especially since there isn't any way of adjusting the polling interval or turning it off without a hacky cron script.
this is what the log was chock full of:
Code: 
Feb 24 22:10:04 StorMax TNAUDIT_SMB[2871584]: @cee:{"TNAUDIT": {"aid": "f14d02e6-eaf1-486e-992c-0a3e427e3ef5>
Feb 24 22:10:14 StorMax TNAUDIT_SMB[2871881]: @cee:{"TNAUDIT": {"aid": "3fd78f9b-cab3-4014-88d6-02b635d3716b>
Feb 24 22:10:24 StorMax TNAUDIT_SMB[2872180]: @cee:{"TNAUDIT": {"aid": "499921f7-af53-4c6f-883f-9ebdba629de4>
Feb 24 22:10:35 StorMax TNAUDIT_SMB[2872482]: @cee:{"TNAUDIT": {"aid": "de34d833-8b1e-4bcb-bd0c-f80ad00b7d3d>
Feb 24 22:10:44 StorMax TNAUDIT_SMB[2872776]: @cee:{"TNAUDIT": {"aid": "7a026236-da0e-497f-a6ac-812e6fc4efce>
Feb 24 22:10:54 StorMax TNAUDIT_SMB[2873087]: @cee:{"TNAUDIT": {"aid": "c554f007-7d60-4efc-a49d-44cbda473f66>
Feb 24 22:11:04 StorMax TNAUDIT_SMB[2873389]: @cee:{"TNAUDIT": {"aid": "6995bc03-8aa6-4f72-8869-9129460caa60>
Feb 24 22:11:15 StorMax TNAUDIT_SMB[2873691]: @cee:{"TNAUDIT": {"aid": "0df4d9b3-b5df-4a4c-a193-ba2d71c5d365>
Feb 24 22:11:24 StorMax TNAUDIT_SMB[2873984]: @cee:{"TNAUDIT": {"aid": "904bce87-ac62-4485-8d90-a0d721e7c313>
Feb 24 22:11:34 StorMax TNAUDIT_SMB[2874281]: @cee:{"TNAUDIT": {"aid": "a92befb3-5e38-4117-b122-3a9324abe328>
Feb 24 22:11:44 StorMax TNAUDIT_SMB[2874573]: @cee:{"TNAUDIT": {"aid": "2dcbd4f9-d28f-47c7-8981-05e76b3a0f80>
Feb 24 22:11:55 StorMax TNAUDIT_SMB[2874887]: @cee:{"TNAUDIT": {"aid": "8e9c3992-2c63-42db-9249-5c91ace2044b>
Feb 24 22:12:04 StorMax TNAUDIT_SMB[2875180]: @cee:{"TNAUDIT": {"aid": "78783975-060b-4c99-b3c6-56019d341bde>
Feb 24 22:12:14 StorMax TNAUDIT_SMB[2875476]: @cee:{"TNAUDIT": {"aid": "28b50990-26ab-4419-8793-9dc0b4fd39ed>
Feb 24 22:12:24 StorMax TNAUDIT_SMB[2875771]: @cee:{"TNAUDIT": {"aid": "1fa15a3a-09f7-4bbd-bb3f-85222a9a4fbd>
Feb 24 22:12:35 StorMax TNAUDIT_SMB[2876075]: @cee:{"TNAUDIT": {"aid": "8b0f4aa7-e26c-4dea-8f5f-85cf8fc50491>
Feb 24 22:12:44 StorMax TNAUDIT_SMB[2876366]: @cee:{"TNAUDIT": {"aid": "9de3f474-6ac6-4da0-bb48-e05f50bc3978>
Feb 24 22:12:54 StorMax TNAUDIT_SMB[2876676]: @cee:{"TNAUDIT": {"aid": "40d38aa7-ee53-44d3-9a7b-1275ba3f1263>
Feb 24 22:13:04 StorMax TNAUDIT_SMB[2876973]: @cee:{"TNAUDIT": {"aid": "730a0f0c-0559-4106-92f6-dedba6fce53f>
Feb 24 22:13:15 StorMax TNAUDIT_SMB[2877275]: @cee:{"TNAUDIT": {"aid": "1d7e009d-44c3-4931-8ad1-fdb496ad82ea>
Feb 24 22:13:24 StorMax TNAUDIT_SMB[2877565]: @cee:{"TNAUDIT": {"aid": "d37c6680-336a-4fb5-872a-bd854ed9b718>
Feb 24 22:13:34 StorMax TNAUDIT_SMB[2877863]: @cee:{"TNAUDIT": {"aid": "5198d88e-410c-4ee6-8907-ff20d492b1b8>
Feb 24 22:13:44 StorMax TNAUDIT_SMB[2878161]: @cee:{"TNAUDIT": {"aid": "07489bd0-2214-477d-b783-b8392e3df226>
just absolutely solid.
as it is, i've moved the one CIFS share on my PVE instance to NFS, which means no spam.
 
Commissar0617 said:
you're right, and that is just a (late night) guess without evidence on my part, but they could not diagnose because there's an entry in the syslog from proxmox connecting every 10 seconds, which causes the systemd journal to roll over frequently.
so.. it is compounding issues. especially since there isn't any way of adjusting the polling interval or turning it off without a hacky cron script.
this is what the log was chock full of:
Code: 
Feb 24 22:10:04 StorMax TNAUDIT_SMB[2871584]: @cee:{"TNAUDIT": {"aid": "f14d02e6-eaf1-486e-992c-0a3e427e3ef5>
Feb 24 22:10:14 StorMax TNAUDIT_SMB[2871881]: @cee:{"TNAUDIT": {"aid": "3fd78f9b-cab3-4014-88d6-02b635d3716b>
Feb 24 22:10:24 StorMax TNAUDIT_SMB[2872180]: @cee:{"TNAUDIT": {"aid": "499921f7-af53-4c6f-883f-9ebdba629de4>
Feb 24 22:10:35 StorMax TNAUDIT_SMB[2872482]: @cee:{"TNAUDIT": {"aid": "de34d833-8b1e-4bcb-bd0c-f80ad00b7d3d>
Feb 24 22:10:44 StorMax TNAUDIT_SMB[2872776]: @cee:{"TNAUDIT": {"aid": "7a026236-da0e-497f-a6ac-812e6fc4efce>
Feb 24 22:10:54 StorMax TNAUDIT_SMB[2873087]: @cee:{"TNAUDIT": {"aid": "c554f007-7d60-4efc-a49d-44cbda473f66>
Feb 24 22:11:04 StorMax TNAUDIT_SMB[2873389]: @cee:{"TNAUDIT": {"aid": "6995bc03-8aa6-4f72-8869-9129460caa60>
Feb 24 22:11:15 StorMax TNAUDIT_SMB[2873691]: @cee:{"TNAUDIT": {"aid": "0df4d9b3-b5df-4a4c-a193-ba2d71c5d365>
Feb 24 22:11:24 StorMax TNAUDIT_SMB[2873984]: @cee:{"TNAUDIT": {"aid": "904bce87-ac62-4485-8d90-a0d721e7c313>
Feb 24 22:11:34 StorMax TNAUDIT_SMB[2874281]: @cee:{"TNAUDIT": {"aid": "a92befb3-5e38-4117-b122-3a9324abe328>
Feb 24 22:11:44 StorMax TNAUDIT_SMB[2874573]: @cee:{"TNAUDIT": {"aid": "2dcbd4f9-d28f-47c7-8981-05e76b3a0f80>
Feb 24 22:11:55 StorMax TNAUDIT_SMB[2874887]: @cee:{"TNAUDIT": {"aid": "8e9c3992-2c63-42db-9249-5c91ace2044b>
Feb 24 22:12:04 StorMax TNAUDIT_SMB[2875180]: @cee:{"TNAUDIT": {"aid": "78783975-060b-4c99-b3c6-56019d341bde>
Feb 24 22:12:14 StorMax TNAUDIT_SMB[2875476]: @cee:{"TNAUDIT": {"aid": "28b50990-26ab-4419-8793-9dc0b4fd39ed>
Feb 24 22:12:24 StorMax TNAUDIT_SMB[2875771]: @cee:{"TNAUDIT": {"aid": "1fa15a3a-09f7-4bbd-bb3f-85222a9a4fbd>
Feb 24 22:12:35 StorMax TNAUDIT_SMB[2876075]: @cee:{"TNAUDIT": {"aid": "8b0f4aa7-e26c-4dea-8f5f-85cf8fc50491>
Feb 24 22:12:44 StorMax TNAUDIT_SMB[2876366]: @cee:{"TNAUDIT": {"aid": "9de3f474-6ac6-4da0-bb48-e05f50bc3978>
Feb 24 22:12:54 StorMax TNAUDIT_SMB[2876676]: @cee:{"TNAUDIT": {"aid": "40d38aa7-ee53-44d3-9a7b-1275ba3f1263>
Feb 24 22:13:04 StorMax TNAUDIT_SMB[2876973]: @cee:{"TNAUDIT": {"aid": "730a0f0c-0559-4106-92f6-dedba6fce53f>
Feb 24 22:13:15 StorMax TNAUDIT_SMB[2877275]: @cee:{"TNAUDIT": {"aid": "1d7e009d-44c3-4931-8ad1-fdb496ad82ea>
Feb 24 22:13:24 StorMax TNAUDIT_SMB[2877565]: @cee:{"TNAUDIT": {"aid": "d37c6680-336a-4fb5-872a-bd854ed9b718>
Feb 24 22:13:34 StorMax TNAUDIT_SMB[2877863]: @cee:{"TNAUDIT": {"aid": "5198d88e-410c-4ee6-8907-ff20d492b1b8>
Feb 24 22:13:44 StorMax TNAUDIT_SMB[2878161]: @cee:{"TNAUDIT": {"aid": "07489bd0-2214-477d-b783-b8392e3df226>
just absolutely solid.
as it is, i've moved the one CIFS share on my PVE instance to NFS, which means no spam.
Click to expand...
You could just filter out those messages when querying the journal? Or maybe you can configure your logging on the target side differently.

The storage status is queried once every 10 seconds. I suppose maybe the connection could be keept alive/cached, feel free to open a feature request on the bug tracker, but it certainly shouldn't be something a server cannot handle.
 
That is the reason why I stopped using (Samba) shares, provided by TrueNAS, on PVE too...
Getting 8.640 entries per day respectively 259.200 entries per month per PVE-node in the audit log of TrueNAS is unpleasant, to say the least...
 
fiona said:
You could just filter out those messages when querying the journal? Or maybe you can configure your logging on the target side differently.

The storage status is queried once every 10 seconds. I suppose maybe the connection could be keept alive/cached, feel free to open a feature request on the bug tracker, but it certainly shouldn't be something a server cannot handle.
Click to expand...
This is also an issue with zfs over iscsi. My Truenas Scale logs are full of authentication messages making it difficult to see any other issues. It seems that both Proxmox and Truenas aren't interested in acknowledging it as an issue. My assumption is that there isn't a setting to configure the poll frequency. It seems as though Truenas isn't interested in letting us filter the messages either. So we have a standoff.

https://forums.truenas.com/t/truenas-scale-filling-smb-audit-logs/6181/31

Pages and pages of this:

Code: 
Mar 19 20:38:43 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 19 20:38:43 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 19 23:09:43 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 19 23:09:43 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 01:38:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 20 01:38:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 04:02:44 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8537 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 04:02:44 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 06:34:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 06:34:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 09:05:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 20 09:05:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 11:35:25 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 11:35:25 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
 
Last edited:
boomshankerx said:
It seems that both Proxmox and Truenas aren't interested in acknowledging it as an issue.
Click to expand...
fiona said:
I suppose maybe the connection could be keept alive/cached, feel free to open a feature request on the bug tracker, but it certainly shouldn't be something a server cannot handle.
Click to expand...
I did acknowledge the issue and suggested what you can do to increase the chances of somebody looking at it (in the future).
 
Yeah just posted here, in my case is a TrueNAS system.

Loads of hassle to register on that bug report page, only for it to say its locked out, looks like TrueNAS dont want bug reports public, so if anyone can copy and paste it all, would be nice.

C

Post in thread 'NAS constantly active after setting up SMB share in Proxmox'

In my case, I noticed the issue from a huge increase in logging activity on the NAS, every request from proxmox is a new authentication and logged. It isnt affecting sleep on the drives however, they have stayed spun down I assume due to ZFS caching taking care of things, so in my case I might just reconfigure the logging, but I do think proxmox polling every 10 seconds on remote storage is really excessive. It seems to only grab storage utilisation so I think once a minute or even a configurable value should be the way forward, it doesnt need to be this frequent.

Update, seems the...
 
Last edited:
fiona said:
Could you provide more logs/details? Maybe the connection behavior on the Proxmox VE side can be improved, but if TrueNAS crashes just because of frequent connections, the issue is still on their side IMHO.
Click to expand...
It sounds like you not using keepalive from the screenshot.

I notice as an example accessing SMB over my lan is no new authentication request, but on PVE is there every 10 seconds (for each instance of PVE).

Please if you can provide some info on how PVE is doing the polling, then I might be able to see if it can be done without a reauth. I have found the mount point, but not the bit thats doing the polling, might be part of the atop process?
 
Last edited:
boomshankerx said:
This is also an issue with zfs over iscsi. My Truenas Scale logs are full of authentication messages making it difficult to see any other issues. It seems that both Proxmox and Truenas aren't interested in acknowledging it as an issue. My assumption is that there isn't a setting to configure the poll frequency. It seems as though Truenas isn't interested in letting us filter the messages either. So we have a standoff.

https://forums.truenas.com/t/truenas-scale-filling-smb-audit-logs/6181/31

Pages and pages of this:

Code: 
Mar 19 20:38:43 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 19 20:38:43 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 19 23:09:43 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 19 23:09:43 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 01:38:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 20 01:38:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 04:02:44 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8537 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 04:02:44 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 06:34:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 06:34:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 09:05:14 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8533 of 11377 items, 6553600 file size, 768 bytes per hash table item), suggesting rotation.
Mar 20 09:05:14 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Mar 20 11:35:25 nas systemd-journald[710]: Data hash table of /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal has a fill level at 75.0 (8534 of 11377 items, 6553600 file size, 767 bytes per hash table item), suggesting rotation.
Mar 20 11:35:25 nas systemd-journald[710]: /var/log/journal/41b709d33bd84b5781e0dbebfc8542bc/system.journal: Journal header limits reached or header out-of-date, rotating.
Click to expand...
I noticed TrueNAS core doesnt have any auth log settings, I manually patched the middleware to disable successful auth logging, which isnt ideal but stops the spam, however I was then surprised to see it only reduced all the i/o by about 20%, so there is something else triggering the writes on boot drive when proxmox has the storage mounted.

Difficult to debug as FreeBSD seems to have inadequate tools to monitor i/o on a per file basis. I cant see anything else being written to in logs. the zfs io stat shows boot pool writing 1.76megabytes every time proxmox polls. Although other data shows it at about 13kB/sec.

Proxmox side could make the 10s a tunable value, or even disable the monitoring altogether, only instead applying a check when the storage is being accessed.
 
Last edited:
Ok I think I have solved it. This post helped me get going.

cheiss

Post in thread '[Question] Need Information on Configuration Parameters for Pvestatd Service'

Hi,

the source code for pvestatd can be found here.

What do you want to configure exactly?
The thing is, there is not a whole lot to configure for pvestatd. It's a basic daemon and not designed to be configurable in any way.

Note this is not a feature parity solution, I will post more after some testing, but the solution basically disables the connection checking on pvestatd schedule (10 secs) on cifs storage, all other storage types behave as normal. There is still some kind of traffic overhead, but all write overheads have stopped on TrueNAS.

Also the code isnt functionally clean, I was going to do it differently before just deciding to always return positive status. Thats why it sets some internal variables for no reason.

When clicking the storage in the GUI it still is able to fetch live information. So the only lost functionality (which is lost anyway by disabling it) is probably the graph displaying storage space over time.

https://bugzilla.proxmox.com/show_bug.cgi?id=6917

Below is the diff for 8.4.14 pve.

Code: 
--- CIFSPlugin.pm.orig.8.4.14   2025-10-11 16:49:38.921000948 +0100
+++ CIFSPlugin.pm.silent.8.4.14 2025-10-11 16:49:38.921000948 +0100
@@ -273,6 +273,16 @@
 
     my $servicename = '//' . $scfg->{server} . '/' . $scfg->{share};
 
+    my $path = $scfg->{path};
+
+    return 1;
+}
+
+sub check_connection_off {
+    my ($class, $storeid, $scfg) = @_;
+
+    my $servicename = '//' . $scfg->{server} . '/' . $scfg->{share};
+
     my $cmd = ['/usr/bin/smbclient', $servicename, '-d', '0'];
 
     if (defined($scfg->{smbversion}) && $scfg->{smbversion} ne 'default') {

Note - it is possible even the lost cifs graphing functionality I mentioned might not even be impacted, I basically just changed a check_connection routine to an emulated routine that always reports success. There is still network traffic meaning PVE is still doing background activity, so its possible the space utilisation still gets updated. So the graphing is an assumption rather than something I tested.
 
Last edited:
You must log in or register to reply here.
Top Bottom