Marek,

I think there 4 distinct problems:

> AVC avc:  denied  { execute } for  pid=2974 comm="nfsd" name="dbus-QilPrv8L"
> dev="dm-8" ino=113910401 scontext=system_u:system_r:kernel_t:s0
> tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=0
A reproducer and more data are required.

> AVC avc:  denied  { write } for  pid=58353 comm="sa-update"
> name=".spamassassin" dev="dm-1" ino=524570
> scontext=system_u:system_r:spamd_update_t:s0
> tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=0
> 
> AVC avc:  denied  { write } for  pid=58365 comm="systemctl" name="socket"
> dev="tmpfs" ino=46 scontext=system_u:system_r:spamd_update_t:s0
> tcontext=system_u:object_r:syslogd_var_run_t:s0 tclass=sock_file permissive=0
> 
> AVC avc:  denied  { write } for  pid=58365 comm="systemctl" name="kmsg"
> dev="devtmpfs" ino=10 scontext=system_u:system_r:spamd_update_t:s0
> tcontext=system_u:object_r:kmsg_device_t:s0 tclass=chr_file permissive=0
Creating .spamassassin and logging - does it require a particular configuration change?

> USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295
> subj=system_u:system_r:init_t:s0 msg='avc:  denied  { status } for auid=n/a
> uid=0 gid=0 path="/usr/lib/systemd/system/mimedefang.service" cmdline=""
> function="mac_selinux_filter" scontext=system_u:system_r:spamd_update_t:s0
> tcontext=system_u:object_r:systemd_unit_file_t:s0 tclass=service
> permissive=0 exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=?
> terminal=?'
The unit file requires a private type.

Hello,

I agree there are several distinct problems.

If you could, please, be more specific on what data are required. I have no clue when any of these issues occur and they do not have any visible consequences for me. And I am not able to reproduce at will. It just occurs.

Regarding .spamassasin what configuration change is required?

What do you mean by unit file requires a private type? Unit files are Fedora provided. Some change to it is needed?

Thanks

Marek

Hello,

I did not do any debugs yet, but I switched to permissive mode because of other known bugs affecteing me. Thereafter there are probably some useful findings:

1. regarding mimedefang:

USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  denied  { status } for auid=n/a uid=0 gid=0 path="/usr/lib/systemd/system/mimedefang.service" cmdline="" function="mac_selinux_filter" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:systemd_unit_file_t:s0 tclass=service permissive=1 exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'

USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  denied  { reload } for auid=n/a uid=0 gid=0 path="/usr/lib/systemd/system/mimedefang.service" cmdline="" function="bus_unit_method_start_generic" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:systemd_unit_file_t:s0 tclass=service permissive=1 exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'

There are more blockings when in permissive mode. Probably the process died before when in blocking mode. There sogs are following immediatelly after spamassassin.

2. regarding spamassassin:

AVC avc:  denied  { write } for  pid=15142 comm="sa-update" name=".spamassassin" dev="dm-1" ino=524570 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=1
AVC avc:  denied  { add_name } for  pid=15142 comm="sa-update" name=".sawritetest151425qf2mp" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=1
AVC avc:  denied  { create } for  pid=15142 comm="sa-update" name=".sawritetest151425qf2mp" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=file permissive=1{ read open } for  pid=15142 comm="sa-update" path="/root/.spamassassin/.sawritetest151425qf2mp" dev="dm-1" ino=524491 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=file permissive=1
AVC avc:  denied  { ioctl } for  pid=15142 comm="sa-update" path="/root/.spamassassin/.sawritetest151425qf2mp" dev="dm-1" ino=524491 ioctlcmd=0x5401 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=file permissive=1
AVC avc:  denied  { getattr } for  pid=15142 comm="sa-update" path="/root/.spamassassin/.sawritetest151425qf2mp" dev="dm-1" ino=524491 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=file permissive=1
AVC avc:  denied  { write } for  pid=15142 comm="sa-update" name=".spamassassin" dev="dm-1" ino=524570 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=1
AVC avc:  denied  { remove_name } for  pid=15142 comm="sa-update" name=".sawritetest151425qf2mp" dev="dm-1" ino=524491 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=1
AVC avc:  denied  { unlink } for  pid=15142 comm="sa-update" name=".sawritetest151425qf2mp" dev="dm-1" ino=524491 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=file permissive=1
AVC avc:  denied  { add_name } for  pid=15142 comm="sa-update" name=".sawritetest15142D0KwSS" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:spamc_home_t:s0 tclass=dir permissive=1
AVC avc:  denied  { write } for  pid=15175 comm="systemctl" name="socket" dev="tmpfs" ino=46 scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:object_r:syslogd_var_run_t:s0 tclass=sock_file permissive=1
AVC avc:  denied  { sendto } for  pid=15175 comm="systemctl" path="/run/systemd/journal/socket" scontext=system_u:system_r:spamd_update_t:s0 tcontext=system_u:system_r:kernel_t:s0 tclass=unix_dgram_socket permissive=1

