cron is failing to run for selinux context, but everything looks fine

[stan]

Recently, I've noticed that some jobs that are started by dwatch,
aren't starting.  If I start them manually, they start fine.  dwatch is
in cron.d, and should be running every 5 minutes, but no cron jobs are
running.  I see the following in journalctl,
Jul 28 10:07:08 localhost.localdomain crond[1192]: (root) FAILED (loading cron table)
Jul 28 10:07:08 localhost.localdomain crond[1192]: ((null)) No SELinux security context (/etc/crontab)
but when I check the security context, it seems fine to me.
-rw-r--r--. 1 0 0 system_u:object_r:system_cron_spool_t:s0  451 Jul 24  2019 /etc/crontab

Before I open a bugzilla, I wanted to check if anyone has an
explanation for this, and a fix.

[Samuel Sieb]

On 7/28/20 10:35 AM, stan via users wrote:
> Recently, I've noticed that some jobs that are started by dwatch,
> aren't starting.  If I start them manually, they start fine.  dwatch is
> in cron.d, and should be running every 5 minutes, but no cron jobs are
> running.  I see the following in journalctl,

Are any other cron jobs running?
> Jul 28 10:07:08 localhost.localdomain crond[1192]: (root) FAILED (loading cron table)
> Jul 28 10:07:08 localhost.localdomain crond[1192]: ((null)) No SELinux security context (/etc/crontab)
> but when I check the security context, it seems fine to me.
> -rw-r--r--. 1 0 0 system_u:object_r:system_cron_spool_t:s0  451 Jul 24  2019 /etc/crontab

I don't see how this is related to something in /etc/cron.d

[Samuel Sieb]

On 7/28/20 10:35 AM, stan via users wrote:
> Recently, I've noticed that some jobs that are started by dwatch,
> aren't starting.  If I start them manually, they start fine.  dwatch is

What is "dwatch".  I can't find any reference to it (other than BSD).

[stan]

On Tue, 28 Jul 2020 11:53:15 -0700
Samuel Sieb  wrote:
> On 7/28/20 10:35 AM, stan via users wrote:
> > Recently, I've noticed that some jobs that are started by dwatch,
> > aren't starting.  If I start them manually, they start fine.
> > dwatch is
>
> What is "dwatch".  I can't find any reference to it (other than BSD).

It's a shortcut for daemon watch.  It checks whether a user daemon is
running, and if it isn't, starts it according to an invocation in a
conf file.  I use it to run my entropy gathering daemons.  None of the
cron jobs run.  I only looked in /etc because the message said that
/etc/crontab had the incorrect selinux context.
> No SELinux security context (/etc/crontab)

Everything has been running fine until recently, so there was an update
that caused the issue.  The main selinux policy updated on 6/12/2020,
but container_selinux has been updated several times.  That should have
no effect here, since I don't run any containers, but ...

I'll open a bugzilla.

[stan]

On Tue, 28 Jul 2020 10:35:54 -0700
stan via users  wrote:
> Before I open a bugzilla, I wanted to check if anyone has an
> explanation for this, and a fix.

Opened a bugzilla,
https://bugzilla.redhat.com/show_bug.cgi?id=1861505

[Ed Greshko]

On 2020-07-29 03:23, stan via users wrote:
> On Tue, 28 Jul 2020 10:35:54 -0700
> stan via users  wrote:
> > Before I open a bugzilla, I wanted to check if anyone has an
> > explanation for this, and a fix.
>
> Opened a bugzilla,
> https://bugzilla.redhat.com/show_bug.cgi?id=1861505

Could you clarify things a bit?

I still don't know what "daemon watch" is.  What package/rpm supplies this?

Also, in the BZ you say "No cron jobs run" but in the thread it sounded to me as if it was only
cron jobs associated with "dwatch".  So, which is it?

Then, just as a troubleshoot, have you tried running the system with setenforce 0?

[stan]

