"selinux_nlmsg_perm: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=30" warning on Linux 3.18-rc3

PATCH In review Vinson Lee 5 participants 13 messages Nov 4, 2014 – Nov 12, 2014 SELinux security module

lore

Share & tools

lore

Vinson Lee

author

2014-11-04 20:12 UTC #0 lore raw

Hi.

trinity triggered this kernel warning in selinux_netlink_send on Linux 3.18-rc3.

------------[ cut here ]------------
WARNING: CPU: 8 PID: 53557 at security/selinux/hooks.c:4730
selinux_netlink_send+0x9e/0xfc()
selinux_nlmsg_perm: unrecognized netlink message: protocol=0
nlmsg_type=0 sclass=30
Modules linked in: af_key l2tp_ppp l2tp_netlink l2tp_core nfnetlink

can_bcm scsi_transport_iscsi can_raw can pppoe pppox ppp_generic slhc netconsole configfs ipv6 dm_multipath scsi_dh video sbs sbshc acpi_pad acpi_ipmi parport_pc lp parport tcp_diag inet_diag ipmi_devintf sg mlx4_en ptp pps_core vxlan udp_tunnel ip6_udp_tunnel mlx4_core iTCO_wdt iTCO_vendor_support dcdbas wmi ioatdma sb_edac hed i2c_i801 i2c_core microcode edac_core ipmi_si ipmi_msghandler lpc_ich mfd_core shpchp dca ahci libahci libata sd_mod scsi_mod

CPU: 8 PID: 53557 Comm: trinity-c8 Not tainted 3.18.0-rc3 #1
 0000000000000009 ffff88104c153be8 ffffffff814daf56 00000000000000e5
 ffff88104c153c38 ffff88104c153c28 ffffffff8106010d ffffffff8142815f
 ffffffff8123431e 00000000ffffffea ffff8800770be800 0000000000000000
Call Trace:
 [<ffffffff814daf56>] dump_stack+0x46/0x58
 [<ffffffff8106010d>] warn_slowpath_common+0x81/0x9b
 [<ffffffff8142815f>] ? __alloc_skb+0x84/0x1b1
 [<ffffffff8123431e>] ? selinux_netlink_send+0x9e/0xfc
 [<ffffffff8106016d>] warn_slowpath_fmt+0x46/0x48
 [<ffffffff8123431e>] selinux_netlink_send+0x9e/0xfc
 [<ffffffff8123119b>] security_netlink_send+0x16/0x18
 [<ffffffff8145bf30>] netlink_sendmsg+0x570/0x630
 [<ffffffff81232aeb>] ? sock_has_perm+0x63/0x6a
 [<ffffffff8141ea6f>] __sock_sendmsg_nosec+0x25/0x27
 [<ffffffff81420252>] sock_aio_write+0xc6/0xdd
 [<ffffffff81233255>] ? file_has_perm+0x5d/0x81
 [<ffffffff8116835b>] do_sync_write+0x55/0x78
 [<ffffffff81168c8e>] vfs_write+0xbb/0x124
 [<ffffffff81169321>] SyS_write+0x44/0x78
 [<ffffffff814e26b9>] ia32_do_call+0x13/0x13
---[ end trace 9c4105cdf6c3f1b1 ]---

Cheers,
Vinson

Paul Moore

maintainer

2014-11-05 20:48 UTC #1 lore raw

Quoted 4 lines · Vinson Lee

Hi.
trinity triggered this kernel warning in selinux_netlink_send on Linux 3.18-rc3.

It looks like trinity sent a bogus netlink message to the kernel and SELinux responded as I would expect it to, with a WARN_ONCE() message. Thank you for your help in testing, but I don't see a problem here that needs to be resolved.

Quoted 38 lines