These logs appeared in this sequence on 0:17 probably due to sa-update.timer. When I run sa-update from terminal no AVC denies appear. The logs from systemctl are probably related to the error I see when running from terminal:

deprecated method; prefer $rr->rdstring() at /usr/bin/sa-update line 1460.

The sa-update.timer service is probably trying to log this error message to syslog and to the system journal.

The mimedefang related denies follow immediatelly after those denials.

3. Regarding nfsd no update. It appeared around 19:54 today. I do not know what event is it related to, yet.

Marek

Hello,

moreover I just found out this:

sa-update.cron[15142]: deprecated method; prefer $rr->rdstring() at /usr/bin/sa-update line 1460.

This is in the system journal in the corresponding time.

Marek

I've submitted a Fedora PR to address the spam-update issues:

https://github.com/fedora-selinux/selinux-policy/pull/1762

You can try the following scratchbuild:
Checks -> Artifacts -> rpms.zip

For nfs, additional data are required:
https://fedoraproject.org/wiki/SELinux/Debugging

Full auditing is a good start, maybe kernel traces would be more helpful, depending on what is the triggering condition.

Hello,

after installing rpms you provided all the blockings disappeared including non reported ones, only the nfsd remained, but other one appeared:

This one after boot:

kernel: audit: type=1400 audit(1687900880.916:3): avc:  denied  { audit_control } for  pid=1 comm="systemd" capability=30  scontext=system_u:system_r:init_t:s0 tcontext=system_u:system_r:init_t:s0 tclass=capability permissive=1

This is the know one after client login:

audit[3001]: AVC avc:  denied  { execute } for  pid=3001 comm="nfsd" name="dbus-Qxyb4nxw" dev="dm-8" ino=113910378 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=1

I do not understand how could any nfs client side socket usage trigger execute on a nfs server.

These ones after enabling full auditing:

audit[1594]: AVC avc:  denied  { read } for  pid=1594 comm="auditd" name="4213" dev="proc" ino=56424 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=dir permissive=1
audit[1594]: AVC avc:  denied  { open } for  pid=1594 comm="auditd" path="/proc/4213" dev="proc" ino=56424 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=dir permissive=1
audit[1594]: AVC avc:  denied  { getattr } for  pid=1594 comm="auditd" path="/proc/4213" dev="proc" ino=56424 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=dir permissive=1
audit[1594]: AVC avc:  denied  { search } for  pid=1594 comm="auditd" name="4213" dev="proc" ino=56424 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=dir permissive=1
audit[1594]: AVC avc:  denied  { read } for  pid=1594 comm="auditd" name="sessionid" dev="proc" ino=26397 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=file permissive=1
audit[1594]: AVC avc:  denied  { open } for  pid=1594 comm="auditd" path="/proc/4213/sessionid" dev="proc" ino=26397 scontext=system_u:system_r:auditd_t:s0 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=file permissive=1

It seems enabling full auditing is also blocked somehow, but now in permissive mode, so no impact on debug.

Then unlogged and logged the client:

audit[3002]: AVC avc:  denied  { execute } for  pid=3002 comm="nfsd" name="dbus-T8c5Qq7D" dev="dm-8" ino=113910378 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=1