On Wed, 29 Jul 2020 05:38:29 +0800
Ed Greshko  wrote:
> On 2020-07-29 03:23, stan via users wrote:
> > On Tue, 28 Jul 2020 10:35:54 -0700
> > stan via users  wrote:
> > > Before I open a bugzilla, I wanted to check if anyone has an
> > > explanation for this, and a fix.
> >
> > Opened a bugzilla,
> > https://bugzilla.redhat.com/show_bug.cgi?id=1861505
>
> Could you clarify things a bit?

I'll try.
> I still don't know what "daemon watch" is.  What package/rpm supplies
> this?

Name        : dwatch
Version     : 0.1.1
Release     : 18.fc31
Architecture: x86_64
Install Date: Mon 10 Jun 2019 08:19:26 PM MST
Group       : Applications/System
Size        : 43883
License     : GPLv2+
Signature   : (none)
Source RPM  : dwatch-0.1.1-18.fc31.src.rpm
Build Date  : Mon 10 Jun 2019 08:18:22 PM MST
Build Host  : localhost
URL         : http://siag.nu/dwatch/
Summary     : A program that watches over other programs
Description :
Dwatch (Daemon Watch) is a program that watches over other programs and
performs actions based on conditions specified in a configuration file.
See dwatch.conf for an example of what the file might look like.

Dwatch is meant to be run from cron at regular intervals.
> Also, in the BZ you say "No cron jobs run" but in the thread it
> sounded to me as if it was only cron jobs associated with "dwatch".
> So, which is it?

As far as I can tell, no cron jobs run.  I noticed dwatch not running
because the entropy gathering daemons weren't running.  The others run,
but their output isn't as noticeable to me.
> Then, just as a troubleshoot, have you tried running the system with
> setenforce 0?

I haven't, and that is a good suggestion.  I'll reboot with
setenforce=0 on the kernel boot line.

[Ed Greshko]

On 2020-07-29 20:29, stan via users wrote:
> On Wed, 29 Jul 2020 05:38:29 +0800
> Ed Greshko  wrote:
> > On 2020-07-29 03:23, stan via users wrote:
> > > On Tue, 28 Jul 2020 10:35:54 -0700
> > > stan via users  wrote:
> > > > Before I open a bugzilla, I wanted to check if anyone has an
> > > > explanation for this, and a fix.
> > >
> > > Opened a bugzilla,
> > > https://bugzilla.redhat.com/show_bug.cgi?id=1861505
> >
> > Could you clarify things a bit?
>
> I'll try.
> > I still don't know what "daemon watch" is.  What package/rpm supplies
> > this?
>
> Name        : dwatch
> Version     : 0.1.1
> Release     : 18.fc31
> Architecture: x86_64
> Install Date: Mon 10 Jun 2019 08:19:26 PM MST
> Group       : Applications/System
> Size        : 43883
> License     : GPLv2+
> Signature   : (none)
> Source RPM  : dwatch-0.1.1-18.fc31.src.rpm
> Build Date  : Mon 10 Jun 2019 08:18:22 PM MST
> Build Host  : localhost
> URL         : http://siag.nu/dwatch/
> Summary     : A program that watches over other programs
> Description :
> Dwatch (Daemon Watch) is a program that watches over other programs and
> performs actions based on conditions specified in a configuration file.
> See dwatch.conf for an example of what the file might look like.
>
> Dwatch is meant to be run from cron at regular intervals.

So, dwatch is not part of Fedora.

On an F31 system...

[egreshko@f31k ~]$ dnf info dwatch
Last metadata expiration check: 0:00:33 ago on Wed 29 Jul 2020 08:49:46 PM CST.
Error: No matching Packages to list

On an F32 system...

[egreshko@meimei ~]$ dnf info dwatch
Last metadata expiration check: 4:12:49 ago on Wed 29 Jul 2020 04:35:59 PM CST.
Error: No matching Packages to list

So, where did you acquire it?
> > Also, in the BZ you say "No cron jobs run" but in the thread it
> > sounded to me as if it was only cron jobs associated with "dwatch".
> > So, which is it?
>
> As far as I can tell, no cron jobs run.  I noticed dwatch not running
> because the entropy gathering daemons weren't running.  The others run,
> but their output isn't as noticeable to me.