------------[ cut here ]------------
WARNING: CPU: 8 PID: 53557 at security/selinux/hooks.c:4730
selinux_netlink_send+0x9e/0xfc()
selinux_nlmsg_perm: unrecognized netlink message: protocol=0
nlmsg_type=0 sclass=30
Modules linked in: af_key l2tp_ppp l2tp_netlink l2tp_core nfnetlink

CPU: 8 PID: 53557 Comm: trinity-c8 Not tainted 3.18.0-rc3 #1
 0000000000000009 ffff88104c153be8 ffffffff814daf56 00000000000000e5
 ffff88104c153c38 ffff88104c153c28 ffffffff8106010d ffffffff8142815f
 ffffffff8123431e 00000000ffffffea ffff8800770be800 0000000000000000
Call Trace:
 [<ffffffff814daf56>] dump_stack+0x46/0x58
 [<ffffffff8106010d>] warn_slowpath_common+0x81/0x9b
 [<ffffffff8142815f>] ? __alloc_skb+0x84/0x1b1
 [<ffffffff8123431e>] ? selinux_netlink_send+0x9e/0xfc
 [<ffffffff8106016d>] warn_slowpath_fmt+0x46/0x48
 [<ffffffff8123431e>] selinux_netlink_send+0x9e/0xfc
 [<ffffffff8123119b>] security_netlink_send+0x16/0x18
 [<ffffffff8145bf30>] netlink_sendmsg+0x570/0x630
 [<ffffffff81232aeb>] ? sock_has_perm+0x63/0x6a
 [<ffffffff8141ea6f>] __sock_sendmsg_nosec+0x25/0x27
 [<ffffffff81420252>] sock_aio_write+0xc6/0xdd
 [<ffffffff81233255>] ? file_has_perm+0x5d/0x81
 [<ffffffff8116835b>] do_sync_write+0x55/0x78
 [<ffffffff81168c8e>] vfs_write+0xbb/0x124
 [<ffffffff81169321>] SyS_write+0x44/0x78
 [<ffffffff814e26b9>] ia32_do_call+0x13/0x13
---[ end trace 9c4105cdf6c3f1b1 ]---

Cheers,
Vinson

Signature · 2 lines

paul moore
www.paul-moore.com

Stephen Smalley

2014-11-05 20:51 UTC #2 lore raw

Quoted 10 lines · Paul Moore

Quoted 4 lines · Vinson Lee
Hi.
trinity triggered this kernel warning in selinux_netlink_send on Linux 3.18-rc3.
It looks like trinity sent a bogus netlink message to the kernel and SELinux responded as I would expect it to, with a WARN_ONCE() message. Thank you for your help in testing, but I don't see a problem here that needs to be resolved.

I guess the only thing new here is that this message used to be directed to the audit system via audit_log() and was changed to use WARN_ONCE().
Why was that change made (the change description gives no rationale)?
Is this an appropriate use of WARN_ONCE()?

Quoted 40 lines

Quoted 39 lines

------------[ cut here ]------------
WARNING: CPU: 8 PID: 53557 at security/selinux/hooks.c:4730
selinux_netlink_send+0x9e/0xfc()
selinux_nlmsg_perm: unrecognized netlink message: protocol=0
nlmsg_type=0 sclass=30
Modules linked in: af_key l2tp_ppp l2tp_netlink l2tp_core nfnetlink

CPU: 8 PID: 53557 Comm: trinity-c8 Not tainted 3.18.0-rc3 #1
 0000000000000009 ffff88104c153be8 ffffffff814daf56 00000000000000e5
 ffff88104c153c38 ffff88104c153c28 ffffffff8106010d ffffffff8142815f
 ffffffff8123431e 00000000ffffffea ffff8800770be800 0000000000000000
