IMA: Add audit log for failure conditions

The final log statement in process_buffer_measurement() for failure condition is at debug level. This does not log the message unless the system log level is raised which would significantly increase the messages in the system log. Change this log message to an audit message for better triaging failures in the function.

ima_alloc_key_entry() does not log a message for failure condition. Add an audit message for failure condition in this function.

Sample audit messages:

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error(-22) comm="systemd" name=".builtin_trusted_keys" res=0

[    8.063218] audit: type=1804 audit(1591633422.377:9): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_kexec_cmdline cause=alloc_entry(-12) comm="systemd" name="kexec-cmdline" res=0

Signed-off-by Lakshmi Ramasubramanian <[email protected]>

---
 security/integrity/ima/ima.h            |  2 ++
 security/integrity/ima/ima_main.c       | 37 +++++++++++++++++++++----
 security/integrity/ima/ima_queue.c      |  2 --
 security/integrity/ima/ima_queue_keys.c |  4 +++
 4 files changed, 37 insertions(+), 8 deletions(-)

security/integrity/ima/ima.h +2 -0

index df93ac258e01..8a47249c6238 100644
@@ -47,6 +47,8 @@ enum tpm_pcrs { TPM_PCR0 = 0, TPM_PCR8 = 8 };
 
 #define NR_BANKS(chip) ((chip != NULL) ? chip->nr_allocated_banks : 0)
 
+#define AUDIT_CAUSE_LEN_MAX 32
+
 /* current content of the policy */
 extern int ima_policy_flag;
 

security/integrity/ima/ima_main.c +31 -6

index 800fb3bba418..b10f09bc7eca 100644
@@ -739,6 +739,9 @@ void process_buffer_measurement(const void *buf, int size,
 				int pcr, const char *keyring)
 {
 	int ret = 0;
+	const char *audit_cause = "ENOMEM";
+	const char *op = "measuring_keys";
+	char measurement_audit_cause[AUDIT_CAUSE_LEN_MAX];
 	struct ima_template_entry *entry = NULL;
 	struct integrity_iint_cache iint = {};
 	struct ima_event_data event_data = {.iint = &iint,

@@ -793,21 +796,43 @@ void process_buffer_measurement(const void *buf, int size,
 	iint.ima_hash->length = hash_digest_size[ima_hash_algo];
 
 	ret = ima_calc_buffer_hash(buf, size, iint.ima_hash);
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "hashing_error";
 		goto out;
+	}
 
 	ret = ima_alloc_init_template(&event_data, &entry, template);
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "alloc_entry";
 		goto out;
+	}
 
 	ret = ima_store_template(entry, violation, NULL, buf, pcr);
-
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "store_entry";
 		ima_free_template_entry(entry);
+	}
 
 out:
-	if (ret < 0)
-		pr_devel("%s: failed, result: %d\n", __func__, ret);
+	if (ret < 0) {
+		snprintf(measurement_audit_cause, AUDIT_CAUSE_LEN_MAX,
+			 "%s(%d)", audit_cause, ret);
+
+		switch (func) {
+		case KEXEC_CMDLINE:
+			op = "measuring_kexec_cmdline";
+			break;
+		case KEY_CHECK:
+			op = "measuring_keys";
+			break;
+		default:
+			op = "measuring_blacklisted_hash";
+			break;
+		}
+
+		integrity_audit_msg(AUDIT_INTEGRITY_PCR, NULL, eventname,
+				    op, measurement_audit_cause, ret, 0);
+	}
 
 	return;
 }

security/integrity/ima/ima_queue.c +0 -2

index fb4ec270f620..4a761d765c6c 100644
@@ -19,8 +19,6 @@
 #include <linux/slab.h>
 #include "ima.h"
 
-#define AUDIT_CAUSE_LEN_MAX 32
-
 /* pre-allocated array of tpm_digest structures to extend a PCR */
 static struct tpm_digest *digests;
 

security/integrity/ima/ima_queue_keys.c +4 -0