Well, you should easily be able to tell if the hourly cron job runs...

journalctl -b 0 | grep hourly

should return a bunch of stuff like...

Jul 29 20:01:01 meimei.greshko.com CROND[29642]: (root) CMD (run-parts /etc/cron.hourly)
Jul 29 20:01:01 meimei.greshko.com run-parts[29645]: (/etc/cron.hourly) starting 0anacron
Jul 29 20:01:01 meimei.greshko.com run-parts[29651]: (/etc/cron.hourly) finished 0anacron
> > Then, just as a troubleshoot, have you tried running the system with
> > setenforce 0?
>
> I haven't, and that is a good suggestion.  I'll reboot with
> setenforce=0 on the kernel boot line.

[stan]

On Wed, 29 Jul 2020 20:54:38 +0800
Ed Greshko  wrote:
> So, dwatch is not part of Fedora.

Not now.
> On an F31 system...
>
> [egreshko@f31k ~]$ dnf info dwatch
> Last metadata expiration check: 0:00:33 ago on Wed 29 Jul 2020
> 08:49:46 PM CST. Error: No matching Packages to list
>
> On an F32 system...
>
> [egreshko@meimei ~]$ dnf info dwatch
> Last metadata expiration check: 4:12:49 ago on Wed 29 Jul 2020
> 04:35:59 PM CST. Error: No matching Packages to list
>
> So, where did you acquire it?

https://koji.fedoraproject.org/koji/packageinfo?packageID=4453
> Well, you should easily be able to tell if the hourly cron job runs...
>
> journalctl -b 0 | grep hourly
>
> should return a bunch of stuff like...
>
> Jul 29 20:01:01 meimei.greshko.com CROND[29642]: (root) CMD
> (run-parts /etc/cron.hourly) Jul 29 20:01:01 meimei.greshko.com
> run-parts[29645]: (/etc/cron.hourly) starting 0anacron Jul 29
> 20:01:01 meimei.greshko.com run-parts[29651]: (/etc/cron.hourly)
> finished 0anacron

Returns nothing.
> > > Then, just as a troubleshoot, have you tried running the system
> > > with setenforce 0?
> >
> > I haven't, and that is a good suggestion.  I'll reboot with
> > setenforce=0 on the kernel boot line.

I updated the bugzilla with the new information, but putting
enforcing=0 on the kernel boot line results in a working system again.
The messages change to allowing crond to run even though it has a NULL
security context because it is in security mode. I tried older kernels
from when it worked before, they also fail now, so not a kernel
problem.  Somehow, the user that runs crond lost its selinux security
context.

e.g.

crond[5954]: (*system*) NULL security context for user, but SELinux in permissive mode, continuing ()

and

crond[1169]: ((null)) No security context but SELinux in permissive mode, continuing (/etc/cron.d/dwatch)

[Ed Greshko]

On 2020-07-29 23:25, stan via users wrote:
> On Wed, 29 Jul 2020 20:54:38 +0800
> Ed Greshko  wrote:
> > So, dwatch is not part of Fedora.
>
> Not now.

Right.  It was retired around F24 and you've rebuilt it locally to make a F31 package.
> > Well, you should easily be able to tell if the hourly cron job runs...
> >
> > journalctl -b 0 | grep hourly
> >
> > should return a bunch of stuff like...
> >
> > Jul 29 20:01:01 meimei.greshko.com CROND[29642]: (root) CMD
> > (run-parts /etc/cron.hourly) Jul 29 20:01:01 meimei.greshko.com
> > run-parts[29645]: (/etc/cron.hourly) starting 0anacron Jul 29
> > 20:01:01 meimei.greshko.com run-parts[29651]: (/etc/cron.hourly)
> > finished 0anacron
>
> Returns nothing.
> > > > Then, just as a troubleshoot, have you tried running the system
> > > > with setenforce 0?
> > >
> > > I haven't, and that is a good suggestion.  I'll reboot with
> > > setenforce=0 on the kernel boot line.
>
> I updated the bugzilla with the new information, but putting
> enforcing=0 on the kernel boot line results in a working system again.
> The messages change to allowing crond to run even though it has a NULL
> security context because it is in security mode. I tried older kernels
> from when it worked before, they also fail now, so not a kernel
> problem.  Somehow, the user that runs crond lost its selinux security
> context.
>
> e.g.
>
> crond[5954]: (*system*) NULL security context for user, but SELinux in permissive mode, continuing ()
>
> and
>
> crond[1169]: ((null)) No security context but SELinux in permissive mode, continuing (/etc/cron.d/dwatch)