Call Trace:
 [<ffffffff814daf56>] dump_stack+0x46/0x58
 [<ffffffff8106010d>] warn_slowpath_common+0x81/0x9b
 [<ffffffff8142815f>] ? __alloc_skb+0x84/0x1b1
 [<ffffffff8123431e>] ? selinux_netlink_send+0x9e/0xfc
 [<ffffffff8106016d>] warn_slowpath_fmt+0x46/0x48
 [<ffffffff8123431e>] selinux_netlink_send+0x9e/0xfc
 [<ffffffff8123119b>] security_netlink_send+0x16/0x18
 [<ffffffff8145bf30>] netlink_sendmsg+0x570/0x630
 [<ffffffff81232aeb>] ? sock_has_perm+0x63/0x6a
 [<ffffffff8141ea6f>] __sock_sendmsg_nosec+0x25/0x27
 [<ffffffff81420252>] sock_aio_write+0xc6/0xdd
 [<ffffffff81233255>] ? file_has_perm+0x5d/0x81
 [<ffffffff8116835b>] do_sync_write+0x55/0x78
 [<ffffffff81168c8e>] vfs_write+0xbb/0x124
 [<ffffffff81169321>] SyS_write+0x44/0x78
 [<ffffffff814e26b9>] ia32_do_call+0x13/0x13
---[ end trace 9c4105cdf6c3f1b1 ]---

Cheers,
Vinson

Paul Moore

maintainer

2014-11-05 21:57 UTC #3 lore raw

Quoted 7 lines · Stephen Smalley

Quoted 6 lines · Paul Moore
Quoted 4 lines · Vinson Lee
Hi.
trinity triggered this kernel warning in selinux_netlink_send on Linux 3.18-rc3.

Quoted 8 lines

Quoted 4 lines
It looks like trinity sent a bogus netlink message to the kernel and SELinux responded as I would expect it to, with a WARN_ONCE() message. Thank you for your help in testing, but I don't see a problem here that needs to be resolved.
I guess the only thing new here is that this message used to be directed to the audit system via audit_log() and was changed to use WARN_ONCE(). Why was that change made (the change description gives no rationale)?

My understanding was that the audit record didn't fit the hoped-for-but-not- really-a-standard name value pair format that the audit folks like. Richard wanted to either normalize the audit record or replace it with something else.

Quoted 1 line

Is this an appropriate use of WARN_ONCE()?

In retrospect, we could probably do better. I don't think it should be an audit record, but I can see the point that a backtrace and scary WARNING! display are probably a bit too much.

Richard, how about converting this WARN_ONCE() to a printk_once(), or similar?

Signature · 2 lines

paul moore
www.paul-moore.com

Richard Guy Briggs

2014-11-05 22:25 UTC #4 lore raw

Quoted 7 lines · Paul Moore

Quoted 6 lines · Stephen Smalley
Quoted 5 lines · Paul Moore
Quoted 4 lines · Vinson Lee
Hi.
trinity triggered this kernel warning in selinux_netlink_send on Linux 3.18-rc3.

Vinson, have you ever seen an audit message reporting this problem previously from trinity?

Quoted 5 lines

Quoted 5 lines
Quoted 4 lines
It looks like trinity sent a bogus netlink message to the kernel and SELinux responded as I would expect it to, with a WARN_ONCE() message. Thank you for your help in testing, but I don't see a problem here that needs to be resolved.

Quoted 7 lines

Quoted 3 lines
I guess the only thing new here is that this message used to be directed to the audit system via audit_log() and was changed to use WARN_ONCE(). Why was that change made (the change description gives no rationale)?
My understanding was that the audit record didn't fit the hoped-for-but-not- really-a-standard name value pair format that the audit folks like. Richard wanted to either normalize the audit record or replace it with something else.

I didn't like that it was an audit record because that wasn't really an auditable event since it failed, presenting no danger to the system, and that it could potentially fill audit logs with useless reports.

I didn't really like that it was a WARN_ONCE, since it seemed a bit too alarmist and also made it more difficult to debug.

The other recent WARN_ONCE conversions were partly influenced by an effort to clean up locking in audit, but that is not the case here.

Quoted 7 lines