The output of 
ausearch -i -m avc,user_avc,selinux_err,user_selinux_err -ts today 
gives (stripped since 23:00 - your rpms were installed at 23:10):


----
type=AVC msg=audit(27.06.2023 23:00:13.428:121530) : avc:  denied  { execute } for  pid=3078 comm=nfsd name=dbus-YafWD64i dev="dm-8" ino=113910378 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=1 
----
type=AVC msg=audit(27.06.2023 23:19:59.793:121955) : avc:  denied  { lease } for  pid=343085 comm=rpc.nfsd capability=lease  scontext=system_u:system_r:nfsd_t:s0 tcontext=system_u:system_r:nfsd_t:s0 tclass=capability permissive=1 
----
type=AVC msg=audit(27.06.2023 23:20:00.895:122007) : avc:  denied  { unlink } for  pid=1 comm=systemd name=krb5_97.rcache2 dev="dm-2" ino=1179766 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:dovecot_auth_tmp_t:s0 tclass=file permissive=1 
----
type=AVC msg=audit(27.06.2023 23:27:47.707:404) : avc:  denied  { execute } for  pid=3001 comm=nfsd name=dbus-Qxyb4nxw dev="dm-8" ino=113910378 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=1 
----
type=AVC msg=audit(27.06.2023 23:30:35.820:539) : avc:  denied  { execute } for  pid=3002 comm=nfsd name=dbus-T8c5Qq7D dev="dm-8" ino=113910378 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=1 

The krb5 related log is also new.

I cannot see any improvement on nfsd logging, probably the kernel log you mentioned is needed. Did you mean the tracefs section by kernel debugging? I am not sure.

Thanks

Marek