In the above, is PID 5954 the crond process?  If you run ps with the -Z option do you get something
like

[egreshko@f31k ~]$ ps p 821 -Z
LABEL                               PID TTY      STAT   TIME COMMAND
system_u:system_r:crond_t:s0-s0:c0.c1023 821 ?   Ss     0:00 /usr/sbin/crond -n

Do you happen to have another F31 system which doesn't have dwatch installed?  All of my F31 systems
are running cron jobs just fine and they are all fully updated.

Jul 30 02:01:01 f31k.greshko.com CROND[2417]: (root) CMD (run-parts /etc/cron.hourly)
Jul 30 02:01:01 f31k.greshko.com run-parts[2420]: (/etc/cron.hourly) starting 0anacron
Jul 30 02:01:01 f31k.greshko.com run-parts[2428]: (/etc/cron.hourly) finished 0anacron

Do you think having dwatch installed may be significant?  And, did you mention that in the bugzilla?
It sounds to me like an important detail.

[stan]

On Thu, 30 Jul 2020 02:47:22 +0800
Ed Greshko  wrote:
> In the above, is PID 5954 the crond process?  If you run ps with the
> -Z option do you get something like
>
> [egreshko@f31k ~]$ ps p 821 -Z
> LABEL                               PID TTY      STAT   TIME COMMAND
> system_u:system_r:crond_t:s0-s0:c0.c1023 821 ?   Ss     0:00
> /usr/sbin/crond -n

LABEL                               PID TTY      STAT   TIME COMMAND
system_u:system_r:crond_t:s0-s0:c0.c1023 3167 ?  Ss     0:00
/usr/sbin/crond -n
> Do you happen to have another F31 system which doesn't have dwatch
> installed?  All of my F31 systems are running cron jobs just fine and
> they are all fully updated.

No, but I removed dwatch from /etc/cron.d, and the behavior persists.
I think I have something installed that you do not, though it is good
to see that your systems are running fine.
> Jul 30 02:01:01 f31k.greshko.com CROND[2417]: (root) CMD (run-parts
> /etc/cron.hourly) Jul 30 02:01:01 f31k.greshko.com run-parts[2420]:
> (/etc/cron.hourly) starting 0anacron Jul 30 02:01:01 f31k.greshko.com
> run-parts[2428]: (/etc/cron.hourly) finished 0anacron

If I boot with enforcing=0 as a kernel option, I see this happen.
> Do you think having dwatch installed may be significant?  And, did
> you mention that in the bugzilla? It sounds to me like an important
> detail.

No, I don't think dwatch is significant, it is just the job I noticed.
It was running fine on July 25, I updated, and on reboot on July 26, I
see this behavior.

I think this is the problem:
crond[5954]: (*system*) NULL security context for user, but SELinux in
permissive mode, continuing ()

crond only starts and runs properly when selinux is disabled.  It
hasn't been updated since last year, selinux was last updated in June,
and the container-selinux package doesn't seem to have anything to do
with this even though it was updated on July 25.

With enforcing 0, restart crond, no dwatch