Quoted 1 line
Is this an appropriate use of WARN_ONCE()?
In retrospect, we could probably do better. I don't think it should be an audit record, but I can see the point that a backtrace and scary WARNING! display are probably a bit too much.
Richard, how about converting this WARN_ONCE() to a printk_once(), or similar?

I'd be agreeable to that. While I was a bit concerned that a WARN_ONCE() could be lost in the noise (evidently that's not the case!) a printk_once() would more likely get lost in the noise. Would it make sense to make it a bit less infrequent than printk_once() and rate-limit it at say, one per 5 seconds or more?

Quoted 1 line

paul moore

- RGB

--
Richard Guy Briggs <[email protected]>
Senior Software Engineer, Kernel Security, AMER ENG Base Operating Systems, Red Hat Remote, Ottawa, Canada
Voice: +1.647.777.2635, Internal: (81) 32635, Alt: +1.613.693.0684x3545

Paul Moore

maintainer

2014-11-10 20:41 UTC #5 lore raw

Quoted 5 lines · Richard Guy Briggs

Quoted 4 lines · Paul Moore
In retrospect, we could probably do better. I don't think it should be an audit record, but I can see the point that a backtrace and scary WARNING! display are probably a bit too much.

Quoted 8 lines

Quoted 2 lines
Richard, how about converting this WARN_ONCE() to a printk_once(), or similar?
I'd be agreeable to that. While I was a bit concerned that a WARN_ONCE() could be lost in the noise (evidently that's not the case!) a printk_once() would more likely get lost in the noise. Would it make sense to make it a bit less infrequent than printk_once() and rate-limit it at say, one per 5 seconds or more?

Let's just go with printk_once() for right now. We probably need to have a better, more consistent approach to error messages not related to the normal access control stuff, however, I'd like to fix this for the v3.18-rcX releases and that is a bit out of scope for right now.

Ideally I'd like to fix it this week. Richard, any chance you can submit a patch by the end of the day on Tuesday? It really should be trivial; if you can't let me know and I'll take care of it.

Signature · 2 lines

paul moore
www.paul-moore.com

Richard Guy Briggs

2014-11-12 19:01 UTC #6 lore raw

PATCH 1/1 selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm().

After conversion from audit_log() in commit e173fb26, WARN_ONCE() was deemed too alarmist, so switch it to printk_once(). If this gets buried in the noise, it may be converted to a rate-limited call in the future.

Signed-off-by Richard Guy Briggs <[email protected]>

---
 security/selinux/hooks.c |    6 +++---
 1 files changed, 3 insertions(+), 3 deletions(-)

security/selinux/hooks.c +3 -3