index cb3e3f501593..4de31ff172aa 100644
@@ -68,6 +68,7 @@ static struct ima_key_entry *ima_alloc_key_entry(struct key *keyring,
 						 size_t payload_len)
 {
 	int rc = 0;
+	const char *audit_cause = "ENOMEM";
 	struct ima_key_entry *entry;
 
 	entry = kzalloc(sizeof(*entry), GFP_KERNEL);

@@ -88,6 +89,9 @@ static struct ima_key_entry *ima_alloc_key_entry(struct key *keyring,
 
 out:
 	if (rc) {
+		integrity_audit_msg(AUDIT_INTEGRITY_PCR, NULL,
+				    keyring->description, "measuring_keys",
+				    audit_cause, rc, 0);
 		ima_free_key_entry(entry);
 		entry = NULL;
 	}

Signature · 7 lines

2.27.0


--
Linux-audit mailing list
[email protected]
https://www.redhat.com/mailman/listinfo/linux-audit

The final log statement in process_buffer_measurement() for failure condition is at debug level. This does not log the message unless the system log level is raised which would significantly increase the messages in the system log. Change this log message to an audit message for better triaging failures in the function.

ima_alloc_key_entry() does not log a message for failure condition. Add an audit message for failure condition in this function.

Sample audit messages:

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error(-22)

comm="systemd"
name=".builtin_trusted_keys" res=0

[    8.063218] audit: type=1804 audit(1591633422.377:9): pid=1 uid=0

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_kexec_cmdline cause=alloc_entry(-12) comm="systemd" name="kexec-cmdline" res=0

Signed-off-by Lakshmi Ramasubramanian <[email protected]>

---
 security/integrity/ima/ima.h            |  2 ++
 security/integrity/ima/ima_main.c       | 37 +++++++++++++++++++++----
 security/integrity/ima/ima_queue.c      |  2 --
 security/integrity/ima/ima_queue_keys.c |  4 +++
 4 files changed, 37 insertions(+), 8 deletions(-)

security/integrity/ima/ima.h +2 -0

index df93ac258e01..8a47249c6238 100644
@@ -47,6 +47,8 @@ enum tpm_pcrs { TPM_PCR0 = 0, TPM_PCR8 = 8 };
 
 #define NR_BANKS(chip) ((chip != NULL) ? chip->nr_allocated_banks : 0)
 
+#define AUDIT_CAUSE_LEN_MAX 32
+
 /* current content of the policy */
 extern int ima_policy_flag;
 

(quoted diff) +0 -0

b/security/integrity/ima/ima_main.c index 800fb3bba418..b10f09bc7eca 100644

security/integrity/ima/ima_main.c +31 -6

@@ -739,6 +739,9 @@ void process_buffer_measurement(const void *buf, int
 size, int pcr, const char *keyring)
 {
 	int ret = 0;
+	const char *audit_cause = "ENOMEM";
+	const char *op = "measuring_keys";
+	char measurement_audit_cause[AUDIT_CAUSE_LEN_MAX];
 	struct ima_template_entry *entry = NULL;
 	struct integrity_iint_cache iint = {};
 	struct ima_event_data event_data = {.iint = &iint,

@@ -793,21 +796,43 @@ void process_buffer_measurement(const void *buf, int
 size, iint.ima_hash->length = hash_digest_size[ima_hash_algo];
 
 	ret = ima_calc_buffer_hash(buf, size, iint.ima_hash);
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "hashing_error";
 		goto out;
+	}
 
 	ret = ima_alloc_init_template(&event_data, &entry, template);
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "alloc_entry";
 		goto out;
+	}
 
 	ret = ima_store_template(entry, violation, NULL, buf, pcr);
-
-	if (ret < 0)
+	if (ret < 0) {
+		audit_cause = "store_entry";
 		ima_free_template_entry(entry);
+	}
 
 out:
-	if (ret < 0)
-		pr_devel("%s: failed, result: %d\n", __func__, ret);
+	if (ret < 0) {
+		snprintf(measurement_audit_cause, AUDIT_CAUSE_LEN_MAX,
+			 "%s(%d)", audit_cause, ret);
+
+		switch (func) {
+		case KEXEC_CMDLINE:
+			op = "measuring_kexec_cmdline";
+			break;
+		case KEY_CHECK:
+			op = "measuring_keys";
+			break;
+		default:
+			op = "measuring_blacklisted_hash";
+			break;
+		}
+
+		integrity_audit_msg(AUDIT_INTEGRITY_PCR, NULL, eventname,
+				    op, measurement_audit_cause, ret, 0);
+	}
 
 	return;
 }

(quoted diff) +0 -0

b/security/integrity/ima/ima_queue.c index fb4ec270f620..4a761d765c6c 100644

security/integrity/ima/ima_queue.c +0 -2

@@ -19,8 +19,6 @@
 #include <linux/slab.h>
 #include "ima.h"
 
-#define AUDIT_CAUSE_LEN_MAX 32
-
 /* pre-allocated array of tpm_digest structures to extend a PCR */
 static struct tpm_digest *digests;
 

(quoted diff) +0 -0

b/security/integrity/ima/ima_queue_keys.c index cb3e3f501593..4de31ff172aa 100644

security/integrity/ima/ima_queue_keys.c +4 -0

@@ -68,6 +68,7 @@ static struct ima_key_entry *ima_alloc_key_entry(struct
 key *keyring, size_t payload_len)
 {
 	int rc = 0;
+	const char *audit_cause = "ENOMEM";
 	struct ima_key_entry *entry;
 
 	entry = kzalloc(sizeof(*entry), GFP_KERNEL);

@@ -88,6 +89,9 @@ static struct ima_key_entry *ima_alloc_key_entry(struct
 key *keyring,
 
 out:
 	if (rc) {
+		integrity_audit_msg(AUDIT_INTEGRITY_PCR, NULL,
+				    keyring->description, "measuring_keys",
+				    audit_cause, rc, 0);
 		ima_free_key_entry(entry);
 		entry = NULL;

}

Quoted 6 lines · EDT Lakshmi Ramasubramanian

The final log statement in process_buffer_measurement() for failure condition is at debug level. This does not log the message unless the system log level is raised which would significantly increase the messages in the system log. Change this log message to an audit message for better triaging failures in the function.

Quoted 4 lines

ima_alloc_key_entry() does not log a message for failure condition. Add an audit message for failure condition in this function.

Sample audit messages:

Wouldn't it be better to have an IMA_ERROR record type?

Quoted 4 lines

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error(-22)

The audit system uses a name=value scheme to express information. This last field has something in parenthesis that may need to be interpreted. In its current form, we can't do this. It would require writing code to special case this event, go to this field, find the first parenthesis, find the second, extract what's between, and look it up.

It would be better if that number in parenthesis was normalized to the expected way we do audit events so nothing special has to be made.

Quoted 7 lines · Steve Grubb

Quoted 6 lines · EDT Lakshmi Ramasubramanian

The final log statement in process_buffer_measurement() for failure condition is at debug level. This does not log the message unless the system log level is raised which would significantly increase the messages in the system log. Change this log message to an audit message for better triaging failures in the function.

Quoted 5 lines

Quoted 4 lines

ima_alloc_key_entry() does not log a message for failure condition. Add an audit message for failure condition in this function.

Sample audit messages:

Wouldn't it be better to have an IMA_ERROR record type?

type "1804" is AUDIT_INTEGRITY_PCR which is used for failures to add to the measurement list.

Quoted 4 lines

Quoted 3 lines

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error(-22)

Quoted 8 lines

The audit system uses a name=value scheme to express information. This last field has something in parenthesis that may need to be interpreted. In its current form, we can't do this. It would require writing code to special case this event, go to this field, find the first parenthesis, find the second, extract what's between, and look it up.

It would be better if that number in parenthesis was normalized to the expected way we do audit events so nothing special has to be made.

The number in parenthesis is the error code (such as ENOMEM, EINVAL, etc.) IMA uses this format for reporting TPM errors in one of the audit messages (In ima_add_template_entry()). I followed the same pattern.

Would it be better if the value for "cause" is formatted as

    cause=hashing_error_-22

    cause=alloc_entry_-12

Quoted 9 lines

The number in parenthesis is the error code (such as ENOMEM, EINVAL, etc.) IMA uses this format for reporting TPM errors in one of the audit messages (In ima_add_template_entry()). I followed the same pattern.

Would it be better if the value for "cause" is formatted as

     cause=hashing_error_-22

     cause=alloc_entry_-12

Neither fit the name=value style that all other events follow. What would fit the style is something like this:

cause=hashing_error errno=-22

cause=alloc_entry errno=-12

Would this be OK? Also, errno is only to illustrate. You can name it something else as long as there are no use case collisions with our dictionary of field names.

https://github.com/linux-audit/audit-documentation/blob/master/specs/fields/
field-dictionary.csv

Quoted 15 lines · Steve Grubb

Quoted 9 lines

The number in parenthesis is the error code (such as ENOMEM, EINVAL, etc.) IMA uses this format for reporting TPM errors in one of the audit messages (In ima_add_template_entry()). I followed the same pattern.

Would it be better if the value for "cause" is formatted as

     cause=hashing_error_-22

     cause=alloc_entry_-12

Neither fit the name=value style that all other events follow. What would fit the style is something like this:

cause=hashing_error errno=-22

Quoted 8 lines

cause=alloc_entry errno=-12

Would this be OK? Also, errno is only to illustrate. You can name it something else as long as there are no use case collisions with our dictionary of field names.

https://github.com/linux-audit/audit-documentation/blob/master/specs/fields/
field-dictionary.csv

I am fine with this.

"errno" is currently not listed in the dictionary of audit message field names (Thanks for the pointer to this one Steve)

Mimi - please let me know if you have any concerns with adding the "result" code in "errno" field in integrity_audit_msg().

Sample message:

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0 

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error errno=-22 comm="systemd" name=".builtin_trusted_keys" res=0

Quoted 16 lines · Steve Grubb

Quoted 9 lines

The number in parenthesis is the error code (such as ENOMEM, EINVAL, etc.) IMA uses this format for reporting TPM errors in one of the audit messages (In ima_add_template_entry()). I followed the same pattern.

Would it be better if the value for "cause" is formatted as

     cause=hashing_error_-22

     cause=alloc_entry_-12

Neither fit the name=value style that all other events follow. What would fit the style is something like this:

cause=hashing_error errno=-22
cause=alloc_entry errno=-12

Quoted 6 lines

Would this be OK? Also, errno is only to illustrate. You can name it something else as long as there are no use case collisions with our dictionary of field names.

https://github.com/linux-audit/audit-documentation/blob/master/specs/fields/
field-dictionary.csv

I am fine with this.

"errno" is currently not listed in the dictionary of audit message field names (Thanks for the pointer to this one Steve)

Mimi - please let me know if you have any concerns with adding the "result" code in "errno" field in integrity_audit_msg().

Sample message:

[    8.051937] audit: type=1804 audit(1591633422.365:8): pid=1 uid=0

auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 op=measuring_keys cause=hashing_error errno=-22 comm="systemd" name=".builtin_trusted_keys" res=0

thanks,
-lakshmi

On 2020-06-09 10:00, Lakshmi Ramasubramanian wrote:

If it is added, it should be appended to the end of the record since it is an existing record format, then in the case of res=1, errno= should still be present (not swing in and out) and just contain zero. (Or another value if there is a non-fatal warning?)

Quoted 18 lines · Lakshmi Ramasubramanian

Quoted 17 lines · Steve Grubb

Quoted 10 lines

The number in parenthesis is the error code (such as ENOMEM, EINVAL, etc.) IMA uses this format for reporting TPM errors in one of the audit
messages (In ima_add_template_entry()). I followed the same pattern.

Would it be better if the value for "cause" is formatted as

cause=hashing_error_-22

cause=alloc_entry_-12

Neither fit the name=value style that all other events follow. What would fit the style is something like this:

cause=hashing_error errno=-22
cause=alloc_entry errno=-12

Quoted 8 lines

Quoted 6 lines

Would this be OK? Also, errno is only to illustrate. You can name it something else as long as there are no use case collisions with our dictionary of field names.

https://github.com/linux-audit/audit-documentation/blob/master/specs/fi
elds/ field-dictionary.csv

I am fine with this.

Quoted 2 lines

"errno" is currently not listed in the dictionary of audit message field names (Thanks for the pointer to this one Steve)

Quoted 2 lines

Mimi - please let me know if you have any concerns with adding the "result" code in "errno" field in integrity_audit_msg().

If it is added, it should be appended to the end of the record since it is an existing record format, then in the case of res=1, errno= should still be present (not swing in and out) and just contain zero. (Or another value if there is a non-fatal warning?)

Quoted 5 lines

If it is added, it should be appended to the end of the record since it is an existing record format, then in the case of res=1, errno= should still be present (not swing in and out) and just contain zero. (Or another value if there is a non-fatal warning?)

This is not a searchable field, so it can go anywhere. If it is searchable, ausearch expects ordering of other searchable fields.

The final log statement in process_buffer_measurement() for failure condition is at debug level. This does not log the message unless the system log level is raised which would significantly increase the messages in the system log. Change this log message to an audit message for better triaging failures in the function.

(quoted diff) +1 -0

+	}