Jul 29 12:25:03 localhost.localdomain crond[12307]: (CRON) INFO
(@reboot jobs will be run at computer's startup.) Jul 29 12:25:03
localhost.localdomain crond[12307]: (CRON) INFO (running with inotify
support) Jul 29 12:25:03 localhost.localdomain crond[12307]: ((null))
No security context but SELinux in permissive mode, continuing
(/etc/cron.d/0hourly) Jul 29 12:25:03 localhost.localdomain
crond[12307]: ((null)) No security context but SELinux in permissive
mode, continuing (/etc/cron.d/atop) Jul 29 12:25:03
localhost.localdomain crond[12307]: ((null)) No security context but
SELinux in permissive mode, continuing (/etc/cron.d/moodle) Jul 29
12:25:03 localhost.localdomain crond[12307]: ((null)) No security
context but SELinux in permissive mode, continuing
(/etc/cron.d/mailman) Jul 29 12:25:03 localhost.localdomain
crond[12307]: ((null)) No security context but SELinux in permissive
mode, continuing (/etc/cron.d/rear) Jul 29 12:25:03
localhost.localdomain crond[12307]: ((null)) No security context but
SELinux in permissive mode, continuing (/etc/crontab) Jul 29 12:25:03
localhost.localdomain crond[12307]: (CRON) INFO (RANDOM_DELAY will be
scaled with factor 30% if used.) Jul 29 12:25:03 localhost.localdomain
crond[12307]: (CRON) STARTUP (1.5.4) Jul 29 12:25:03
localhost.localdomain systemd[1]: Started Command Scheduler. Jul 29
12:25:03 localhost.localdomain systemd[1]: Stopped Command Scheduler.
Jul 29 12:25:03 localhost.localdomain systemd[1]: crond.service:
Succeeded. Jul 29 12:25:03 localhost.localdomain crond[11695]: (CRON)
INFO (Shutting down) Jul 29 12:25:03 localhost.localdomain systemd[1]:
Stopping Command Scheduler...

With enforcing 1, restart crond, no dwatch

Jul 29 12:25:47 localhost.localdomain crond[12324]: (CRON) INFO
(@reboot jobs will be run at computer's startup.) Jul 29 12:25:47
localhost.localdomain crond[12324]: (CRON) INFO (running with inotify
support) Jul 29 12:25:47 localhost.localdomain crond[12324]: (root)
FAILED (loading cron table) Jul 29 12:25:47 localhost.localdomain
crond[12324]: ((null)) No SELinux security context
(/etc/cron.d/0hourly) Jul 29 12:25:47 localhost.localdomain
crond[12324]: (root) FAILED (loading cron table) Jul 29 12:25:47
localhost.localdomain crond[12324]: ((null)) No SELinux security
context (/etc/cron.d/atop) Jul 29 12:25:47 localhost.localdomain
crond[12324]: (root) FAILED (loading cron table) Jul 29 12:25:47
localhost.localdomain crond[12324]: ((null)) No SELinux security
context (/etc/cron.d/moodle) Jul 29 12:25:46 localhost.localdomain
crond[12324]: (root) FAILED (loading cron table) Jul 29 12:25:46
localhost.localdomain crond[12324]: ((null)) No SELinux security
context (/etc/cron.d/mailman) Jul 29 12:25:46 localhost.localdomain
crond[12324]: (root) FAILED (loading cron table) Jul 29 12:25:46
localhost.localdomain crond[12324]: ((null)) No SELinux security
context (/etc/cron.d/rear) Jul 29 12:25:46 localhost.localdomain
crond[12324]: (root) FAILED (loading cron table) Jul 29 12:25:46
localhost.localdomain crond[12324]: ((null)) No SELinux security
context (/etc/crontab) Jul 29 12:25:46 localhost.localdomain
crond[12324]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 28%
if used.) Jul 29 12:25:46 localhost.localdomain crond[12324]: (CRON)
STARTUP (1.5.4) Jul 29 12:25:46 localhost.localdomain systemd[1]:
Started Command Scheduler. Jul 29 12:25:46 localhost.localdomain
systemd[1]: Stopped Command Scheduler. Jul 29 12:25:46
localhost.localdomain systemd[1]: crond.service: Succeeded. Jul 29
12:25:46 localhost.localdomain crond[12307]: (CRON) INFO (Shutting
down) Jul 29 12:25:46 localhost.localdomain systemd[1]: Stopping
Command Scheduler...

I think something (inadvertently) changed the selinux security context
that crond is started with, systemd happily starts it in either case,
ignoring any difference, but when it runs, the missing security context
prevents it from actually performing its function.

I reinstalled all the selinux components, and still the problem
persists.  I'm going to drop this for a while, see if anything comes to
me.  I have your workaround for the time being.

[Ed Greshko]

On 2020-07-30 04:29, stan via users wrote:
> I reinstalled all the selinux components, and still the problem
> persists.  I'm going to drop this for a while, see if anything comes to
> me.  I have your workaround for the time being.

Have you considered doing a relabel?

fixfiles -F onboot

and reboot?

[stan]

On Thu, 30 Jul 2020 05:09:30 +0800
Ed Greshko  wrote:
> Have you considered doing a relabel?
>
> fixfiles -F onboot
>
> and reboot?

I tried a touch /.autorelabel and reboot but it followed symbolic links,
and I have a bunch of links in /home and /mnt.  So I stopped it.  It
looks like I can restrict fixfiles to specific directories, so I will
look into it.  I have already used restorecon -r on /usr and /etc, which
should have picked up any problems.  I also reinstalled cronie, to see
if a reinstall would correct any missing selinux context.  No joy with
any of them.

I think my next step will be to downgrade some of the updates from
July 25 to see if they are causing the problem.  None of them look
likely.

[Ed Greshko]

On 2020-07-31 01:25, stan via users wrote:
> On Thu, 30 Jul 2020 05:09:30 +0800
> Ed Greshko  wrote:
> > Have you considered doing a relabel?
> >
> > fixfiles -F onboot
> >
> > and reboot?
>
> I tried a touch /.autorelabel and reboot but it followed symbolic links,
> and I have a bunch of links in /home and /mnt.  So I stopped it.  It
> looks like I can restrict fixfiles to specific directories, so I will
> look into it.  I have already used restorecon -r on /usr and /etc, which
> should have picked up any problems.  I also reinstalled cronie, to see
> if a reinstall would correct any missing selinux context.  No joy with
> any of them.
>
> I think my next step will be to downgrade some of the updates from
> July 25 to see if they are causing the problem.  None of them look
> likely.

Well, it seems similar issues have come up in the past.

https://bugzilla.redhat.com/show_bug.cgi?id=1309108

and

https://bugzilla.redhat.com/show_bug.cgi?id=1298192

You may want to try the work around in comment 19 of that one.

I think you should then wait on your BZ as well as you may want to join/ask on the selinux
mailing list.

[stan]

On Fri, 31 Jul 2020 05:51:21 +0800
Ed Greshko  wrote:
> Well, it seems similar issues have come up in the past.
>
> https://bugzilla.redhat.com/show_bug.cgi?id=1309108
>
> and
>
> https://bugzilla.redhat.com/show_bug.cgi?id=1298192
>
> You may want to try the work around in comment 19 of that one.

I think it is already in place as the command

sesearch -A -s unconfined_t -t user_cron_spool_t -c file

found

allow application_domain_type user_cron_spool_t:file { append getattr ioctl lock read write };
allow crontab_domain user_cron_spool_t:file { append create getattr ioctl link lock open read rename setattr unlink write };
allow domain file_type:file map; [ domain_can_mmap_files ]:True
allow files_unconfined_type file_type:file execmod; [ selinuxuser_execmod ]:True
allow files_unconfined_type file_type:file { append audit_access create execute execute_no_trans getattr ioctl link lock map mounton open quotaon read relabelfrom relabelto rename setattr swapon unlink write };
allow unconfined_t user_cron_spool_t:file entrypoint; [ cron_userdomain_transition ]:True
allow unconfined_t user_cron_spool_t:file { getattr ioctl read write };

and the second from the bottom is that workaround.
> I think you should then wait on your BZ as well as you may want to
> join/ask on the selinux mailing list.

I agree, I'll wait a while to see if anything develops, and then ask
there.  Hey, it is F31, so going end of life in a few months,
seems to work fine except for this corner case, so probably not a
priority.