samba - Feb 2023 - log flood: smbd_calculate_access_mask_fsp: Access denied

Hello!

I thought about giving current samba a try on one of our larger
production servers, and upgraded from debian "stable" 4.13 to
current 4.17.5.  And immediately the log, which was almost empty
before, started flooding by the following messages:

[2023/02/07 22:33:19.542320,  0]
../../source3/smbd/open.c:3392(smbd_calculate_access_mask_fsp)
   smbd_calculate_access_mask_fsp: Access denied on file <filename>.ico:
rejected by share access mask[0x001F00A9] orig[0x00120189] mapped[0x00120189]
reject[0x00000100]

This is logged about 100 times per minute, sometimes more.

There are 2 issues here.

1. There's absolutely zero information about the client which is causing
this. The above is the whole message, there's no other messages, just this
one. Since there are about 600 connections currently active, it's impossible
to know which client is casing this. Maybe I'll try to use log.smbd.%I to
find out, but really, samba should have some client identity here, or most
messages are useless.

2. This is logged as an error. But it is a genuine error, so to say, - I can
only *guess* this is either some antivirus software or maybe some on-access
picture preview genetation software, or something like that (since most of
the time, it is the .ico files which are being rejected access). I'll find
out (hopefully) what is causing this.

The whole share is read-only, there's nothing in there to write, writing is
disabled. 0x100 is SEC_FILE_WRITE_ATTRIBUTE. And sure thing, it is correctly
denied access.

But heck. This is sort of wrong to log this issue as error. And *this* is the
second issue.  At max, it should be a warning, but I'd use notice or even
debug log level there, because it is, basically normal situation. But I
can't
turn this logging off, unfortunately.

I'm lowering this message in source3/smbd/open.c and rebuilding samba
locally.
The same change should be done in debian too, it looks like. Unless I
misunderstand
something fundamental here...

Thanks,

/mjt

On Tue, Feb 07, 2023 at 10:50:58PM +0300, Michael Tokarev via samba
wrote:
>Hello!
>
>I thought about giving current samba a try on one of our larger
>production servers, and upgraded from debian "stable" 4.13 to
>current 4.17.5.  And immediately the log, which was almost empty
>before, started flooding by the following messages:
>
>[2023/02/07 22:33:19.542320,  0]
../../source3/smbd/open.c:3392(smbd_calculate_access_mask_fsp)
>  smbd_calculate_access_mask_fsp: Access denied on file 
><filename>.ico: rejected by share access mask[0x001F00A9] 
>orig[0x00120189] mapped[0x00120189] reject[0x00000100]
>
>This is logged about 100 times per minute, sometimes more.
>
>There are 2 issues here.
>
>1. There's absolutely zero information about the client which is causing
>this. The above is the whole message, there's no other messages, just
this
>one. Since there are about 600 connections currently active, it's
impossible
>to know which client is casing this. Maybe I'll try to use log.smbd.%I
to
>find out, but really, samba should have some client identity here, or most
>messages are useless.
>
>2. This is logged as an error. But it is a genuine error, so to say, - I can
>only *guess* this is either some antivirus software or maybe some on-access
>picture preview genetation software, or something like that (since most of
>the time, it is the .ico files which are being rejected access). I'll
find
>out (hopefully) what is causing this.
>
>The whole share is read-only, there's nothing in there to write, writing
is
>disabled. 0x100 is SEC_FILE_WRITE_ATTRIBUTE. And sure thing, it is correctly
>denied access.
>
>But heck. This is sort of wrong to log this issue as error. And *this* is
the
>second issue.  At max, it should be a warning, but I'd use notice or
even
>debug log level there, because it is, basically normal situation. But I
can't
>turn this logging off, unfortunately.
>
>I'm lowering this message in source3/smbd/open.c and rebuilding samba
locally.
>The same change should be done in debian too, it looks like. Unless I
misunderstand
>something fundamental here...
Please log a bug on this. It should be a debug level 5
at the lowest.

Thanks !

On 2/7/23 20:50, Michael Tokarev via samba wrote:
> 1. There's absolutely zero information about the client which is
causing
> this. The above is the whole message, there's no other messages, just
this
> one. Since there are about 600 connections currently active, it's 
> impossible
> to know which client is casing this. Maybe I'll try to use log.smbd.%I
to
> find out, but really, samba should have some client identity here, or most
> messages are useless.
smb.conf: debug pid = yes

# smbstatus -p

-slow

-- 
Ralph Boehme, Samba Team                 https://samba.org/
SerNet Samba Team Lead      https://sernet.de/en/team-samba

-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 840 bytes
Desc: OpenPGP digital signature
URL:
<http://lists.samba.org/pipermail/samba/attachments/20230207/ed7d45dd/OpenPGP_signature.sig>