index e663141..17d0066 100644
@@ -4725,9 +4725,9 @@ static int selinux_nlmsg_perm(struct sock *sk, struct sk_buff *skb)
 	err = selinux_nlmsg_lookup(sksec->sclass, nlh->nlmsg_type, &perm);
 	if (err) {
 		if (err == -EINVAL) {
-			WARN_ONCE(1, "selinux_nlmsg_perm: unrecognized netlink message:"
-				  " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
-				  sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
+			printk_once("selinux_nlmsg_perm: unrecognized netlink message:"
+				    " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
+				    sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
 			if (!selinux_enforcing || security_get_allow_unknown())
 				err = 0;
 		}

Signature · 1 line

1.7.1

Paul Moore

2014-11-12 21:21 UTC #7 lore raw

Re: [PATCH] selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Quoted 16 lines · Richard Guy Briggs

Convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm().
After conversion from audit_log() in commit e173fb26, WARN_ONCE() was deemed too alarmist, so switch it to printk_once(). If this gets buried in the noise, it may be converted to a rate-limited call in the future.
Signed-off-by Richard Guy Briggs <[email protected]>
---
 security/selinux/hooks.c |    6 +++---
 1 files changed, 3 insertions(+), 3 deletions(-)
security/selinux/hooks.c +0 -0
index e663141..17d0066 100644

security/selinux/hooks.c static int selinux_nlmsg_perm(struct sock *sk, struct · line 4728

Quoted 4 lines

security/selinux/hooks.c +0 -1

@@ -4725,9 +4725,9 @@ static int selinux_nlmsg_perm(struct sock *sk, struct
 sk_buff *skb) err = selinux_nlmsg_lookup(sksec->sclass, nlh->nlmsg_type,
 &perm); if (err) {
 		if (err == -EINVAL) {
-			WARN_ONCE(1, "selinux_nlmsg_perm: unrecognized netlink

message:"

security/selinux/hooks.c static int selinux_nlmsg_perm(struct sock *sk, struct sk_buff *skb) · line 4733

Quoted 8 lines

security/selinux/hooks.c +3 -2

-				  " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
-				  sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
+			printk_once("selinux_nlmsg_perm: unrecognized netlink message:"
+				    " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
+				    sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
 			if (!selinux_enforcing || security_get_allow_unknown())
 				err = 0;
 		}

My apologies, I should have noticed this sooner, but printk_once() is probably not a good choice here as only the first invalid netlink message will be displayed. This is fine if all the invalid netlink messages happen the same, but that isn't likely to be the case.

Richard, any objections if I convert the printk_once() to a printk(WARN) and update the patch description accordingly?

Signature · 2 lines

paul moore
security and virtualization @ redhat

Richard Guy Briggs

2014-11-12 21:25 UTC #8 lore raw

Re: [PATCH] selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Quoted 22 lines · Paul Moore

Quoted 16 lines · Richard Guy Briggs
Convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm().
After conversion from audit_log() in commit e173fb26, WARN_ONCE() was deemed too alarmist, so switch it to printk_once(). If this gets buried in the noise, it may be converted to a rate-limited call in the future.
Signed-off-by Richard Guy Briggs <[email protected]>
---
 security/selinux/hooks.c |    6 +++---
 1 files changed, 3 insertions(+), 3 deletions(-)
security/selinux/hooks.c +0 -0
index e663141..17d0066 100644
security/selinux/hooks.c static int selinux_nlmsg_perm(struct sock *sk, struct · line 4728
Quoted 4 lines
security/selinux/hooks.c +0 -1
@@ -4725,9 +4725,9 @@ static int selinux_nlmsg_perm(struct sock *sk, struct
 sk_buff *skb) err = selinux_nlmsg_lookup(sksec->sclass, nlh->nlmsg_type,
 &perm); if (err) {
 		if (err == -EINVAL) {
-			WARN_ONCE(1, "selinux_nlmsg_perm: unrecognized netlink 
message:"

Quoted 13 lines

security/selinux/hooks.c static int selinux_nlmsg_perm(struct sock *sk, struct sk_buff *skb) · line 4733
Quoted 8 lines
security/selinux/hooks.c +3 -2
-				  " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
-				  sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
+			printk_once("selinux_nlmsg_perm: unrecognized netlink message:"
+				    " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
+				    sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
 			if (!selinux_enforcing || security_get_allow_unknown())
 				err = 0;
 		}
My apologies, I should have noticed this sooner, but printk_once() is probably not a good choice here as only the first invalid netlink message will be displayed. This is fine if all the invalid netlink messages happen the same, but that isn't likely to be the case.

This was the same situation with WARN_ONCE(), hence my comment about difficulty in debugging...

Quoted 2 lines

Richard, any objections if I convert the printk_once() to a printk(WARN) and update the patch description accordingly?

Use pr_warn() instead...

Quoted 1 line

paul moore

- RGB

Paul Moore

2014-11-12 21:30 UTC #9 lore raw

Re: [PATCH] selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Quoted 8 lines · Richard Guy Briggs

Quoted 4 lines · Paul Moore
My apologies, I should have noticed this sooner, but printk_once() is probably not a good choice here as only the first invalid netlink message will be displayed. This is fine if all the invalid netlink messages happen the same, but that isn't likely to be the case.
This was the same situation with WARN_ONCE(), hence my comment about difficulty in debugging...

Unfortunately I didn't realize your point until now.

Quoted 4 lines

Quoted 2 lines
Richard, any objections if I convert the printk_once() to a printk(WARN) and update the patch description accordingly?
Use pr_warn() instead...

Normally, yes, but the rest of the SELinux code uses printk(WARN) and I'm a stickler for consistency.

Signature · 2 lines

paul moore
security and virtualization @ redhat

Richard Guy Briggs

2014-11-12 21:35 UTC #10 lore raw

Re: [PATCH] selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Quoted 12 lines · Paul Moore

Quoted 8 lines · Richard Guy Briggs
Quoted 4 lines · Paul Moore
My apologies, I should have noticed this sooner, but printk_once() is probably not a good choice here as only the first invalid netlink message will be displayed. This is fine if all the invalid netlink messages happen the same, but that isn't likely to be the case.
This was the same situation with WARN_ONCE(), hence my comment about difficulty in debugging...
Unfortunately I didn't realize your point until now.

Quoted 7 lines

Quoted 4 lines
Quoted 2 lines
Richard, any objections if I convert the printk_once() to a printk(WARN) and update the patch description accordingly?
Use pr_warn() instead...
Normally, yes, but the rest of the SELinux code uses printk(WARN) and I'm a stickler for consistency.

And Joe Perches hasn't handed a patch you've accepted yet to convert it all over?

As you prefer...

Quoted 1 line

paul moore

- RGB

Paul Moore

2014-11-12 21:44 UTC #11 lore raw

Re: [PATCH] selinux: convert WARN_ONCE() to printk_once() in selinux_nlmsg_perm()

Quoted 9 lines · Richard Guy Briggs

Quoted 5 lines · Paul Moore
Quoted 1 line · Richard Guy Briggs
Use pr_warn() instead...
Normally, yes, but the rest of the SELinux code uses printk(WARN) and I'm a stickler for consistency.
And Joe Perches hasn't handed a patch you've accepted yet to convert it all over?

Maybe I missed it, but I don't recall one ...

Signature · 2 lines

paul moore
security and virtualization @ redhat

Paul Moore

2014-11-12 21:36 UTC #12 lore raw

PATCH 1/1 selinux: convert WARN_ONCE() to printk() in selinux_nlmsg_perm()

In reply to Richard Guy Briggs

From: Richard Guy Briggs <[email protected]>

Convert WARN_ONCE() to printk() in selinux_nlmsg_perm().

After conversion from audit_log() in commit e173fb26, WARN_ONCE() was deemed too alarmist, so switch it to printk().

Signed-off-by Richard Guy Briggs <[email protected]>

[PM: Changed to printk(WARNING) so we can all of the different invalid
netlink messages. In Richard's defense, he brought this point up earlier, but I didn't understand his point at the time.]

Signed-off-by Paul Moore <[email protected]>

---
 security/selinux/hooks.c |    7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

security/selinux/hooks.c +4 -3

index 2478976..654f071 100644
@@ -4727,9 +4727,10 @@ static int selinux_nlmsg_perm(struct sock *sk, struct sk_buff *skb)
 	err = selinux_nlmsg_lookup(sksec->sclass, nlh->nlmsg_type, &perm);
 	if (err) {
 		if (err == -EINVAL) {
-			WARN_ONCE(1, "selinux_nlmsg_perm: unrecognized netlink message:"
-				  " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
-				  sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
+			printk(KERN_WARNING
+			       "SELinux: unrecognized netlink message:"
+			       " protocol=%hu nlmsg_type=%hu sclass=%hu\n",
+			       sk->sk_protocol, nlh->nlmsg_type, sksec->sclass);
 			if (!selinux_enforcing || security_get_allow_unknown())
 				err = 0;
 		}