(In reply to Marek Greško from comment #6)
> I cannot see any improvement on nfsd logging, probably the kernel log you
> mentioned is needed. Did you mean the tracefs section by kernel debugging? I
> am not sure.

Yes, please follow the "Using tracefs" steps for the nfsd "execute" denial, since it looks really weird and seeing the kernel stack trace would be helpful.

Hello,

find the output of tracefs below.

Thanks

Marek



# tracer: nop
#
# entries-in-buffer/entries-written: 2/2   #P:16
#
#                                _-----=> irqs-off/BH-disabled
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
            nfsd-3000    [001] ..... 50200.935363: selinux_audited: requested=0x4000 denied=0x4000 audited=0x4000 result=0 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file
            nfsd-3000    [001] ..... 50200.935378: <stack trace>
 => trace_event_raw_event_selinux_audited
 => avc_audit_post_callback
 => common_lsm_audit
 => slow_avc_audit
 => audit_inode_permission
 => selinux_inode_permission
 => security_inode_permission
 => nfsd_permission
 => nfsd_access
 => nfsd4_proc_compound
 => nfsd_dispatch
 => svc_process_common
 => svc_process
 => nfsd
 => kthread
 => ret_from_fork

Regarding krb5_97.rcache2 blocking above. This is probably related to this:

ls -lZ /var/tmp/krb5_*
-rw-------. 1 root  root  system_u:object_r:krb5_host_rcache_t:s0  16352 jún 28 13:18 /var/tmp/krb5_0.rcache2
-rw-------. 1 squid squid system_u:object_r:krb5_host_rcache_t:s0 475600 jún 28 13:46 /var/tmp/krb5_23.rcache2

ls -lZ /var/tmp/systemd-private-2ef...............164-dovecot.service-a....i/tmp/
celkom 16
-rw-------. 1 dovecot dovecot system_u:object_r:dovecot_auth_tmp_t:s0 14592 jún 28 13:45 krb5_97.rcache2


The dovecots krb5_97.rcache2 is not of type krb5_host_rcache_t. Should it be?

Marek

Hello,

I realized I had not been specific enough in the client side on the nfs blocking problem. The problem arises when user is logging into the KDE plasma session on the nfs client machine.

With the latest selinux-policy-targeted-38.20-1.fc38.noarch package problem with spamassassin are also gone same as with rpms provided by you.

Marek

The krb5_97.rcache2 blocking arises on shutdown when rebooting.

Marek

I just noticed a storm of avc:  denied  { lease } for  pid=3912 comm=rpc.nfsd capability=lease  scontext=system_u:system_r:nfsd_t:s0 tcontext=system_u:system_r:nfsd_t:s0 tclass=capability permissive=0. It seems not to be related to the original nfsd problem, but also to reboots of the server. It arises right before krb5_97.rcache2 problem on shutdown.

Marek

Hello,

latest selinux-policy update did not solve any of the issues, but introduced these ones:

type=AVC msg=audit(18.07.2023 06:41:19.255:171423) : avc:  denied  { ipc_lock } 
for  pid=312572 comm=rndc capability=ipc_lock  scontext=system_u:system_r:ndc_t:
s0 tcontext=system_u:system_r:ndc_t:s0 tclass=capability permissive=0 

type=AVC msg=audit(18.07.2023 06:41:19.255:171424) : avc:  denied  { sqpoll } fo
r  pid=312572 comm=rndc scontext=system_u:system_r:ndc_t:s0 tcontext=system_u:sy
stem_r:ndc_t:s0 tclass=io_uring permissive=0 

type=AVC msg=audit(18.07.2023 06:42:30.013:124) : avc:  denied  { sqpoll } for  pid=1880 comm=named scontext=system_u:system_r:named_t:s0 tcontext=system_u:system_r:named_t:s0 tclass=io_uring permissive=0 

Thanks

Marek

(In reply to Marek Greško from comment #8)
> Hello,
> 
> find the output of tracefs below.
> [...]

Hi, sorry for the late response, I forgot I should follow up here... From the trace it seems that nfsd (the kernel facility) was handling an OP_ACCESS request from the client (AFAIK corresponding to the access(2) syscall) that for some weird reason checked for an execute permission on a socket file, eventually leading to a check if the nfsd (with its adjusted fsuid and fsgid) has the corresponding access to the file. That appears to be a valid behavior of nfsd (AFAICT, even on a regular filesystem access("...", X_OK) on a socket file isn't treated as a special case and goes through the regular DAC and MAC logic as a normal file would), so we need to handle it somehow in the policy.

Since it is a bit of a nonsensical combination, I opened a PR to silence all execute-on-sock_file checks at the SELinux level. They will keep being denied, but it should not affect anything. In fact, there already were some pre-existing execute-on-sock_file dontaudit rules in the policy.

https://github.com/fedora-selinux/selinux-policy/pull/1787

That said, it might be worthwhile to try to identify the program that generates this access check on the client side (perhaps by doing a global strace filtered to just access(2) & faccessat(2) while doing the session login) to understand why it is happening. Maybe it is a symptom of some obscure minor bug somewhere...

The sqpoll issues are a result of libuv update and will be fixed in the next selinux-policy build.

Hello,

that would be probably a problem to find out which client application causes the nfsd problem. So the silence drop would be probably satisfactory solution if it could not cause any harm. I do not observe any. what do you mean by global strace? I only used strace to run some command. I am not aware of any global usage. Regarding sqpoll great news. How about these two:

----
type=AVC msg=audit(27.06.2023 23:19:59.793:121955) : avc:  denied  { lease } for  pid=343085 comm=rpc.nfsd capability=lease  scontext=system_u:system_r:nfsd_t:s0 tcontext=system_u:system_r:nfsd_t:s0 tclass=capability permissive=1 
----
type=AVC msg=audit(27.06.2023 23:20:00.895:122007) : avc:  denied  { unlink } for  pid=1 comm=systemd name=krb5_97.rcache2 dev="dm-2" ino=1179766 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:dovecot_auth_tmp_t:s0 tclass=file permissive=1 
----

???

Thanks

Marek

Just checked systemd journal on the client. Could this be related?

kded5[745545]: print-manager.kded: unable to register service to dbus

Thanks

Marek

So the print-manager.kded is not related to the problem. But the socket is located int the .cache/ibus directory. So it is probably somehow related to ibus.

Marek

Hello,

I confirm that after setting alternatives xinputrc to none, AVC avc:  denied  { execute } for  pid=2974 comm="nfsd" name="dbus-QilPrv8L" dev="dm-8" ino=113910401 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:object_r:cache_home_t:s0 tclass=sock_file permissive=0 messages are gone. So it is definitely related to ibus.

Marek

Hello,

just found out the latest selinux-policy introduced also this blocking:

type=AVC msg=audit(27.07.2023 15:26:21.152:115716) : avc:  denied  { getattr } for  pid=209666 comm=auth path=/home/... dev="dm-8" ino=..... scontext=system_u:system_r:dovecot_auth_t:s0 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=dir permissive=0 

So this is in addition to:

----
type=AVC msg=audit(27.06.2023 23:19:59.793:121955) : avc:  denied  { lease } for  pid=343085 comm=rpc.nfsd capability=lease  scontext=system_u:system_r:nfsd_t:s0 tcontext=system_u:system_r:nfsd_t:s0 tclass=capability permissive=1 
----
type=AVC msg=audit(27.06.2023 23:20:00.895:122007) : avc:  denied  { unlink } for  pid=1 comm=systemd name=krb5_97.rcache2 dev="dm-2" ino=1179766 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:dovecot_auth_tmp_t:s0 tclass=file permissive=1 
----

Thanks

Marek

Hello,

after selinux-policy-targeted-38.22-1 update, these blockings are still present:

type=AVC msg=audit(01.08.2023 07:31:47.826:928) : avc:  denied  { lease } for  pid=4127 comm=rpc.nfsd capability=lease  scontext=system_u:system_r:nfsd_t:s0 tcontext=system_u:system_r:nfsd_t:s0 tclass=capability permissive=0 

type=AVC msg=audit(01.08.2023 07:31:49.035:996) : avc:  denied  { unlink } for  pid=1 comm=systemd name=krb5_97.rcache2 dev="dm-2" ino=1180064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:dovecot_auth_tmp_t:s0 tclass=file permissive=0 

type=AVC msg=audit(01.08.2023 07:31:58.880:1015) : avc:  denied  { ipc_lock } for  pid=4275 comm=rndc capability=ipc_lock  scontext=system_u:system_r:ndc_t:s0 tcontext=system_u:system_r:ndc_t:s0 tclass=capability permissive=0 

and probably also this:

type=AVC msg=audit(27.07.2023 15:26:21.152:115716) : avc:  denied  { getattr } for  pid=209666 comm=auth path=/home/... dev="dm-8" ino=..... scontext=system_u:system_r:dovecot_auth_t:s0 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=dir permissive=0 

... there should be non-kerberos auth request on dovecot to trigger this, it is not so frequent here.

Any debugs needed?

Thanks

Marek

Can you try your applications with the latest selinux-policy and kernel packages updated? I see at least some of the reported problems should be gone.

For the remaining, we need reproducing steps and/or additional debugging data like AVCs with full auditing enabled.
https://fedoraproject.org/wiki/SELinux/Debugging#Enable_full_auditing

Created attachment 1990000 [details]
rpc.nfsd and krb rcache

Hello,

I attached full auditing logs for rpc.nfsd and krb rcache problems. I will be probably able to reproduce the dovecot plain auth problem tomorrow and report next week.

The rpc.nfsd problem trigger condition is reboot of the nfs server when nfs client is using nfs filesystem on server. And also systemctl restart nfs-server is sufficient.

The krb rcache problem trigger is reboot of the server. Also restart of the dovecot service is sufficient.

Thanks

Marek

Created attachment 1990387 [details]
Dovecot auth

Created attachment 1990388 [details]
NFS client

Hello,

I attached also logs of dovecot auth, which triggers when user logs into dovecot using plain auth. and also nfs client logs which triggers when user logs into plasma session on fns client when homedir is on the NFS server.

Thanks

Marek

Hello,

since there is not activity, most of the originally reported issues are solved and I upgraded to Fedora 39 I am going to close the bug and open new one with actual issues.

Thanks

Marek