From: dhfelix Date: Thu, 21 May 2020 03:05:27 +0000 (-0500) Subject: Separate validation logs from operation logs X-Git-Tag: v1.3.0~18 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=0e0d367be16150325b0934c986729e90bed4e156;p=thirdparty%2FFORT-validator.git Separate validation logs from operation logs Fix #31 --- diff --git a/src/address.c b/src/address.c index 86b4d410..df69bbf3 100644 --- a/src/address.c +++ b/src/address.c @@ -166,11 +166,11 @@ prefix4_decode(IPAddress_t const *str, struct ipv4_prefix *result) int len; if (str->size > 4) { - return pr_err("IPv4 address has too many octets. (%zu)", + return pr_val_err("IPv4 address has too many octets. (%zu)", str->size); } if (str->bits_unused < 0 || 7 < str->bits_unused) { - return pr_err("Bit string IPv4 address's unused bits count (%d) is out of range (0-7).", + return pr_val_err("Bit string IPv4 address's unused bits count (%d) is out of range (0-7).", str->bits_unused); } @@ -179,14 +179,14 @@ prefix4_decode(IPAddress_t const *str, struct ipv4_prefix *result) len = 8 * str->size - str->bits_unused; if (len < 0 || 32 < len) { - return pr_err("IPv4 prefix length (%d) is out of bounds (0-32).", + return pr_val_err("IPv4 prefix length (%d) is out of bounds (0-32).", len); } result->len = len; if ((result->addr.s_addr & be32_suffix_mask(result->len)) != 0) { - return pr_err("IPv4 prefix '%s/%u' has enabled suffix bits.", + return pr_val_err("IPv4 prefix '%s/%u' has enabled suffix bits.", v4addr2str(&result->addr), result->len); } @@ -203,11 +203,11 @@ prefix6_decode(IPAddress_t const *str, struct ipv6_prefix *result) int len; if (str->size > 16) { - return pr_err("IPv6 address has too many octets. (%zu)", + return pr_val_err("IPv6 address has too many octets. (%zu)", str->size); } if (str->bits_unused < 0 || 7 < str->bits_unused) { - return pr_err("Bit string IPv6 address's unused bits count (%d) is out of range (0-7).", + return pr_val_err("Bit string IPv6 address's unused bits count (%d) is out of range (0-7).", str->bits_unused); } @@ -216,7 +216,7 @@ prefix6_decode(IPAddress_t const *str, struct ipv6_prefix *result) len = 8 * str->size - str->bits_unused; if (len < 0 || 128 < len) { - return pr_err("IPv6 prefix length (%d) is out of bounds (0-128).", + return pr_val_err("IPv6 prefix length (%d) is out of bounds (0-128).", len); } @@ -225,7 +225,7 @@ prefix6_decode(IPAddress_t const *str, struct ipv6_prefix *result) memset(&suffix, 0, sizeof(suffix)); ipv6_suffix_mask(result->len, &suffix); if (addr6_bitwise_and(&result->addr, &suffix)) { - return pr_err("IPv6 prefix '%s/%u' has enabled suffix bits.", + return pr_val_err("IPv6 prefix '%s/%u' has enabled suffix bits.", v6addr2str(&result->addr), result->len); } @@ -236,7 +236,7 @@ static int check_order4(struct ipv4_range *result) { if (ntohl(result->min.s_addr) > ntohl(result->max.s_addr)) { - return pr_err("The IPv4 range '%s-%s' is inverted.", + return pr_val_err("The IPv4 range '%s-%s' is inverted.", v4addr2str(&result->min), v4addr2str2(&result->max)); } @@ -263,7 +263,7 @@ check_encoding4(struct ipv4_range *range) if (((MIN & mask) != 0) || ((MAX & mask) == 0)) return 0; - return pr_err("IPAddressRange '%s-%s' is a range, but should have been encoded as a prefix.", + return pr_val_err("IPAddressRange '%s-%s' is a range, but should have been encoded as a prefix.", v4addr2str(&range->min), v4addr2str2(&range->max)); } @@ -304,7 +304,7 @@ check_order6(struct ipv6_range *result) min = addr6_get_quadrant(&result->min, quadrant); max = addr6_get_quadrant(&result->max, quadrant); if (min > max) { - return pr_err("The IPv6 range '%s-%s' is inverted.", + return pr_val_err("The IPv6 range '%s-%s' is inverted.", v6addr2str(&result->min), v6addr2str2(&result->max)); } else if (min < max) { @@ -318,7 +318,7 @@ check_order6(struct ipv6_range *result) static int pr_bad_encoding(struct ipv6_range *range) { - return pr_err("IPAddressRange %s-%s is a range, but should have been encoded as a prefix.", + return pr_val_err("IPAddressRange %s-%s is a range, but should have been encoded as a prefix.", v6addr2str(&range->min), v6addr2str2(&range->max)); } @@ -409,11 +409,11 @@ prefix4_parse(const char *str, struct ipv4_prefix *result) int error; if (str == NULL) - return pr_err("Can't parse NULL IPv4 prefix"); + return pr_val_err("Can't parse NULL IPv4 prefix"); error = str2addr4(str, &result->addr); if (error) - return pr_err("Invalid IPv4 prefix '%s'", str); + return pr_val_err("Invalid IPv4 prefix '%s'", str); return 0; } @@ -424,11 +424,11 @@ prefix6_parse(const char *str, struct ipv6_prefix *result) int error; if (str == NULL) - return pr_err("Can't parse NULL IPv6 prefix"); + return pr_val_err("Can't parse NULL IPv6 prefix"); error = str2addr6(str, &result->addr); if (error) - return pr_err("Invalid IPv6 prefix '%s'", str); + return pr_val_err("Invalid IPv6 prefix '%s'", str); return 0; } @@ -439,17 +439,17 @@ prefix_length_parse(const char *text, uint8_t *dst, uint8_t max_value) unsigned long len; if (text == NULL) - return pr_err("Can't decode NULL prefix length"); + return pr_val_err("Can't decode NULL prefix length"); errno = 0; len = strtoul(text, NULL, 10); if (errno) { - pr_errno(errno, "Invalid prefix length '%s'", text); + pr_val_errno(errno, "Invalid prefix length '%s'", text); return -EINVAL; } /* An underflow or overflow will be considered here */ if (max_value < len) - return pr_err("Prefix length (%lu) is out of range (0-%u).", + return pr_val_err("Prefix length (%lu) is out of range (0-%u).", len, max_value); *dst = (uint8_t) len; @@ -462,7 +462,7 @@ ipv4_prefix_validate(struct ipv4_prefix *prefix) char buffer[INET_ADDRSTRLEN]; if ((prefix->addr.s_addr & be32_suffix_mask(prefix->len)) != 0) - return pr_err("IPv4 prefix %s/%u has enabled suffix bits.", + return pr_val_err("IPv4 prefix %s/%u has enabled suffix bits.", addr2str4(&prefix->addr, buffer), prefix->len); return 0; @@ -480,7 +480,7 @@ ipv6_prefix_validate(struct ipv6_prefix *prefix) for (i = 0; i < 16; i++) if (prefix->addr.s6_addr[i] & suffix.s6_addr[i]) - return pr_err("IPv6 prefix %s/%u has enabled suffix bits.", + return pr_val_err("IPv6 prefix %s/%u has enabled suffix bits.", addr2str6(&prefix->addr, buffer), prefix->len); return 0; diff --git a/src/algorithm.c b/src/algorithm.c index 35529ffa..69f7aae4 100644 --- a/src/algorithm.c +++ b/src/algorithm.c @@ -27,7 +27,7 @@ validate_certificate_signature_algorithm(int nid, char const *what) if (nid == NID_sha256WithRSAEncryption) return 0; - return pr_err("%s's signature algorithm is NID '%d', not RSA+SHA256.", + return pr_val_err("%s's signature algorithm is NID '%d', not RSA+SHA256.", what, nid); } @@ -48,7 +48,7 @@ validate_certificate_public_key_algorithm(X509_ALGOR *pa) if (nid == NID_rsaEncryption) return 0; - return pr_err("Certificate's public key format is NID '%s', not rsaEncryption.", + return pr_val_err("Certificate's public key format is NID '%s', not rsaEncryption.", OBJ_nid2sn(nid)); } @@ -64,18 +64,18 @@ validate_certificate_public_key_algorithm_bgpsec(X509_ALGOR *pa) /* Validate algorithm and parameters (RFC 8608#section-3.1.1) */ if (nid != NID_X9_62_id_ecPublicKey) - return pr_err("Certificate's public key format is NID '%s', not id-ecPublicKey.", + return pr_val_err("Certificate's public key format is NID '%s', not id-ecPublicKey.", OBJ_nid2sn(nid)); if (pa->parameter == NULL) - return pr_err("Certificate's public key algorithm MUST have parameters"); + return pr_val_err("Certificate's public key algorithm MUST have parameters"); if (pa->parameter->type != V_ASN1_OBJECT) - return pr_err("Certificate's public key parameter type isn't valid"); + return pr_val_err("Certificate's public key parameter type isn't valid"); nid = OBJ_obj2nid((ASN1_OBJECT *)pa->parameter->value.object); if (nid != NID_X9_62_prime256v1) - return pr_err("Certificate's public key format is NID '%s', not secp256r1 (a.k.a prime256v1).", + return pr_val_err("Certificate's public key format is NID '%s', not secp256r1 (a.k.a prime256v1).", OBJ_nid2sn(nid)); return 0; @@ -87,7 +87,7 @@ validate_cms_hashing_algorithm(AlgorithmIdentifier_t *id, char const *what) int error; if (id == NULL) - return pr_err("The hash algorithm of the '%s' is absent", what); + return pr_val_err("The hash algorithm of the '%s' is absent", what); error = validate_cms_hashing_algorithm_oid(&id->algorithm, what); if (error) @@ -111,7 +111,7 @@ validate_cms_hashing_algorithm(AlgorithmIdentifier_t *id, char const *what) ? incidence(INID_HASHALG_HAS_PARAMS, "The hash algorithm of the '%s' has a NULL object as parameters", what) - : pr_err("The hash algorithm of the '%s' has parameters", + : pr_val_err("The hash algorithm of the '%s' has parameters", what); } @@ -134,7 +134,7 @@ validate_cms_hashing_algorithm_oid(OBJECT_IDENTIFIER_t *oid, char const *what) }; if (oid == NULL) - return pr_err("The hash algorithm of the '%s' is absent", what); + return pr_val_err("The hash algorithm of the '%s' is absent", what); if (oid->size != sizeof(sha256)) goto incorrect_oid; @@ -144,7 +144,7 @@ validate_cms_hashing_algorithm_oid(OBJECT_IDENTIFIER_t *oid, char const *what) return 0; incorrect_oid: - return pr_err("The hash algorithm of the '%s' is not SHA256.", what); + return pr_val_err("The hash algorithm of the '%s' is not SHA256.", what); } int @@ -164,7 +164,7 @@ validate_cms_signature_algorithm(AlgorithmIdentifier_t *id) uint8_t last; if (id == NULL) - return pr_err("The signature algorithm is absent."); + return pr_val_err("The signature algorithm is absent."); /* * rsaEncryption is { pkcs-1 1 }, and sha256WithRSAEncryption is @@ -222,10 +222,10 @@ validate_cms_signature_algorithm(AlgorithmIdentifier_t *id) * accept both. */ if (id->parameters != NULL && !is_asn1_null(id->parameters)) - return pr_err("The signature algorithm has parameters."); + return pr_val_err("The signature algorithm has parameters."); return 0; incorrect_oid: - return pr_err("The Signature algorithm is not RSA nor RSA+SHA256."); + return pr_val_err("The Signature algorithm is not RSA nor RSA+SHA256."); } diff --git a/src/asn1/content_info.c b/src/asn1/content_info.c index 4cf50223..8c122551 100644 --- a/src/asn1/content_info.c +++ b/src/asn1/content_info.c @@ -21,7 +21,7 @@ validate(struct ContentInfo *info) return error; if (!ARCS_EQUAL_OIDS(&arcs, oid_sdata)) - error = pr_err("Incorrect content-type."); + error = pr_val_err("Incorrect content-type."); free_arcs(&arcs); return error; diff --git a/src/asn1/decode.c b/src/asn1/decode.c index bb2c5c37..f4703d1d 100644 --- a/src/asn1/decode.c +++ b/src/asn1/decode.c @@ -28,7 +28,7 @@ validate(asn_TYPE_descriptor_t const *descriptor, void *result, bool log) &error_msg_size); if (error == -1) return COND_LOG(log, - pr_err("Error validating ASN.1 object: %s", error_msg)); + pr_val_err("Error validating ASN.1 object: %s", error_msg)); return 0; } @@ -39,7 +39,7 @@ der_coder(const void *buf, size_t size, void *app_key) struct ber_data *data = app_key; if (data->consumed + size > data->src_size) { - pr_debug("DER encoding will consume more bytes than expected (expected %lu, will get %lu)", + pr_val_debug("DER encoding will consume more bytes than expected (expected %lu, will get %lu)", data->consumed + size, data->src_size); return -1; } @@ -72,7 +72,7 @@ validate_der(size_t ber_consumed, asn_TYPE_descriptor_t const *descriptor, "'%s' isn't DER encoded", eval.failed_type->name); if (ber_consumed != eval.encoded) { - pr_debug("DER encoding consumed less bytes than expected (expected %lu, got %lu)", + pr_val_debug("DER encoding consumed less bytes than expected (expected %lu, got %lu)", ber_consumed, eval.encoded); return incidence(INID_OBJ_NOT_DER, "'%s' isn't DER encoded", descriptor->name); @@ -100,7 +100,7 @@ asn1_decode(const void *buffer, size_t buffer_size, ASN_STRUCT_FREE(*descriptor, *result); /* We expect the data to be complete; RC_WMORE is an error. */ return COND_LOG(log, - pr_err("Error '%u' decoding ASN.1 object around byte %zu", + pr_val_err("Error '%u' decoding ASN.1 object around byte %zu", rval.code, rval.consumed)); } diff --git a/src/asn1/oid.c b/src/asn1/oid.c index d592f652..d7018d31 100644 --- a/src/asn1/oid.c +++ b/src/asn1/oid.c @@ -33,7 +33,7 @@ oid2arcs(OBJECT_IDENTIFIER_t *oid, struct oid_arcs *result) count = OBJECT_IDENTIFIER_get_arcs(oid, result->arcs, MAX_ARCS); if (count < 0) { - pr_err("OBJECT_IDENTIFIER_get_arcs() returned %zd.", count); + pr_val_err("OBJECT_IDENTIFIER_get_arcs() returned %zd.", count); free(result->arcs); return count; } @@ -51,7 +51,7 @@ oid2arcs(OBJECT_IDENTIFIER_t *oid, struct oid_arcs *result) count2 = OBJECT_IDENTIFIER_get_arcs(oid, result->arcs, count); if (count != count2) { - pr_err("OBJECT_IDENTIFIER_get_arcs() returned %zd. (expected %zd)", + pr_val_err("OBJECT_IDENTIFIER_get_arcs() returned %zd. (expected %zd)", count2, count); free(result->arcs); return -EINVAL; diff --git a/src/asn1/signed_data.c b/src/asn1/signed_data.c index 1305d950..16e36b00 100644 --- a/src/asn1/signed_data.c +++ b/src/asn1/signed_data.c @@ -51,12 +51,12 @@ get_sid(struct SignerInfo *sinfo, OCTET_STRING_t **result) *result = &sinfo->sid.choice.subjectKeyIdentifier; return 0; case SignerIdentifier_PR_issuerAndSerialNumber: - return pr_err("Signer Info's sid is an IssuerAndSerialNumber, not a SubjectKeyIdentifier."); + return pr_val_err("Signer Info's sid is an IssuerAndSerialNumber, not a SubjectKeyIdentifier."); case SignerIdentifier_PR_NOTHING: break; } - return pr_err("Signer Info's sid is not a SubjectKeyIdentifier."); + return pr_val_err("Signer Info's sid is not a SubjectKeyIdentifier."); } static int @@ -73,7 +73,7 @@ handle_sdata_certificate(ANY_t *cert_encoded, struct signed_object_args *args, * to a tree leaf. Loops aren't possible. */ - pr_debug("EE Certificate (embedded) {"); + pr_val_debug("EE Certificate (embedded) {"); /* * "If the call is successful *in is incremented to the byte following @@ -86,7 +86,7 @@ handle_sdata_certificate(ANY_t *cert_encoded, struct signed_object_args *args, cert = d2i_X509(NULL, &tmp, cert_encoded->size); if (cert == NULL) { - error = crypto_err("Signed object's 'certificate' element does not decode into a Certificate"); + error = val_crypto_err("Signed object's 'certificate' element does not decode into a Certificate"); goto end1; } @@ -117,7 +117,7 @@ handle_sdata_certificate(ANY_t *cert_encoded, struct signed_object_args *args, end2: X509_free(cert); end1: - pr_debug("}"); + pr_val_debug("}"); return error; } @@ -137,7 +137,7 @@ validate_content_type_attribute(CMSAttributeValue_t *value, eContentType = &eci->eContentType; if (!oid_equal(attrValues, eContentType)) - error = pr_err("The attrValues for the content-type attribute does not match the eContentType in the EncapsulatedContentInfo."); + error = pr_val_err("The attrValues for the content-type attribute does not match the eContentType in the EncapsulatedContentInfo."); ASN_STRUCT_FREE(asn_DEF_OBJECT_IDENTIFIER, attrValues); return error; @@ -151,7 +151,7 @@ validate_message_digest_attribute(CMSAttributeValue_t *value, int error; if (eci->eContent == NULL) - return pr_err("There's no content being signed."); + return pr_val_err("There's no content being signed."); error = asn1_decode_any(value, &asn_DEF_MessageDigest, (void **) &digest, true, false); @@ -160,7 +160,7 @@ validate_message_digest_attribute(CMSAttributeValue_t *value, error = hash_validate_octet_string("sha256", digest, eci->eContent); if (error) - pr_err("The content's hash does not match the Message-Digest Attribute."); + pr_val_err("The content's hash does not match the Message-Digest Attribute."); ASN_STRUCT_FREE(asn_DEF_MessageDigest, digest); return error; @@ -180,18 +180,18 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) int error; if (sinfo->signedAttrs == NULL) - return pr_err("The SignerInfo's signedAttrs field is NULL."); + return pr_val_err("The SignerInfo's signedAttrs field is NULL."); for (i = 0; i < sinfo->signedAttrs->list.count; i++) { attr = sinfo->signedAttrs->list.array[i]; if (attr == NULL) { - pr_err("SignedAttrs array element %u is NULL.", i); + pr_val_err("SignedAttrs array element %u is NULL.", i); continue; } attrs = &attr->attrValues; if (attrs->list.count != 1) { - return pr_err("signedAttrs's attribute set size (%d) is different than 1", + return pr_val_err("signedAttrs's attribute set size (%d) is different than 1", attr->attrValues.list.count); } if (attrs->list.array == NULL || attrs->list.array[0] == NULL) @@ -203,7 +203,7 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) if (ARCS_EQUAL_OIDS(&attrType, oid_cta)) { if (content_type_found) { - pr_err("Multiple ContentTypes found."); + pr_val_err("Multiple ContentTypes found."); goto illegal_attrType; } error = validate_content_type_attribute( @@ -212,7 +212,7 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) } else if (ARCS_EQUAL_OIDS(&attrType, oid_mda)) { if (message_digest_found) { - pr_err("Multiple MessageDigests found."); + pr_val_err("Multiple MessageDigests found."); goto illegal_attrType; } error = validate_message_digest_attribute( @@ -221,7 +221,7 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) } else if (ARCS_EQUAL_OIDS(&attrType, oid_sta)) { if (signing_time_found) { - pr_err("Multiple SigningTimes found."); + pr_val_err("Multiple SigningTimes found."); goto illegal_attrType; } error = 0; /* No validations needed for now. */ @@ -229,7 +229,7 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) } else if (ARCS_EQUAL_OIDS(&attrType, oid_bsta)) { if (binary_signing_time_found) { - pr_err("Multiple BinarySigningTimes found."); + pr_val_err("Multiple BinarySigningTimes found."); goto illegal_attrType; } error = 0; /* No validations needed for now. */ @@ -237,7 +237,7 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) } else { /* rfc6488#section-3.1.g */ - pr_err("Illegal attrType OID in SignerInfo."); + pr_val_err("Illegal attrType OID in SignerInfo."); goto illegal_attrType; } @@ -249,9 +249,9 @@ validate_signed_attrs(struct SignerInfo *sinfo, EncapsulatedContentInfo_t *eci) /* rfc6488#section-3.1.f */ if (!content_type_found) - return pr_err("SignerInfo lacks a ContentType attribute."); + return pr_val_err("SignerInfo lacks a ContentType attribute."); if (!message_digest_found) - return pr_err("SignerInfo lacks a MessageDigest attribute."); + return pr_val_err("SignerInfo lacks a MessageDigest attribute."); return 0; @@ -271,7 +271,7 @@ validate(struct SignedData *sdata, ANY_t *sdata_encoded, /* rfc6488#section-2.1 */ if (sdata->signerInfos.list.count != 1) { - return pr_err("The SignedData's SignerInfo set is supposed to have only one element. (%d given.)", + return pr_val_err("The SignedData's SignerInfo set is supposed to have only one element. (%d given.)", sdata->signerInfos.list.count); } @@ -280,18 +280,18 @@ validate(struct SignedData *sdata, ANY_t *sdata_encoded, error = asn_INTEGER2ulong(&sdata->version, &version); if (error) { if (errno) - pr_errno(errno, "Error converting SignedData version"); - return pr_err("The SignedData version isn't a valid unsigned long"); + pr_val_errno(errno, "Error converting SignedData version"); + return pr_val_err("The SignedData version isn't a valid unsigned long"); } if (version != 3) { - return pr_err("The SignedData version is only allowed to be 3. (Was %lu.)", + return pr_val_err("The SignedData version is only allowed to be 3. (Was %lu.)", version); } /* rfc6488#section-2.1.2 */ /* rfc6488#section-3.1.j 1/2 */ if (sdata->digestAlgorithms.list.count != 1) { - return pr_err("The SignedData's digestAlgorithms set is supposed to have only one element. (%d given.)", + return pr_val_err("The SignedData's digestAlgorithms set is supposed to have only one element. (%d given.)", sdata->digestAlgorithms.list.count); } @@ -319,22 +319,22 @@ validate(struct SignedData *sdata, ANY_t *sdata_encoded, /* rfc6488#section-2.1.5 */ /* rfc6488#section-3.1.d */ if (sdata->crls != NULL && sdata->crls->list.count > 0) - return pr_err("The SignedData contains at least one CRL."); + return pr_val_err("The SignedData contains at least one CRL."); /* rfc6488#section-2.1.6.1 */ /* rfc6488#section-3.1.e */ sinfo = sdata->signerInfos.list.array[0]; if (sinfo == NULL) - return pr_err("The SignerInfo object is NULL."); + return pr_val_err("The SignerInfo object is NULL."); error = asn_INTEGER2ulong(&sinfo->version, &version); if (error) { if (errno) - pr_errno(errno, "Error converting SignerInfo version"); - return pr_err("The SignerInfo version isn't a valid unsigned long"); + pr_val_errno(errno, "Error converting SignerInfo version"); + return pr_val_err("The SignerInfo version isn't a valid unsigned long"); } if (version != 3) { - return pr_err("The SignerInfo version is only allowed to be 3. (Was %lu.)", + return pr_val_err("The SignerInfo version is only allowed to be 3. (Was %lu.)", version); } @@ -369,17 +369,17 @@ validate(struct SignedData *sdata, ANY_t *sdata_encoded, /* rfc6488#section-2.1.6.7 */ /* rfc6488#section-3.1.i */ if (sinfo->unsignedAttrs != NULL && sinfo->unsignedAttrs->list.count > 0) - return pr_err("SignerInfo has at least one unsignedAttr."); + return pr_val_err("SignerInfo has at least one unsignedAttr."); /* rfc6488#section-2.1.4 */ /* rfc6488#section-3.1.c 1/2 */ /* rfc6488#section-3.2 */ /* rfc6488#section-3.3 */ if (sdata->certificates == NULL) - return pr_err("The SignedData does not contain certificates."); + return pr_val_err("The SignedData does not contain certificates."); if (sdata->certificates->list.count != 1) { - return pr_err("The SignedData contains %d certificates, one expected.", + return pr_val_err("The SignedData contains %d certificates, one expected.", sdata->certificates->list.count); } diff --git a/src/cert_stack.c b/src/cert_stack.c index a9198a46..b659dc00 100644 --- a/src/cert_stack.c +++ b/src/cert_stack.c @@ -129,7 +129,7 @@ certstack_create(struct cert_stack **result) stack->x509s = sk_X509_new_null(); if (stack->x509s == NULL) { free(stack); - return crypto_err("sk_X509_new_null() returned NULL"); + return val_crypto_err("sk_X509_new_null() returned NULL"); } SLIST_INIT(&stack->defers); @@ -194,9 +194,9 @@ certstack_destroy(struct cert_stack *stack) defer_destroy(post); stack_size++; } - pr_debug("Deleted %u deferred certificates.", stack_size); + pr_val_debug("Deleted %u deferred certificates.", stack_size); - pr_debug("Deleting %d stacked x509s.", sk_X509_num(stack->x509s)); + pr_val_debug("Deleting %d stacked x509s.", sk_X509_num(stack->x509s)); sk_X509_pop_free(stack->x509s, X509_free); stack_size = 0; @@ -206,7 +206,7 @@ certstack_destroy(struct cert_stack *stack) meta_destroy(meta); stack_size++; } - pr_debug("Deleted %u metadatas.", stack_size); + pr_val_debug("Deleted %u metadatas.", stack_size); stack_size = 0; while (!SLIST_EMPTY(&stack->levels)) { @@ -215,7 +215,7 @@ certstack_destroy(struct cert_stack *stack) free(level); stack_size++; } - pr_debug("Deleted %u stacked levels.", stack_size); + pr_val_debug("Deleted %u stacked levels.", stack_size); free(stack); } @@ -350,7 +350,7 @@ x509stack_push(struct cert_stack *stack, struct rpki_uri *uri, X509 *x509, * part is already handled in certificate_get_resources(). */ if (type == TA && resources_empty(meta->resources)) { - error = pr_err("Trust Anchor certificate does not define any number resources."); + error = pr_val_err("Trust Anchor certificate does not define any number resources."); goto end5; } @@ -363,7 +363,7 @@ x509stack_push(struct cert_stack *stack, struct rpki_uri *uri, X509 *x509, ok = sk_X509_push(stack->x509s, x509); if (ok <= 0) { - error = crypto_err( + error = val_crypto_err( "Could not add certificate to trusted stack: %d", ok); goto end5; } @@ -498,7 +498,7 @@ x509stack_store_serial(struct cert_stack *stack, BIGNUM *number) ARRAYLIST_FOREACH(&meta->serials, cursor, i) { if (BN_cmp(cursor->number, number) == 0) { BN2string(number, &string); - pr_warn("Serial number '%s' is not unique. (Also found in '%s'.)", + pr_val_warn("Serial number '%s' is not unique. (Also found in '%s'.)", string, cursor->file); BN_free(number); free(string); @@ -591,7 +591,7 @@ x509stack_store_subject(struct cert_stack *stack, struct rfc5280_name *subject, continue; char const *serial = x509_name_serialNumber(subject); - pr_warn("Subject name '%s%s%s' is not unique. (Also found in '%s'.)", + pr_val_warn("Subject name '%s%s%s' is not unique. (Also found in '%s'.)", x509_name_commonName(subject), (serial != NULL) ? "/" : "", (serial != NULL) ? serial : "", diff --git a/src/certificate_refs.c b/src/certificate_refs.c index 134d0d92..7fb617cf 100644 --- a/src/certificate_refs.c +++ b/src/certificate_refs.c @@ -33,7 +33,7 @@ validate_cdp(struct certificate_refs *refs, struct rpp const *pp) pr_crit("Manifest's CRL was not recorded."); if (strcmp(refs->crldp, uri_get_global(pp_crl)) != 0) { - return pr_err("Certificate's CRL Distribution Point ('%s') does not match manifest's CRL ('%s').", + return pr_val_err("Certificate's CRL Distribution Point ('%s') does not match manifest's CRL ('%s').", refs->crldp, uri_get_global(pp_crl)); } @@ -48,9 +48,9 @@ validate_signedObject(struct certificate_refs *refs, pr_crit("Certificate's signedObject was not recorded."); if (!uri_equals(refs->signedObject, signedObject_uri)) { - return pr_err("Certificate's signedObject ('%s') does not match the URI of its own signed object (%s).", - uri_get_printable(refs->signedObject), - uri_get_printable(signedObject_uri)); + return pr_val_err("Certificate's signedObject ('%s') does not match the URI of its own signed object (%s).", + uri_val_get_printable(refs->signedObject), + uri_val_get_printable(signedObject_uri)); } return 0; @@ -77,7 +77,7 @@ refs_validate_ca(struct certificate_refs *refs, struct rpp const *pp) if (refs->signedObject != NULL) pr_crit("CA summary has a signedObject ('%s').", - uri_get_printable(refs->signedObject)); + uri_op_get_printable(refs->signedObject)); return 0; } diff --git a/src/clients.c b/src/clients.c index d0975935..7288ca2b 100644 --- a/src/clients.c +++ b/src/clients.c @@ -27,7 +27,7 @@ clients_db_init(void) error = pthread_rwlock_init(&lock, NULL); if (error) - return pr_errno(error, "pthread_rwlock_init() errored"); + return pr_op_errno(error, "pthread_rwlock_init() errored"); return 0; } @@ -72,7 +72,7 @@ clients_add(int fd, struct sockaddr_storage addr, pthread_t tid) if (errno) { rwlock_unlock(&lock); free(new_client); - return -pr_errno(errno, "Client couldn't be stored"); + return -pr_op_errno(errno, "Client couldn't be stored"); } if (old_client != NULL) free(old_client); diff --git a/src/common.c b/src/common.c index bf25d89c..7215b8dd 100644 --- a/src/common.c +++ b/src/common.c @@ -23,7 +23,7 @@ rwlock_read_lock(pthread_rwlock_t *lock) case 0: return error; case EAGAIN: - pr_err("There are too many threads; I can't modify the database."); + pr_op_err("There are too many threads; I can't modify the database."); return error; } @@ -34,7 +34,7 @@ rwlock_read_lock(pthread_rwlock_t *lock) * pthread_rwlock_rdlock() failing like this is akin to `if` failing; * we're screwed badly, so let's just pull the trigger. */ - pr_err("pthread_rwlock_rdlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", + pr_op_err("pthread_rwlock_rdlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", error); exit(error); } @@ -50,7 +50,7 @@ rwlock_write_lock(pthread_rwlock_t *lock) */ error = pthread_rwlock_wrlock(lock); if (error) { - pr_err("pthread_rwlock_wrlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", + pr_op_err("pthread_rwlock_wrlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", error); exit(error); } @@ -67,7 +67,7 @@ rwlock_unlock(pthread_rwlock_t *lock) */ error = pthread_rwlock_unlock(lock); if (error) { - pr_err("pthread_rwlock_unlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", + pr_op_err("pthread_rwlock_unlock() returned error code %d. This is too critical for a graceful recovery; I must die now.", error); exit(error); } @@ -108,18 +108,18 @@ process_file(char const *dir_name, char const *file_name, char const *file_ext, /* Get the full file path */ tmp = strdup(dir_name); if (tmp == NULL) - return -pr_errno(errno, "Couldn't create temporal char"); + return -pr_op_errno(errno, "Couldn't create temporal char"); tmp = realloc(tmp, strlen(tmp) + 1 + strlen(file_name) + 1); if (tmp == NULL) - return -pr_errno(errno, "Couldn't reallocate temporal char"); + return -pr_op_errno(errno, "Couldn't reallocate temporal char"); strcat(tmp, "/"); strcat(tmp, file_name); fullpath = realpath(tmp, NULL); if (fullpath == NULL) { free(tmp); - return -pr_errno(errno, + return -pr_op_errno(errno, "Error getting real path for file '%s' at dir '%s'", dir_name, file_name); } @@ -140,7 +140,7 @@ process_dir_files(char const *location, char const *file_ext, dir_loc = opendir(location); if (dir_loc == NULL) { - error = -pr_errno(errno, "Couldn't open dir %s", location); + error = -pr_op_errno(errno, "Couldn't open dir %s", location); goto end; } @@ -150,17 +150,17 @@ process_dir_files(char const *location, char const *file_ext, error = process_file(location, dir_ent->d_name, file_ext, &found, cb, arg); if (error) { - pr_err("The error was at file %s", dir_ent->d_name); + pr_op_err("The error was at file %s", dir_ent->d_name); goto close_dir; } errno = 0; } if (errno) { - pr_err("Error reading dir %s", location); + pr_op_err("Error reading dir %s", location); error = -errno; } if (!error && found == 0) - pr_warn("Location '%s' doesn't have files with extension '%s'", + pr_op_warn("Location '%s' doesn't have files with extension '%s'", location, file_ext); close_dir: closedir(dir_loc); @@ -177,7 +177,7 @@ process_file_or_dir(char const *location, char const *file_ext, error = stat(location, &attr); if (error) - return pr_errno(errno, "Error reading path '%s'", location); + return pr_op_errno(errno, "Error reading path '%s'", location); if (S_ISDIR(attr.st_mode) == 0) return cb(location, arg); @@ -187,7 +187,8 @@ process_file_or_dir(char const *location, char const *file_ext, bool -valid_file_or_dir(char const *location, bool check_file, bool check_dir) +valid_file_or_dir(char const *location, bool check_file, bool check_dir, + int (*cb) (int error, const char *format, ...)) { FILE *file; struct stat attr; @@ -200,13 +201,13 @@ valid_file_or_dir(char const *location, bool check_file, bool check_dir) result = false; file = fopen(location, "rb"); if (file == NULL) { - pr_errno(errno, "Could not open location '%s'", + cb(errno, "Could not open location '%s'", location); return false; } if (fstat(fileno(file), &attr) == -1) { - pr_errno(errno, "fstat(%s) failed", location); + cb(errno, "fstat(%s) failed", location); goto end; } @@ -215,13 +216,13 @@ valid_file_or_dir(char const *location, bool check_file, bool check_dir) result = is_file || is_dir; if (!result) - pr_err("'%s' does not seem to be a %s", location, + pr_op_err("'%s' does not seem to be a %s", location, (check_file && check_dir) ? "file or directory" : (check_file) ? "file" : "directory"); end: if (fclose(file) == -1) - pr_errno(errno, "fclose() failed"); + cb(errno, "fclose() failed"); return result; } @@ -257,14 +258,14 @@ dir_exists(char const *path, bool *result) if (stat(path, &_stat) == 0) { if (!S_ISDIR(_stat.st_mode)) { - return pr_err("Path '%s' exists and is not a directory.", + return pr_op_err("Path '%s' exists and is not a directory.", path); } *result = true; } else if (errno == ENOENT) { *result = false; } else { - return pr_errno(errno, "stat() failed"); + return pr_op_errno(errno, "stat() failed"); } *last_slash = '/'; @@ -279,7 +280,7 @@ create_dir(char *path) error = mkdir(path, 0777); if (error && errno != EEXIST) - return pr_errno(errno, "Error while making directory '%s'", + return pr_op_errno(errno, "Error while making directory '%s'", path); return 0; @@ -331,7 +332,7 @@ remove_file(char const *path) errno = 0; error = remove(path); if (error) - return pr_errno(errno, "Couldn't delete %s", path); + return pr_op_errno(errno, "Couldn't delete %s", path); return 0; } @@ -389,7 +390,7 @@ delete_dir_recursive_bottom_up(char const *path) if (errno == ENOTEMPTY || errno == EEXIST) break; - error = pr_errno(errno, "Couldn't delete dir %s", work_loc); + error = pr_op_errno(errno, "Couldn't delete dir %s", work_loc); goto release_str; } while (true); @@ -407,7 +408,7 @@ get_current_time(time_t *result) now = time(NULL); if (now == ((time_t) -1)) - return pr_errno(errno, "Error getting the current time"); + return pr_val_errno(errno, "Error getting the current time"); *result = now; return 0; diff --git a/src/common.h b/src/common.h index 0606651f..a5392e3a 100644 --- a/src/common.h +++ b/src/common.h @@ -53,7 +53,9 @@ void close_thread(pthread_t thread, char const *); typedef int (*process_file_cb)(char const *, void *); int process_file_or_dir(char const *, char const *, process_file_cb, void *); -bool valid_file_or_dir(char const *, bool, bool); + +typedef int (*pr_errno_cb)(int, const char *, ...); +bool valid_file_or_dir(char const *, bool, bool, pr_errno_cb); char const *addr2str4(struct in_addr const *, char *); char const *addr2str6(struct in6_addr const *, char *); diff --git a/src/config.c b/src/config.c index e1396038..a4f1854d 100644 --- a/src/config.c +++ b/src/config.c @@ -131,6 +131,10 @@ struct rpki_config { } http; struct { + /** Enables operation logs **/ + bool enabled; + /** Prefix to identify operation logs **/ + char *prefix; /** Print ANSI color codes? */ bool color; /** Format in which file names will be printed. */ @@ -139,8 +143,27 @@ struct rpki_config { uint8_t level; /* Log output */ enum log_output output; + /** facility for syslog if output is syslog **/ + uint32_t facility; } log; + struct { + /** Enables validation Logs **/ + bool enabled; + /** Prefix to identify validation logs **/ + char *prefix; + /** Print ANSI color codes? */ + bool color; + /** Format in which file names will be printed. */ + enum filename_format filename_format; + /* Log level */ + uint8_t level; + /* Log output */ + enum log_output output; + /** facilities for syslog if output is syslog **/ + uint32_t facility; + } validation_log; + struct { /** File where the validated ROAs will be stored */ char *roa; @@ -503,29 +526,94 @@ static const struct option_field options[] = { /* Logging fields */ { - .id = 'c', - .name = "log.color-output", + .id = 4000, + .name = "log.enabled", .type = >_bool, - .offset = offsetof(struct rpki_config, log.color), - .doc = "Print ANSI color codes", + .offset = offsetof(struct rpki_config, log.enabled), + .doc = "Enables operation logs", }, { - .id = 4000, + .id = 4001, + .name = "log.output", + .type = >_log_output, + .offset = offsetof(struct rpki_config, log.output), + .doc = "Output where operation log messages will be printed", + }, { + .id = 4002, + .name = "log.level", + .type = >_log_level, + .offset = offsetof(struct rpki_config, log.level), + .doc = "Log level to print message of equal or higher importance", + }, { + .id = 4003, + .name = "log.prefix", + .type = >_string, + .offset = offsetof(struct rpki_config, log.prefix), + .doc = "Prefix to identify operation logs", + .arg_doc = "", + }, { + .id = 4004, + .name = "log.facility", + .type = >_log_facility, + .offset = offsetof(struct rpki_config, log.facility), + .doc = "Facility for syslog if output is syslog", + }, { + .id = 4005, .name = "log.file-name-format", .type = >_filename_format, .offset = offsetof(struct rpki_config, log.filename_format), .doc = "File name variant to print during debug/error messages", }, { - .id = 4001, - .name = "log.level", + .id = 'c', + .name = "log.color-output", + .type = >_bool, + .offset = offsetof(struct rpki_config, log.color), + .doc = "Print ANSI color codes", + }, + + { + .id = 4010, + .name = "validation-log.enabled", + .type = >_bool, + .offset = offsetof(struct rpki_config, validation_log.enabled), + .doc = "Enables validation logs", + }, { + .id = 4011, + .name = "validation-log.output", + .type = >_log_output, + .offset = offsetof(struct rpki_config, validation_log.output), + .doc = "Output where validation log messages will be printed", + }, { + .id = 4012, + .name = "validation-log.level", .type = >_log_level, - .offset = offsetof(struct rpki_config, log.level), + .offset = offsetof(struct rpki_config, validation_log.level), .doc = "Log level to print message of equal or higher importance", }, { - .id = 4002, - .name = "log.output", - .type = >_log_output, - .offset = offsetof(struct rpki_config, log.output), - .doc = "Output where log messages will be printed", + .id = 4013, + .name = "validation-log.prefix", + .type = >_string, + .offset = offsetof(struct rpki_config, validation_log.prefix), + .doc = "Prefix to identify operation logs", + .arg_doc = "", + }, { + .id = 4014, + .name = "validation-log.facility", + .type = >_log_facility, + .offset = offsetof(struct rpki_config, validation_log.facility), + .doc = "Facility for syslog if output is syslog", + }, { + .id = 4015, + .name = "validation-log.file-name-format", + .type = >_filename_format, + .offset = offsetof(struct rpki_config, + validation_log.filename_format), + .doc = "File name variant to print during debug/error messages", + }, { + .id = 4016, + .name = "validation-log.color-output", + .type = >_bool, + .offset = offsetof(struct rpki_config, validation_log.color), + .doc = "Print ANSI color codes", }, /* Incidences */ @@ -691,13 +779,13 @@ print_config(void) { struct option_field const *opt; - pr_info("Configuration {"); + pr_op_info("Configuration {"); FOREACH_OPTION(options, opt, 0xFFFF) if (is_rpki_config_field(opt) && opt->type->print != NULL) opt->type->print(opt, get_rpki_config_field(opt)); - pr_info("}"); + pr_op_info("}"); } static int @@ -796,6 +884,26 @@ set_default_values(void) rpki_config.log.level = LOG_WARNING; rpki_config.log.output = CONSOLE; + rpki_config.log.enabled = true; + rpki_config.log.output = CONSOLE; + rpki_config.log.level = LOG_WARNING; + rpki_config.log.color = false; + rpki_config.log.filename_format = FNF_GLOBAL; + rpki_config.log.facility = LOG_DAEMON; + rpki_config.log.prefix = NULL; + + rpki_config.validation_log.enabled = false; + rpki_config.validation_log.output = CONSOLE; + rpki_config.validation_log.level = LOG_WARNING; + rpki_config.validation_log.color = false; + rpki_config.validation_log.filename_format = FNF_GLOBAL; + rpki_config.validation_log.facility = LOG_DAEMON; + rpki_config.validation_log.prefix = strdup("Validation"); + if (rpki_config.validation_log.prefix == NULL) { + error = pr_enomem(); + goto revert_validation_log_prefix; + } + rpki_config.output.roa = NULL; rpki_config.output.bgpsec = NULL; @@ -803,6 +911,8 @@ set_default_values(void) rpki_config.stale_repository_period = 43200; /* 12 hours */ return 0; +revert_validation_log_prefix: + free(rpki_config.http.user_agent); revert_flat_array: string_array_cleanup(&rpki_config.rsync.args.flat); revert_recursive_array: @@ -826,28 +936,28 @@ static int validate_config(void) { if (rpki_config.tal == NULL) - return pr_err("The TAL file/directory (--tal) is mandatory."); + return pr_op_err("The TAL file/directory (--tal) is mandatory."); - if (!valid_file_or_dir(rpki_config.tal, true, true)) - return pr_err("Invalid TAL file/directory."); + if (!valid_file_or_dir(rpki_config.tal, true, true, pr_op_errno)) + return pr_op_err("Invalid TAL file/directory."); if (rpki_config.server.interval.expire < rpki_config.server.interval.refresh || rpki_config.server.interval.expire < rpki_config.server.interval.retry) - return pr_err("Expire interval must be greater than refresh and retry intervals"); + return pr_op_err("Expire interval must be greater than refresh and retry intervals"); if (rpki_config.output.roa != NULL && !valid_output_file(rpki_config.output.roa)) - return pr_err("Invalid output.roa file."); + return pr_op_err("Invalid output.roa file."); if (rpki_config.output.bgpsec != NULL && !valid_output_file(rpki_config.output.bgpsec)) - return pr_err("Invalid output.bgpsec file."); + return pr_op_err("Invalid output.bgpsec file."); if (rpki_config.slurm != NULL && - !valid_file_or_dir(rpki_config.slurm, true, true)) - return pr_err("Invalid slurm location."); + !valid_file_or_dir(rpki_config.slurm, true, true, pr_op_errno)) + return pr_op_err("Invalid slurm location."); /* FIXME (later) Remove when sync-strategy is fully deprecated */ if (!rpki_config.rsync.enabled) @@ -906,7 +1016,7 @@ handle_opt(int opt) } } - pr_err("Unrecognized option: %d", opt); + pr_op_err("Unrecognized option: %d", opt); return -ESRCH; } @@ -943,7 +1053,7 @@ handle_flags_config(int argc, char **argv) * This program does not have unflagged payload. */ if (optind < argc) { - error = pr_err("I don't know what '%s' is.", argv[optind]); + error = pr_op_err("I don't know what '%s' is.", argv[optind]); goto end; } @@ -1054,29 +1164,89 @@ config_get_max_cert_depth(void) } bool -config_get_color_output(void) +config_get_op_log_enabled(void) +{ + return rpki_config.log.enabled; +} + +char const * +config_get_op_log_prefix(void) +{ + return rpki_config.log.prefix; +} + +bool +config_get_op_log_color_output(void) { return rpki_config.log.color; } enum filename_format -config_get_filename_format(void) +config_get_op_log_filename_format(void) { return rpki_config.log.filename_format; } uint8_t -config_get_log_level(void) +config_get_op_log_level(void) { return rpki_config.log.level; } enum log_output -config_get_log_output(void) +config_get_op_log_output(void) { return rpki_config.log.output; } +uint32_t +config_get_op_log_facility(void) +{ + return rpki_config.log.facility; +} + +bool +config_get_val_log_enabled(void) +{ + return rpki_config.validation_log.enabled; +} + +char const * +config_get_val_log_prefix(void) +{ + return rpki_config.validation_log.prefix; +} + +bool +config_get_val_log_color_output(void) +{ + return rpki_config.validation_log.color; +} + +enum filename_format +config_get_val_log_filename_format(void) +{ + return rpki_config.validation_log.filename_format; +} + +uint8_t +config_get_val_log_level(void) +{ + return rpki_config.validation_log.level; +} + +enum log_output +config_get_val_log_output(void) +{ + return rpki_config.validation_log.output; +} + +uint32_t +config_get_val_log_facility(void) +{ + return rpki_config.validation_log.facility; +} + bool config_get_rsync_enabled(void) { diff --git a/src/config.h b/src/config.h index a60c57be..d27410bc 100644 --- a/src/config.h +++ b/src/config.h @@ -31,15 +31,11 @@ bool config_get_shuffle_tal_uris(void); unsigned int config_get_max_cert_depth(void); enum mode config_get_mode(void); bool config_get_work_offline(void); -bool config_get_color_output(void); -enum filename_format config_get_filename_format(void); char const *config_get_http_user_agent(void); unsigned int config_get_http_connect_timeout(void); unsigned int config_get_http_transfer_timeout(void); unsigned int config_get_http_idle_timeout(void); char const *config_get_http_ca_path(void); -uint8_t config_get_log_level(void); -enum log_output config_get_log_output(void); bool config_get_rsync_enabled(void); unsigned int config_get_rsync_priority(void); enum rsync_strategy config_get_rsync_strategy(void); @@ -56,6 +52,23 @@ char const *config_get_output_bgpsec(void); unsigned int config_get_asn1_decode_max_stack(void); unsigned int config_get_stale_repository_period(void); +/* Logging getters */ +bool config_get_op_log_enabled(void); +char const * config_get_op_log_prefix(void); +bool config_get_op_log_color_output(void); +enum filename_format config_get_op_log_filename_format(void); +uint8_t config_get_op_log_level(void); +enum log_output config_get_op_log_output(void); +uint32_t config_get_op_log_facility(void); + +bool config_get_val_log_enabled(void); +char const * config_get_val_log_prefix(void); +bool config_get_val_log_color_output(void); +enum filename_format config_get_val_log_filename_format(void); +uint8_t config_get_val_log_level(void); +enum log_output config_get_val_log_output(void); +uint32_t config_get_val_log_facility(void); + /* * Public, so that work-offline can set them, or (to be deprecated) * sync-strategy when set to 'off'. diff --git a/src/config/boolean.c b/src/config/boolean.c index 430459f5..ceb28987 100644 --- a/src/config/boolean.c +++ b/src/config/boolean.c @@ -10,7 +10,7 @@ void print_bool(struct option_field const *field, void *value) { - pr_info("%s: %s", field->name, DEREFERENCE(value) ? "true" : "false"); + pr_op_info("%s: %s", field->name, DEREFERENCE(value) ? "true" : "false"); } int @@ -31,7 +31,7 @@ parse_argv_bool(struct option_field const *field, char const *str, void *result) return 0; } - return pr_err("Cannot parse '%s' as a bool (true|false).", str); + return pr_op_err("Cannot parse '%s' as a bool (true|false).", str); } int @@ -39,7 +39,7 @@ parse_json_bool(struct option_field const *opt, struct json_t *json, void *result) { if (!json_is_boolean(json)) { - return pr_err("The '%s' element is not a JSON boolean.", + return pr_op_err("The '%s' element is not a JSON boolean.", opt->name); } diff --git a/src/config/filename_format.c b/src/config/filename_format.c index a9241f59..e9ec8ce3 100644 --- a/src/config/filename_format.c +++ b/src/config/filename_format.c @@ -30,7 +30,7 @@ print_filename_format(struct option_field const *field, void *value) break; } - pr_info("%s: %s", field->name, str); + pr_op_info("%s: %s", field->name, str); } static int @@ -44,7 +44,7 @@ parse_argv_filename_format(struct option_field const *field, char const *str, else if (strcmp(str, FNF_VALUE_NAME) == 0) DEREFERENCE(result) = FNF_NAME; else - return pr_err("Unknown file name format: '%s'", str); + return pr_op_err("Unknown file name format: '%s'", str); return 0; } diff --git a/src/config/log_conf.c b/src/config/log_conf.c index 5217b914..d6c5f057 100644 --- a/src/config/log_conf.c +++ b/src/config/log_conf.c @@ -16,8 +16,30 @@ #define LOG_OUTPUT_VALUE_SYSLOG "syslog" #define LOG_OUTPUT_VALUE_CONSOLE "console" +#define LOG_FACILITY_VALUE_AUTH "auth" +#define LOG_FACILITY_VALUE_AUTHPRIV "authpriv" +#define LOG_FACILITY_VALUE_CRON "cron" +#define LOG_FACILITY_VALUE_DAEMON "daemon" +#define LOG_FACILITY_VALUE_FTP "ftp" +#define LOG_FACILITY_VALUE_KERN "kern" +#define LOG_FACILITY_VALUE_LPR "lpr" +#define LOG_FACILITY_VALUE_MAIL "mail" +#define LOG_FACILITY_VALUE_NEWS "news" +#define LOG_FACILITY_VALUE_SYSLOG "syslog" +#define LOG_FACILITY_VALUE_USER "user" +#define LOG_FACILITY_VALUE_UUCP "uucp" +#define LOG_FACILITY_VALUE_LOCAL0 "local0" +#define LOG_FACILITY_VALUE_LOCAL1 "local1" +#define LOG_FACILITY_VALUE_LOCAL2 "local2" +#define LOG_FACILITY_VALUE_LOCAL3 "local3" +#define LOG_FACILITY_VALUE_LOCAL4 "local4" +#define LOG_FACILITY_VALUE_LOCAL5 "local5" +#define LOG_FACILITY_VALUE_LOCAL6 "local6" +#define LOG_FACILITY_VALUE_LOCAL7 "local7" + #define DEREFERENCE_UINT(void_value) (*((uint8_t *) void_value)) #define DEREFERENCE_ENUM(void_value) (*((enum log_output *) void_value)) +#define DEREFERENCE_UINT32(void_value) (*((uint32_t *) void_value)) static void print_log_level(struct option_field const *field, void *value) @@ -39,7 +61,7 @@ print_log_level(struct option_field const *field, void *value) break; } - pr_info("%s: %s", field->name, str); + pr_op_info("%s: %s", field->name, str); } static void @@ -56,7 +78,78 @@ print_log_output(struct option_field const *field, void *value) break; } - pr_info("%s: %s", field->name, str); + pr_op_info("%s: %s", field->name, str); +} + +static void +print_log_facility(struct option_field const *field, void *value) +{ + char const *str = ""; + + switch (DEREFERENCE_UINT32(value)) { + case LOG_KERN: + str = LOG_FACILITY_VALUE_KERN; + break; + case LOG_USER: + str = LOG_FACILITY_VALUE_USER; + break; + case LOG_MAIL: + str = LOG_FACILITY_VALUE_MAIL; + break; + case LOG_DAEMON: + str = LOG_FACILITY_VALUE_DAEMON; + break; + case LOG_AUTH: + str = LOG_FACILITY_VALUE_AUTH; + break; + case LOG_SYSLOG: + str = LOG_FACILITY_VALUE_SYSLOG; + break; + case LOG_LPR: + str = LOG_FACILITY_VALUE_LPR; + break; + case LOG_NEWS: + str = LOG_FACILITY_VALUE_NEWS; + break; + case LOG_UUCP: + str = LOG_FACILITY_VALUE_UUCP; + break; + case LOG_CRON: + str = LOG_FACILITY_VALUE_CRON; + break; + case LOG_AUTHPRIV: + str = LOG_FACILITY_VALUE_AUTHPRIV; + break; + case LOG_FTP: + str = LOG_FACILITY_VALUE_FTP; + break; + case LOG_LOCAL0: + str = LOG_FACILITY_VALUE_LOCAL0; + break; + case LOG_LOCAL1: + str = LOG_FACILITY_VALUE_LOCAL1; + break; + case LOG_LOCAL2: + str = LOG_FACILITY_VALUE_LOCAL2; + break; + case LOG_LOCAL3: + str = LOG_FACILITY_VALUE_LOCAL3; + break; + case LOG_LOCAL4: + str = LOG_FACILITY_VALUE_LOCAL4; + break; + case LOG_LOCAL5: + str = LOG_FACILITY_VALUE_LOCAL5; + break; + case LOG_LOCAL6: + str = LOG_FACILITY_VALUE_LOCAL6; + break; + case LOG_LOCAL7: + str = LOG_FACILITY_VALUE_LOCAL7; + break; + } + + pr_op_info("%s: %s", field->name, str); } static int @@ -72,7 +165,7 @@ parse_argv_log_level(struct option_field const *field, char const *str, else if (strcmp(str, LOG_LEVEL_VALUE_DEBUG) == 0) DEREFERENCE_UINT(result) = LOG_DEBUG; else - return pr_err("Unknown log level: '%s'", str); + return pr_op_err("Unknown log level: '%s'", str); return 0; } @@ -86,7 +179,57 @@ parse_argv_log_output(struct option_field const *field, char const *str, else if (strcmp(str, LOG_OUTPUT_VALUE_CONSOLE) == 0) DEREFERENCE_ENUM(result) = CONSOLE; else - return pr_err("Unknown log output: '%s'", str); + return pr_op_err("Unknown log output: '%s'", str); + + return 0; +} + +static int +parse_argv_log_facility(struct option_field const *field, char const *str, + void *result) +{ + if (strcmp(str, LOG_FACILITY_VALUE_AUTH) == 0) + DEREFERENCE_UINT32(result) = LOG_AUTH; + else if (strcmp(str, LOG_FACILITY_VALUE_AUTHPRIV) == 0) + DEREFERENCE_UINT32(result) = LOG_AUTHPRIV; + else if (strcmp(str, LOG_FACILITY_VALUE_CRON) == 0) + DEREFERENCE_UINT32(result) = LOG_CRON; + else if (strcmp(str, LOG_FACILITY_VALUE_DAEMON) == 0) + DEREFERENCE_UINT32(result) = LOG_DAEMON; + else if (strcmp(str, LOG_FACILITY_VALUE_FTP) == 0) + DEREFERENCE_UINT32(result) = LOG_FTP; + else if (strcmp(str, LOG_FACILITY_VALUE_KERN) == 0) + DEREFERENCE_UINT32(result) = LOG_KERN; + else if (strcmp(str, LOG_FACILITY_VALUE_LPR) == 0) + DEREFERENCE_UINT32(result) = LOG_LPR; + else if (strcmp(str, LOG_FACILITY_VALUE_MAIL) == 0) + DEREFERENCE_UINT32(result) = LOG_MAIL; + else if (strcmp(str, LOG_FACILITY_VALUE_NEWS) == 0) + DEREFERENCE_UINT32(result) = LOG_NEWS; + else if (strcmp(str, LOG_FACILITY_VALUE_SYSLOG) == 0) + DEREFERENCE_UINT32(result) = LOG_SYSLOG; + else if (strcmp(str, LOG_FACILITY_VALUE_USER) == 0) + DEREFERENCE_UINT32(result) = LOG_USER; + else if (strcmp(str, LOG_FACILITY_VALUE_UUCP) == 0) + DEREFERENCE_UINT32(result) = LOG_UUCP; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL0) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL0; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL1) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL1; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL2) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL2; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL3) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL3; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL4) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL4; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL5) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL5; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL6) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL6; + else if (strcmp(str, LOG_FACILITY_VALUE_LOCAL7) == 0) + DEREFERENCE_UINT32(result) = LOG_LOCAL7; + else + return pr_op_err("Unknown log output: '%s'", str); return 0; } @@ -113,6 +256,17 @@ parse_json_log_output(struct option_field const *opt, json_t *json, return error ? error : parse_argv_log_output(opt, string, result); } +static int +parse_json_log_facility(struct option_field const *opt, json_t *json, + void *result) +{ + char const *string; + int error; + + error = parse_json_string(json, opt->name, &string); + return error ? error : parse_argv_log_facility(opt, string, result); +} + const struct global_type gt_log_level = { .has_arg = required_argument, .size = sizeof(uint8_t), @@ -133,3 +287,31 @@ const struct global_type gt_log_output = { .parse.json = parse_json_log_output, .arg_doc = LOG_OUTPUT_VALUE_SYSLOG "|" LOG_OUTPUT_VALUE_CONSOLE, }; + +const struct global_type gt_log_facility = { + .has_arg = required_argument, + .size = sizeof(uint32_t), + .print = print_log_facility, + .parse.argv = parse_argv_log_facility, + .parse.json = parse_json_log_facility, + .arg_doc = LOG_FACILITY_VALUE_AUTH + "|" LOG_FACILITY_VALUE_AUTHPRIV + "|" LOG_FACILITY_VALUE_CRON + "|" LOG_FACILITY_VALUE_DAEMON + "|" LOG_FACILITY_VALUE_FTP + "|" LOG_FACILITY_VALUE_KERN + "|" LOG_FACILITY_VALUE_LPR + "|" LOG_FACILITY_VALUE_MAIL + "|" LOG_FACILITY_VALUE_NEWS + "|" LOG_FACILITY_VALUE_SYSLOG + "|" LOG_FACILITY_VALUE_USER + "|" LOG_FACILITY_VALUE_UUCP + "|" LOG_FACILITY_VALUE_LOCAL0 + "|" LOG_FACILITY_VALUE_LOCAL1 + "|" LOG_FACILITY_VALUE_LOCAL2 + "|" LOG_FACILITY_VALUE_LOCAL3 + "|" LOG_FACILITY_VALUE_LOCAL4 + "|" LOG_FACILITY_VALUE_LOCAL5 + "|" LOG_FACILITY_VALUE_LOCAL6 + "|" LOG_FACILITY_VALUE_LOCAL7, +}; diff --git a/src/config/log_conf.h b/src/config/log_conf.h index 98d40557..ffab0989 100644 --- a/src/config/log_conf.h +++ b/src/config/log_conf.h @@ -10,5 +10,6 @@ enum log_output { extern const struct global_type gt_log_level; extern const struct global_type gt_log_output; +extern const struct global_type gt_log_facility; #endif /* SRC_CONFIG_LOG_CONF_H_ */ diff --git a/src/config/mode.c b/src/config/mode.c index 4584a95a..9e425524 100644 --- a/src/config/mode.c +++ b/src/config/mode.c @@ -26,7 +26,7 @@ print_mode(struct option_field const *field, void *value) break; } - pr_info("%s: %s", field->name, str); + pr_op_info("%s: %s", field->name, str); } static int @@ -38,7 +38,7 @@ parse_argv_mode(struct option_field const *field, char const *str, else if (strcmp(str, VALUE_STANDALONE) == 0) DEREFERENCE(result) = STANDALONE; else - return pr_err("Unknown mode: '%s'", str); + return pr_op_err("Unknown mode: '%s'", str); return 0; } diff --git a/src/config/rsync_strategy.c b/src/config/rsync_strategy.c index 34dd815f..b9b3a1dd 100644 --- a/src/config/rsync_strategy.c +++ b/src/config/rsync_strategy.c @@ -20,7 +20,7 @@ #else #define PRINT_STRICT_ARG_DOC #define HANDLE_RSYNC_STRICT \ - return pr_err("Unknown rsync synchronization strategy: '%s'. In order to use it, recompile using flag ENABLE_STRICT_STRATEGY.",\ + return pr_op_err("Unknown rsync synchronization strategy: '%s'. In order to use it, recompile using flag ENABLE_STRICT_STRATEGY.",\ str); #endif @@ -43,7 +43,7 @@ print_rsync_strategy(struct option_field const *field, void *value) break; } - pr_info("%s: %s", field->name, str); + pr_op_info("%s: %s", field->name, str); } int @@ -57,7 +57,7 @@ parse_argv_rsync_strategy(struct option_field const *field, char const *str, else if (strcmp(str, RSYNC_VALUE_ROOT_EXCEPT_TA) == 0) DEREFERENCE(result) = RSYNC_ROOT_EXCEPT_TA; else - return pr_err("Unknown rsync synchronization strategy: '%s'", + return pr_op_err("Unknown rsync synchronization strategy: '%s'", str); /* FIXME (later) Remove when sync-strategy is fully deprecated */ diff --git a/src/config/str.c b/src/config/str.c index a9400ba7..d822ffc1 100644 --- a/src/config/str.c +++ b/src/config/str.c @@ -17,7 +17,7 @@ __string_free(char **string) static void string_print(struct option_field const *field, void *value) { - pr_info("%s: %s", field->name, DEREFERENCE(value)); + pr_op_info("%s: %s", field->name, DEREFERENCE(value)); } static int @@ -26,7 +26,7 @@ string_parse_argv(struct option_field const *field, char const *str, { if (field->type->has_arg != required_argument || str == NULL || strlen(str) == 0) { - return pr_err("String options ('%s' in this case) require an argument.", + return pr_op_err("String options ('%s' in this case) require an argument.", field->name); } @@ -71,7 +71,7 @@ int parse_json_string(json_t *json, char const *name, char const **result) { if (!json_is_string(json)) - return pr_err("The '%s' element is not a JSON string.", name); + return pr_op_err("The '%s' element is not a JSON string.", name); *result = json_string_value(json); return 0; diff --git a/src/config/string_array.c b/src/config/string_array.c index f401d876..cc4bfac0 100644 --- a/src/config/string_array.c +++ b/src/config/string_array.c @@ -59,12 +59,12 @@ string_array_print(struct option_field const *field, void *_value) struct string_array *value = _value; size_t i; - pr_info("%s:", field->name); + pr_op_info("%s:", field->name); if (value->length == 0) - pr_info(" "); + pr_op_info(" "); else for (i = 0; i < value->length; i++) - pr_info(" %s", value->array[i]); + pr_op_info(" %s", value->array[i]); } static int @@ -78,7 +78,7 @@ string_array_parse_json(struct option_field const *opt, json_t *json, int error; if (!json_is_array(json)) { - return pr_err("The '%s' element is not a JSON array.", + return pr_op_err("The '%s' element is not a JSON array.", opt->name); } @@ -91,7 +91,7 @@ string_array_parse_json(struct option_field const *opt, json_t *json, for (i = 0; i < len; i++) { child = json_array_get(json, i); if (!json_is_string(child)) { - return pr_err("'%s' array element #%zu is not a string.", + return pr_op_err("'%s' array element #%zu is not a string.", opt->name, i); } } diff --git a/src/config/sync_strategy.c b/src/config/sync_strategy.c index 146f7adf..224d5c41 100644 --- a/src/config/sync_strategy.c +++ b/src/config/sync_strategy.c @@ -35,7 +35,7 @@ static void print_sync_strategy(struct option_field const *field, void *value) { if (DEREFERENCE(value) == RSYNC_OFF) { - pr_info("%s: %s", field->name, RSYNC_VALUE_OFF); + pr_op_info("%s: %s", field->name, RSYNC_VALUE_OFF); return; } @@ -48,8 +48,8 @@ parse_argv_sync_strategy(struct option_field const *field, char const *str, { int error; - pr_warn("'sync-strategy' will be deprecated."); - pr_warn("Use 'rsync.strategy' instead; or 'rsync.enabled=false' if you wish to use 'off' strategy."); + pr_op_warn("'sync-strategy' will be deprecated."); + pr_op_warn("Use 'rsync.strategy' instead; or 'rsync.enabled=false' if you wish to use 'off' strategy."); if (strcmp(str, RSYNC_VALUE_OFF) == 0) { DEREFERENCE(result) = RSYNC_OFF; diff --git a/src/config/uint.c b/src/config/uint.c index 007bf532..6888489d 100644 --- a/src/config/uint.c +++ b/src/config/uint.c @@ -9,7 +9,7 @@ static void print_uint(struct option_field const *field, void *value) { - pr_info("%s: %u", field->name, *((unsigned int *) value)); + pr_op_info("%s: %u", field->name, *((unsigned int *) value)); } int @@ -21,21 +21,21 @@ parse_argv_uint(struct option_field const *field, char const *str, if (field->type->has_arg != required_argument || str == NULL || strlen(str) == 0) { - return pr_err("Integer options ('%s' in this case) require an argument.", + return pr_op_err("Integer options ('%s' in this case) require an argument.", field->name); } errno = 0; parsed = strtoul(str, &tmp, 10); if (errno || *tmp != '\0') - return errno ? pr_errno(errno, + return errno ? pr_op_errno(errno, "Value '%s' at '%s' is not an unsigned integer", str, field->name) : - pr_err("Value '%s' at '%s' is not an unsigned integer", + pr_op_err("Value '%s' at '%s' is not an unsigned integer", str, field->name); if (parsed < field->min || field->max < parsed) { - return pr_err("Value of '%s' is out of range (%u-%u).", + return pr_op_err("Value of '%s' is out of range (%u-%u).", field->name, field->min, field->max); } @@ -49,14 +49,14 @@ parse_json_uint(struct option_field const *opt, json_t *json, void *result) json_int_t value; if (!json_is_integer(json)) { - return pr_err("The '%s' element is not a JSON integer.", + return pr_op_err("The '%s' element is not a JSON integer.", opt->name); } value = json_integer_value(json); if (value < opt->min || opt->max < value) { - return pr_err("Integer '%s' is out of range (%u-%u).", + return pr_op_err("Integer '%s' is out of range (%u-%u).", opt->name, opt->min, opt->max); } diff --git a/src/config/uint32.c b/src/config/uint32.c index a64699d4..942cfcfe 100644 --- a/src/config/uint32.c +++ b/src/config/uint32.c @@ -10,7 +10,7 @@ static void print_uint32(struct option_field const *field, void *value) { - pr_info("%s: %u", field->name, *((uint32_t *) value)); + pr_op_info("%s: %u", field->name, *((uint32_t *) value)); } static int diff --git a/src/crypto/hash.c b/src/crypto/hash.c index cd747ccb..a39ee135 100644 --- a/src/crypto/hash.c +++ b/src/crypto/hash.c @@ -17,7 +17,7 @@ get_md(char const *algorithm, EVP_MD const **result) md = EVP_get_digestbyname(algorithm); if (md == NULL) { - pr_err("Unknown message digest %s", algorithm); + pr_val_err("Unknown message digest %s", algorithm); return -EINVAL; } @@ -76,7 +76,7 @@ hash_local_file(char const *algorithm, char const *uri, unsigned char *result, } if (!EVP_DigestInit_ex(ctx, md, NULL)) { - error = crypto_err("EVP_DigestInit_ex() failed"); + error = val_crypto_err("EVP_DigestInit_ex() failed"); goto end3; } @@ -84,20 +84,20 @@ hash_local_file(char const *algorithm, char const *uri, unsigned char *result, consumed = fread(buffer, 1, buffer_len, file); error = ferror(file); if (error) { - pr_errno(error, + pr_val_errno(error, "File reading error. Error message (apparently)"); goto end3; } if (!EVP_DigestUpdate(ctx, buffer, consumed)) { - error = crypto_err("EVP_DigestUpdate() failed"); + error = val_crypto_err("EVP_DigestUpdate() failed"); goto end3; } } while (!feof(file)); if (!EVP_DigestFinal_ex(ctx, result, result_len)) - error = crypto_err("EVP_DigestFinal_ex() failed"); + error = val_crypto_err("EVP_DigestFinal_ex() failed"); end3: EVP_MD_CTX_free(ctx); @@ -128,7 +128,7 @@ hash_validate_mft_file(char const *algorithm, struct rpki_uri *uri, int error; if (expected->bits_unused != 0) - return pr_err("Hash string has unused bits."); + return pr_val_err("Hash string has unused bits."); do { error = hash_file(algorithm, uri, actual, &actual_len); @@ -138,7 +138,7 @@ hash_validate_mft_file(char const *algorithm, struct rpki_uri *uri, if (error == EACCES || error == ENOENT) { if (incidence(INID_MFT_FILE_NOT_FOUND, "File '%s' listed at manifest doesn't exist.", - uri_get_printable(uri))) + uri_val_get_printable(uri))) return -EINVAL; return error; @@ -150,7 +150,7 @@ hash_validate_mft_file(char const *algorithm, struct rpki_uri *uri, if (!hash_matches(expected->buf, expected->size, actual, actual_len)) { return incidence(INID_MFT_FILE_HASH_NOT_MATCH, "File '%s' does not match its manifest hash.", - uri_get_printable(uri)); + uri_val_get_printable(uri)); } return 0; @@ -173,8 +173,8 @@ hash_validate_file(char const *algorithm, struct rpki_uri *uri, return error; if (!hash_matches(expected, expected_len, actual, actual_len)) { - return pr_err("File '%s' does not match its expected hash.", - uri_get_printable(uri)); + return pr_val_err("File '%s' does not match its expected hash.", + uri_val_get_printable(uri)); } return 0; @@ -200,7 +200,7 @@ hash_buffer(char const *algorithm, if (!EVP_DigestInit_ex(ctx, md, NULL) || !EVP_DigestUpdate(ctx, content, content_len) || !EVP_DigestFinal_ex(ctx, hash, hash_len)) { - error = crypto_err("Buffer hashing failed"); + error = val_crypto_err("Buffer hashing failed"); } EVP_MD_CTX_free(ctx); diff --git a/src/delete_dir_daemon.c b/src/delete_dir_daemon.c index 91129c30..d81e82f1 100644 --- a/src/delete_dir_daemon.c +++ b/src/delete_dir_daemon.c @@ -25,18 +25,18 @@ struct rem_dirs { static int remove_file(char const *location) { - pr_debug("Trying to remove file '%s'.", location); + pr_op_debug("Trying to remove file '%s'.", location); if (remove(location)) - return pr_errno(errno, "Couldn't delete file '%s'", location); + return pr_op_errno(errno, "Couldn't delete file '%s'", location); return 0; } static int remove_dir(char const *location) { - pr_debug("Trying to remove dir '%s'.", location); + pr_op_debug("Trying to remove dir '%s'.", location); if (rmdir(location)) - return pr_errno(errno, "Couldn't delete directory '%s'", + return pr_op_errno(errno, "Couldn't delete directory '%s'", location); return 0; } @@ -54,18 +54,18 @@ traverse(char const *path, struct stat const *sb, int flag, struct FTW *ftwbuf) case FTW_F: return remove_file(path); case FTW_DNR: - return pr_err("Can't access '%s', stop deletion.", path); + return pr_op_err("Can't access '%s', stop deletion.", path); case FTW_NS: - return pr_err("Can't get information of '%s', stop deletion.", + return pr_op_err("Can't get information of '%s', stop deletion.", path); case FTW_SL: - return pr_err("Can't delete '%s' since is a symbolic link, stop deletion.", + return pr_op_err("Can't delete '%s' since is a symbolic link, stop deletion.", path); case FTW_D: - return pr_err("Can't delete '%s' dir before deleting its content.", + return pr_op_err("Can't delete '%s' dir before deleting its content.", path); default: - return pr_warn("Unknown path flag %d, doing nothing to '%s'.", + return pr_op_warn("Unknown path flag %d, doing nothing to '%s'.", flag, path); } } @@ -90,17 +90,17 @@ remove_from_root(void *arg) FTW_DEPTH|FTW_MOUNT|FTW_PHYS); if (error) { if (errno) - pr_debug("Error deleting directory '%s', please delete it manually: %s", + pr_op_debug("Error deleting directory '%s', please delete it manually: %s", dirs_arr[i], strerror(errno)); else - pr_debug("Couldn't delete directory '%s', please delete it manually", + pr_op_debug("Couldn't delete directory '%s', please delete it manually", dirs_arr[i]); } /* Release at once, won't be needed anymore */ free(dirs_arr[i]); } - pr_debug("Done removing dirs."); + pr_op_debug("Done removing dirs."); free(dirs_arr); return NULL; } @@ -133,7 +133,7 @@ get_local_path(char const *rcvd, char **result) error = stat(local_path, &attr); if (error) { /* Soft error */ - pr_debug("Error reading path '%s' (discarding): %s", + pr_op_debug("Error reading path '%s' (discarding): %s", local_path, strerror(errno)); error = errno; goto release_local; @@ -141,7 +141,7 @@ get_local_path(char const *rcvd, char **result) if (!S_ISDIR(attr.st_mode)) { /* Soft error */ - pr_debug("Path '%s' exists but is not a directory (discarding).", + pr_op_debug("Path '%s' exists but is not a directory (discarding).", local_path); error = ENOTDIR; goto release_local; @@ -202,7 +202,7 @@ rename_local_path(char const *rcvd, char **result) error = rename(rcvd, tmp); if (error) { free(tmp); - pr_debug("Couldn't rename '%s' to delete it (discarding): %s", + pr_op_debug("Couldn't rename '%s' to delete it (discarding): %s", rcvd, strerror(errno)); return errno; /* Soft error */ } @@ -303,7 +303,7 @@ delete_dir_daemon_start(char **roots, size_t roots_len) errno = pthread_create(&thread, NULL, remove_from_root, (void *) arg); if (errno) { rem_dirs_destroy(arg); - return pr_errno(errno, + return pr_op_errno(errno, "Could not spawn the delete dir daemon thread"); } diff --git a/src/extension.c b/src/extension.c index 3301d95a..d8bd58ed 100644 --- a/src/extension.c +++ b/src/extension.c @@ -190,16 +190,16 @@ handle_extension(struct extension_handler *handlers, X509_EXTENSION *ext) * Also "unknown" is misleading. I think it's only "unknown" if the NID * is -1 or something like that. */ - return pr_err("Certificate has unknown extension. (Extension NID: %d)", + return pr_val_err("Certificate has unknown extension. (Extension NID: %d)", nid); dupe: - return pr_err("Certificate has more than one '%s' extension.", + return pr_val_err("Certificate has more than one '%s' extension.", handler->meta->name); not_critical: - return pr_err("Extension '%s' is supposed to be marked critical.", + return pr_val_err("Extension '%s' is supposed to be marked critical.", handler->meta->name); critical: - return pr_err("Extension '%s' is not supposed to be marked critical.", + return pr_val_err("Extension '%s' is not supposed to be marked critical.", handler->meta->name); } @@ -220,7 +220,7 @@ handle_extensions(struct extension_handler *handlers, for (handler = handlers; handler->meta != NULL; handler++) { if (handler->mandatory && !handler->found) - return pr_err("Certificate is missing the '%s' extension.", + return pr_val_err("Certificate is missing the '%s' extension.", handler->meta->name); } @@ -230,7 +230,7 @@ handle_extensions(struct extension_handler *handlers, int cannot_decode(struct extension_metadata const *meta) { - return pr_err("Extension '%s' seems to be malformed. Cannot decode.", + return pr_val_err("Extension '%s' seems to be malformed. Cannot decode.", meta->name); } @@ -281,25 +281,25 @@ validate_public_key_hash(X509 *cert, ASN1_OCTET_STRING *hash) /* Get the SPK (ask libcrypto) */ pubkey = X509_get_X509_PUBKEY(cert); if (pubkey == NULL) - return crypto_err("X509_get_X509_PUBKEY() returned NULL"); + return val_crypto_err("X509_get_X509_PUBKEY() returned NULL"); ok = X509_PUBKEY_get0_param(NULL, &spk, &spk_len, NULL, pubkey); if (!ok) - return crypto_err("X509_PUBKEY_get0_param() returned %d", ok); + return val_crypto_err("X509_PUBKEY_get0_param() returned %d", ok); /* Hash the SPK, compare SPK hash with the SKI */ if (hash->length < 0 || SIZE_MAX < hash->length) { - return pr_err("%s length (%d) is out of bounds. (0-%zu)", + return pr_val_err("%s length (%d) is out of bounds. (0-%zu)", ext_ski()->name, hash->length, SIZE_MAX); } if (spk_len < 0 || SIZE_MAX < spk_len) { - return pr_err("Subject Public Key length (%d) is out of bounds. (0-%zu)", + return pr_val_err("Subject Public Key length (%d) is out of bounds. (0-%zu)", spk_len, SIZE_MAX); } error = hash_validate("sha1", hash->data, hash->length, spk, spk_len); if (error) { - pr_err("The Subject Public Key's hash does not match the %s.", + pr_val_err("The Subject Public Key's hash does not match the %s.", ext_ski()->name); } @@ -319,12 +319,12 @@ handle_aki(X509_EXTENSION *ext, void *arg) return cannot_decode(ext_aki()); if (aki->issuer != NULL) { - error = pr_err("%s extension contains an authorityCertIssuer.", + error = pr_val_err("%s extension contains an authorityCertIssuer.", ext_aki()->name); goto end; } if (aki->serial != NULL) { - error = pr_err("%s extension contains an authorityCertSerialNumber.", + error = pr_val_err("%s extension contains an authorityCertSerialNumber.", ext_aki()->name); goto end; } @@ -337,7 +337,7 @@ handle_aki(X509_EXTENSION *ext, void *arg) parent = x509stack_peek(validation_certstack(state)); if (parent == NULL) { - error = pr_err("Certificate has no parent."); + error = pr_val_err("Certificate has no parent."); goto end; } diff --git a/src/file.c b/src/file.c index 8df0f966..9f7debc6 100644 --- a/src/file.c +++ b/src/file.c @@ -13,14 +13,14 @@ file_get(char const *file_name, FILE **result, struct stat *stat, file = fopen(file_name, mode); if (file == NULL) - return pr_errno(errno, "Could not open file '%s'", file_name); + return pr_val_errno(errno, "Could not open file '%s'", file_name); if (fstat(fileno(file), stat) == -1) { - error = pr_errno(errno, "fstat(%s) failed", file_name); + error = pr_val_errno(errno, "fstat(%s) failed", file_name); goto fail; } if (!S_ISREG(stat->st_mode)) { - error = pr_err("%s does not seem to be a file", file_name); + error = pr_op_err("%s does not seem to be a file", file_name); goto fail; } @@ -48,7 +48,7 @@ void file_close(FILE *file) { if (fclose(file) == -1) - pr_errno(errno, "fclose() failed"); + pr_val_errno(errno, "fclose() failed"); } int @@ -79,7 +79,7 @@ file_load(char const *file_name, struct file_contents *fc) * code. It literally doesn't say how to get an error * code. */ - pr_errno(error, + pr_val_errno(error, "File reading error. Error message (apparently)"); free(fc->buffer); goto end; @@ -90,8 +90,8 @@ file_load(char const *file_name, struct file_contents *fc) * less bytes than requested like read() does. It's either * "consumed everything", "EOF reached" or error. */ - pr_err("Likely programming error: fread() < file size"); - pr_err("fr:%zu bs:%zu EOF:%d", fread_result, fc->buffer_size, + pr_op_err("Likely programming error: fread() < file size"); + pr_op_err("fr:%zu bs:%zu EOF:%d", fread_result, fc->buffer_size, feof(file)); free(fc->buffer); error = -EINVAL; diff --git a/src/http/http.c b/src/http/http.c index 919d236e..c49aee71 100644 --- a/src/http/http.c +++ b/src/http/http.c @@ -25,7 +25,7 @@ http_init(void) CURLcode res; res = curl_global_init(CURL_GLOBAL_SSL); if (res != CURLE_OK) - return pr_err("Error initializing global curl (%s)", + return pr_op_err("Error initializing global curl (%s)", curl_easy_strerror(res)); return 0; @@ -117,7 +117,7 @@ http_fetch(struct http_handler *handler, char const *uri, long *response_code, curl_easy_setopt(handler->curl, CURLOPT_WRITEFUNCTION, cb); curl_easy_setopt(handler->curl, CURLOPT_WRITEDATA, arg); - pr_debug("Doing HTTP GET to '%s'.", uri); + pr_val_debug("Doing HTTP GET to '%s'.", uri); res = curl_easy_perform(handler->curl); curl_easy_getinfo(handler->curl, CURLINFO_RESPONSE_CODE, response_code); if (res == CURLE_OK) { @@ -140,15 +140,13 @@ http_fetch(struct http_handler *handler, char const *uri, long *response_code, } if (*response_code >= HTTP_BAD_REQUEST) - return pr_err("Error requesting URL %s (received HTTP code %ld): %s", + return pr_val_err("Error requesting URL %s (received HTTP code %ld): %s", uri, *response_code, curl_err_string(handler, res)); - /* FIXME (NOW) Always log this to validation log */ - pr_err("Error requesting URL %s: %s", uri, + pr_val_err("Error requesting URL %s: %s", uri, curl_err_string(handler, res)); - /* FIXME (NOW) and send to operation log when requested */ if (log_operation) - pr_err("Error requesting URL %s: %s", uri, + pr_op_err("Error requesting URL %s: %s", uri, curl_err_string(handler, res)); return EREQFAILED; diff --git a/src/incidence/incidence.c b/src/incidence/incidence.c index 16f1ec47..aa83f1ed 100644 --- a/src/incidence/incidence.c +++ b/src/incidence/incidence.c @@ -55,7 +55,7 @@ name2id(char const *name, enum incidence_id *id) } } - return pr_err("Unknown incidence name: %s", name); + return pr_op_err("Unknown incidence name: %s", name); } static char const * @@ -100,7 +100,7 @@ init_action(json_t *json) else if (strcmp("error", action_str) == 0) action = INAC_ERROR; else - return pr_err("Unknown incidence action: '%s'", action_str); + return pr_op_err("Unknown incidence action: '%s'", action_str); incidences[id].action = action; return 0; @@ -136,7 +136,7 @@ incidence_update(json_t *json) int error; if (!json_is_array(json)) - return pr_err("The incidences JSON element is supposed to be an array."); + return pr_op_err("The incidences JSON element is supposed to be an array."); json_array_foreach(json, i, child) { error = init_action(child); @@ -152,10 +152,10 @@ incidence_print(void) { array_index i; - pr_info("Custom incidences:"); + pr_op_info("Custom incidences:"); for (i = 0; i < __INID_MAX; i++) { - pr_info(" %s (%s): %s", incidences[i].name, + pr_op_info(" %s (%s): %s", incidences[i].name, incidences[i].description, action2str(incidences[i].action)); } diff --git a/src/json_handler.c b/src/json_handler.c index 15389d1f..a7cee0f5 100644 --- a/src/json_handler.c +++ b/src/json_handler.c @@ -67,7 +67,7 @@ set_config_from_file(char *file) root = json_load_file(file, JSON_REJECT_DUPLICATES, &json_error); if (root == NULL) { - pr_err("JSON error on line %d, column %d: %s", + pr_op_err("JSON error on line %d, column %d: %s", json_error.line, json_error.column, json_error.text); return -ENOENT; } diff --git a/src/json_parser.c b/src/json_parser.c index 3b567412..9dbb21ed 100644 --- a/src/json_parser.c +++ b/src/json_parser.c @@ -23,7 +23,7 @@ json_get_string(json_t *parent, char const *name, char const **result) if (!json_is_string(child)) { *result = NULL; - return pr_err("The '%s' element is not a JSON string.", name); + return pr_op_err("The '%s' element is not a JSON string.", name); } *result = json_string_value(child); @@ -47,7 +47,7 @@ json_get_int(json_t *parent, char const *name, json_int_t *result) return -ENOENT; if (!json_is_integer(child)) - return pr_err("The '%s' element is not a JSON integer.", name); + return pr_op_err("The '%s' element is not a JSON integer.", name); *result = json_integer_value(child); return 0; @@ -63,7 +63,7 @@ json_get_array(json_t *parent, char const *name) return NULL; if (!json_is_array(child)) { - pr_err("The '%s' element is not a JSON array.", name); + pr_op_err("The '%s' element is not a JSON array.", name); return NULL; } @@ -80,7 +80,7 @@ json_get_object(json_t *parent, char const *name) return NULL; if (!json_is_object(child)) { - pr_err("The '%s' element is not a JSON object.", name); + pr_op_err("The '%s' element is not a JSON object.", name); return NULL; } diff --git a/src/line_file.c b/src/line_file.c index c6563e67..fdd7b784 100644 --- a/src/line_file.c +++ b/src/line_file.c @@ -104,7 +104,7 @@ lfile_read(struct line_file *lfile, char **result) free(string); *result = NULL; if (ferror(lfile->file)) - return pr_errno(error, "Error while reading file"); + return pr_op_errno(error, "Error while reading file"); if (feof(lfile->file)) return 0; pr_crit("Supposedly unreachable code reached. ferror:%d feof:%d", @@ -120,7 +120,7 @@ lfile_read(struct line_file *lfile, char **result) */ for (i = 0; i < len; i++) { if (string[i] == '\0') { - pr_err("File '%s' has an illegal null character in its body. Please remove it.", + pr_op_err("File '%s' has an illegal null character in its body. Please remove it.", lfile_name(lfile)); free(string); return -EINVAL; diff --git a/src/log.c b/src/log.c index f0c4ab5f..73542336 100644 --- a/src/log.c +++ b/src/log.c @@ -3,6 +3,7 @@ #include #include #include +#include #include "config.h" #include "debug.h" @@ -23,8 +24,10 @@ static struct level UNK = { "UNK", "" }; #define COLOR_RESET "\x1B[0m" /* LOG_PERROR is not portable, apparently, so I implemented it myself */ -static bool fprintf_enabled; -static bool syslog_enabled; +static bool op_fprintf_enabled; +static bool op_syslog_enabled; +static bool val_fprintf_enabled; +static bool val_syslog_enabled; void log_setup(void) @@ -38,38 +41,61 @@ log_setup(void) UNK.stream = stdout; openlog("fort", LOG_CONS | LOG_PID, LOG_DAEMON); - fprintf_enabled = true; - syslog_enabled = true; + op_fprintf_enabled = true; + op_syslog_enabled = true; + val_fprintf_enabled = true; + val_syslog_enabled = true; } static void -log_disable_std(void) +log_disable_op_std(void) { - fprintf_enabled = false; + op_fprintf_enabled = false; +} + +static void +log_disable_val_std(void) +{ + val_fprintf_enabled = false; } static void log_disable_syslog(void) { - if (syslog_enabled) { + if (op_syslog_enabled || val_syslog_enabled) { closelog(); - syslog_enabled = false; + op_syslog_enabled = false; + val_syslog_enabled = false; } } void log_start(void) { - switch (config_get_log_output()) { + switch (config_get_op_log_output()) { case SYSLOG: - pr_info("Syslog log output configured; disabling logging on standard streams."); - pr_info("(Logs will be sent to syslog only.)"); - log_disable_std(); + pr_op_info("Syslog log output configured; disabling operation logging on standard streams."); + pr_op_info("(Operation Logs will be sent to syslog only.)"); + log_disable_op_std(); break; case CONSOLE: - pr_info("Console log output configured; disabling logging on syslog."); - pr_info("(Logs will be sent to the standard streams only.)"); - log_disable_syslog(); + pr_op_info("Console log output configured; disabling operation logging on syslog."); + pr_op_info("(Operation Logs will be sent to the standard streams only.)"); + op_syslog_enabled = false; + break; + } + + switch (config_get_val_log_output()) { + case SYSLOG: + pr_op_info("Syslog log output configured; disabling validation logging on standard streams."); + pr_op_info("(Validation Logs will be sent to syslog only.)"); + log_disable_val_std(); + break; + case CONSOLE: + pr_op_info("Console log output configured; disabling validation logging on syslog."); + pr_op_info("(Validation Logs will be sent to the standard streams only.)"); + if (!op_syslog_enabled) + log_disable_syslog(); break; } } @@ -77,7 +103,8 @@ log_start(void) void log_teardown(void) { - log_disable_std(); + log_disable_op_std(); + log_disable_val_std(); log_disable_syslog(); } @@ -101,22 +128,37 @@ level2struct(int level) } static void -__fprintf(int level, char const *format, ...) +__fprintf(int level, char const *prefix, bool color_output, + char const *format, ...) { struct level const *lvl; va_list args; + char time_buff[20]; + time_t now; + struct tm stm_buff; lvl = level2struct(level); - if (config_get_color_output()) + if (color_output) fprintf(lvl->stream, "%s", lvl->color); - fprintf(lvl->stream, "%s: ", lvl->label); + now = time(0); + if (now != ((time_t) -1)) { + localtime_r(&now, &stm_buff); + strftime(time_buff, sizeof(time_buff), "%b %e %T", &stm_buff); + fprintf(lvl->stream, "%s ", time_buff); + } + + fprintf(lvl->stream, "%s", lvl->label); + if (prefix) + fprintf(lvl->stream, " [%s]", prefix); + fprintf(lvl->stream, ": "); + va_start(args, format); vfprintf(lvl->stream, format, args); va_end(args); - if (config_get_color_output()) + if (color_output) fprintf(lvl->stream, COLOR_RESET); fprintf(lvl->stream, "\n"); @@ -128,7 +170,8 @@ __fprintf(int level, char const *format, ...) #define MSG_LEN 512 static void -pr_syslog(int level, const char *format, va_list args) +pr_syslog(int level, char const *prefix, const char *format, int facility, + va_list args) { char const *file_name; struct level const *lvl; @@ -139,30 +182,55 @@ pr_syslog(int level, const char *format, va_list args) /* Can't use vsyslog(); it's not portable. */ vsnprintf(msg, MSG_LEN, format, args); - if (file_name != NULL) - syslog(level, "%s: %s: %s", lvl->label, file_name, msg); - else - syslog(level, "%s: %s", lvl->label, msg); + if (file_name != NULL) { + if (prefix != NULL) + syslog(level | facility, "%s [%s]: %s: %s", lvl->label, + prefix, file_name, msg); + else + syslog(level | facility, "%s: %s: %s", lvl->label, + file_name, msg); + } else { + if (prefix != NULL) + syslog(level | facility, "%s [%s]: %s", lvl->label, + prefix, msg); + else + syslog(level | facility, "%s: %s", lvl->label, msg); + } } static void -pr_stream(int level, const char *format, va_list args) +pr_stream(int level, char const *prefix, const char *format, bool color_output, + va_list args) { char const *file_name; + char time_buff[20]; struct level const *lvl; + time_t now; + struct tm stm_buff; file_name = fnstack_peek(); lvl = level2struct(level); - if (config_get_color_output()) + if (color_output) fprintf(lvl->stream, "%s", lvl->color); - fprintf(lvl->stream, "%s: ", lvl->label); + now = time(0); + if (now != ((time_t) -1)) { + localtime_r(&now, &stm_buff); + strftime(time_buff, sizeof(time_buff), "%b %e %T", &stm_buff); + fprintf(lvl->stream, "%s ", time_buff); + } + + fprintf(lvl->stream, "%s", lvl->label); + if (prefix) + fprintf(lvl->stream, " [%s]", prefix); + fprintf(lvl->stream, ": "); + if (file_name != NULL) fprintf(lvl->stream, "%s: ", file_name); vfprintf(lvl->stream, format, args); - if (config_get_color_output()) + if (color_output) fprintf(lvl->stream, "%s", COLOR_RESET); fprintf(lvl->stream, "\n"); @@ -171,71 +239,158 @@ pr_stream(int level, const char *format, va_list args) fflush(lvl->stream); } -#define PR_SIMPLE(level) \ +#define PR_OP_SIMPLE(level) \ do { \ va_list args; \ + char const *prefix = config_get_op_log_prefix(); \ + bool color = config_get_op_log_color_output(); \ + int facility = config_get_op_log_facility(); \ \ - if (level > config_get_log_level()) \ + if (!config_get_op_log_enabled()) \ break; \ \ - if (syslog_enabled) { \ + if (level > config_get_op_log_level()) \ + break; \ + \ + if (op_syslog_enabled) { \ va_start(args, format); \ - pr_syslog(level, format, args); \ + pr_syslog(level, prefix, format, facility, \ + args); \ va_end(args); \ } \ \ - if (fprintf_enabled) { \ + if (op_fprintf_enabled) { \ va_start(args, format); \ - pr_stream(level, format, args); \ + pr_stream(level, prefix, format, color, args); \ + va_end(args); \ + } \ + } while (0) + + +#define PR_VAL_SIMPLE(level) \ + do { \ + va_list args; \ + char const *prefix = config_get_val_log_prefix(); \ + bool color = config_get_val_log_color_output(); \ + int facility = config_get_val_log_facility(); \ + \ + if (!config_get_val_log_enabled()) \ + break; \ + \ + if (level > config_get_val_log_level()) \ + break; \ + \ + if (val_syslog_enabled) { \ + va_start(args, format); \ + pr_syslog(level, prefix, format, facility, \ + args); \ + va_end(args); \ + } \ + \ + if (val_fprintf_enabled) { \ + va_start(args, format); \ + pr_stream(level, prefix, format, color, args); \ va_end(args); \ } \ } while (0) bool -log_debug_enabled(void) +log_val_debug_enabled(void) { - return config_get_log_level() >= LOG_DEBUG; + return config_get_val_log_level() >= LOG_DEBUG; } bool -log_info_enabled(void) +log_op_debug_enabled(void) { - return config_get_log_level() >= LOG_INFO; + return config_get_op_log_level() >= LOG_DEBUG; +} + +bool +log_op_info_enabled(void) +{ + return config_get_op_log_level() >= LOG_INFO; } void -pr_debug(const char *format, ...) +pr_op_debug(const char *format, ...) { - PR_SIMPLE(LOG_DEBUG); + PR_OP_SIMPLE(LOG_DEBUG); } void -pr_info(const char *format, ...) +pr_op_info(const char *format, ...) { - PR_SIMPLE(LOG_INFO); + PR_OP_SIMPLE(LOG_INFO); } /** - * Always appends a newline at the end. Always returs 0. (So you can interrupt - * whatever you're doing without failing validation.) + * Always returs 0. (So you can interrupt whatever you're doing without failing + * validation.) */ int -pr_warn(const char *format, ...) +pr_op_warn(const char *format, ...) { - PR_SIMPLE(LOG_WARNING); + PR_OP_SIMPLE(LOG_WARNING); return 0; } /** - * Always appends a newline at the end. Always returs -EINVAL. + * Always returs -EINVAL. */ int -pr_err(const char *format, ...) +pr_op_err(const char *format, ...) { - PR_SIMPLE(LOG_ERR); + PR_OP_SIMPLE(LOG_ERR); return -EINVAL; } +void +pr_val_debug(const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_DEBUG); +} + +void +pr_val_info(const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_INFO); +} + +/** + * Always returs 0. (So you can interrupt whatever you're doing without failing + * validation.) + */ +int +pr_val_warn(const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_WARNING); + return 0; +} + +/** + * Always returs -EINVAL. + */ +int +pr_val_err(const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_ERR); + return -EINVAL; +} + +static void +pr_simple_syslog(int level, int facility, char const *prefix, const char *msg) +{ + struct level const *lvl; + + lvl = level2struct(LOG_ERR); + if (prefix != NULL) + syslog(LOG_ERR | facility, "%s [%s]: - %s", lvl->label, prefix, + msg); + else + syslog(LOG_ERR | facility, "%s: - %s", lvl->label, msg); +} + /** * @error fulfills two functions, both of which apply only if it's nonzero: * @@ -250,29 +405,97 @@ pr_err(const char *format, ...) * * Always appends a newline at the end. */ -int -pr_errno(int error, const char *format, ...) +static int +pr_errno(int error, bool syslog_enabled, bool fprintf_enabled, int facility, + bool color, char const *prefix) { - PR_SIMPLE(LOG_ERR); - if (!error) return -EINVAL; if (syslog_enabled) - syslog(LOG_ERR, " - %s", strerror(error)); + pr_simple_syslog(LOG_ERR, facility, prefix, strerror(error)); + if (fprintf_enabled) - __fprintf(LOG_ERR, " - %s", strerror(error)); + __fprintf(LOG_ERR, prefix, color, " - %s", strerror(error)); return error; } -static int log_crypto_error(const char *str, size_t len, void *arg) + +int +pr_op_errno(int error, const char *format, ...) { + PR_OP_SIMPLE(LOG_ERR); + + return pr_errno(error, op_syslog_enabled, + op_fprintf_enabled, config_get_op_log_facility(), + config_get_op_log_color_output(), + config_get_op_log_prefix()); +} + +int +pr_val_errno(int error, const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_ERR); + + return pr_errno(error, val_syslog_enabled, + val_fprintf_enabled, config_get_val_log_facility(), + config_get_val_log_color_output(), + config_get_val_log_prefix()); +} + +static int +log_op_crypto_error(const char *str, size_t len, void *arg) +{ + if (op_syslog_enabled) + pr_simple_syslog(LOG_ERR, config_get_op_log_facility(), + config_get_op_log_prefix(), str); + if (op_fprintf_enabled) + __fprintf(LOG_ERR, config_get_op_log_prefix(), + config_get_op_log_color_output(), + " - %s", str); + return 1; +} + +static int +log_val_crypto_error(const char *str, size_t len, void *arg) +{ + if (val_syslog_enabled) + pr_simple_syslog(LOG_ERR, config_get_val_log_facility(), + config_get_val_log_prefix(), str); + if (val_fprintf_enabled) + __fprintf(LOG_ERR, config_get_val_log_prefix(), + config_get_val_log_color_output(), + " - %s", str); + return 1; +} + +static int +crypto_err(int (*cb) (const char *str, size_t len, void *u), + bool fprintf_enabled, bool syslog_enabled, bool color_output, int facility, + const char *prefix) +{ + unsigned int stack_size; + if (syslog_enabled) - syslog(LOG_ERR, " - %s", str); + pr_simple_syslog(LOG_ERR, facility, prefix, + " libcrypto error stack:"); if (fprintf_enabled) - __fprintf(LOG_ERR, " - %s", str); - return 1; + __fprintf(LOG_ERR, prefix, color_output, + " libcrypto error stack:"); + + stack_size = 0; + ERR_print_errors_cb(cb, &stack_size); + if (stack_size == 0) { + if (syslog_enabled) + pr_simple_syslog(LOG_ERR, facility, prefix, + " \n"); + } + + return -EINVAL; } /** @@ -288,43 +511,60 @@ static int log_crypto_error(const char *str, size_t len, void *arg) * Always appends a newline at the end. */ int -crypto_err(const char *format, ...) +op_crypto_err(const char *format, ...) { - unsigned int stack_size; + PR_OP_SIMPLE(LOG_ERR); - PR_SIMPLE(LOG_ERR); - - if (syslog_enabled) - syslog(LOG_ERR, " libcrypto error stack:"); - if (fprintf_enabled) - __fprintf(LOG_ERR, " libcrypto error stack:"); + return crypto_err(log_op_crypto_error, op_fprintf_enabled, + op_syslog_enabled, config_get_op_log_color_output(), + config_get_op_log_facility(), config_get_op_log_prefix()); +} - stack_size = 0; - ERR_print_errors_cb(log_crypto_error, &stack_size); - if (stack_size == 0) { - if (syslog_enabled) - syslog(LOG_ERR, " "); - if (fprintf_enabled) - __fprintf(LOG_ERR, " \n"); - } +/** + * This is like pr_err() and pr_errno(), except meant to log an error made + * during a libcrypto routine. + * + * This differs from usual printf-like functions: + * + * - It returns -EINVAL, not bytes written. + * - It prints a newline. + * - Also prints the cryptolib's error message stack. + * + * Always appends a newline at the end. + */ +int +val_crypto_err(const char *format, ...) +{ + PR_VAL_SIMPLE(LOG_ERR); - return -EINVAL; + return crypto_err(log_val_crypto_error, val_fprintf_enabled, + val_syslog_enabled, config_get_val_log_color_output(), + config_get_val_log_facility(), config_get_val_log_prefix()); } +/** + * This is an operation log + **/ int pr_enomem(void) { - if (syslog_enabled) - syslog(LOG_ERR, "Out of memory."); - if (fprintf_enabled) - __fprintf(LOG_ERR, "Out of memory.\n"); + if (op_syslog_enabled) + pr_simple_syslog(LOG_ERR, config_get_op_log_facility(), + config_get_op_log_prefix(), "Out of memory."); + if (op_fprintf_enabled) + __fprintf(LOG_ERR, config_get_op_log_prefix(), + config_get_op_log_color_output(), + "Out of memory.\n"); return -ENOMEM; } +/** + * This is an operation log + **/ __dead void pr_crit(const char *format, ...) { - PR_SIMPLE(LOG_CRIT); + PR_OP_SIMPLE(LOG_CRIT); print_stack_trace(); exit(-1); } @@ -343,10 +583,10 @@ incidence(enum incidence_id id, const char *format, ...) case INAC_IGNORE: return 0; case INAC_WARN: - PR_SIMPLE(LOG_WARNING); + PR_VAL_SIMPLE(LOG_WARNING); return 0; case INAC_ERROR: - PR_SIMPLE(LOG_ERR); + PR_VAL_SIMPLE(LOG_ERR); return -EINVAL; } diff --git a/src/log.h b/src/log.h index 4aa0dc5e..11f37383 100644 --- a/src/log.h +++ b/src/log.h @@ -51,19 +51,32 @@ void log_teardown(void); /* * Check if debug or info are enabled, useful to avoid boilerplate code */ -bool log_debug_enabled(void); -bool log_info_enabled(void); +bool log_val_debug_enabled(void); +bool log_op_debug_enabled(void); +bool log_op_info_enabled(void); /* Debug messages, useful for devs or to track a specific problem */ -void pr_debug(const char *, ...) CHECK_FORMAT(1, 2); +void pr_op_debug(const char *, ...) CHECK_FORMAT(1, 2); /* Non-errors deemed useful to the user. */ -void pr_info(const char *, ...) CHECK_FORMAT(1, 2); +void pr_op_info(const char *, ...) CHECK_FORMAT(1, 2); /* Issues that did not trigger RPKI object rejection. */ -int pr_warn(const char *, ...) CHECK_FORMAT(1, 2); +int pr_op_warn(const char *, ...) CHECK_FORMAT(1, 2); /* Errors that trigger RPKI object rejection. */ -int pr_err(const char *, ...) CHECK_FORMAT(1, 2); -int pr_errno(int, const char *, ...) CHECK_FORMAT(2, 3); -int crypto_err(const char *, ...) CHECK_FORMAT(1, 2); +int pr_op_err(const char *, ...) CHECK_FORMAT(1, 2); +int pr_op_errno(int, const char *, ...) CHECK_FORMAT(2, 3); +int op_crypto_err(const char *, ...) CHECK_FORMAT(1, 2); + +/* Debug messages, useful for devs or to track a specific problem */ +void pr_val_debug(const char *, ...) CHECK_FORMAT(1, 2); +/* Non-errors deemed useful to the user. */ +void pr_val_info(const char *, ...) CHECK_FORMAT(1, 2); +/* Issues that did not trigger RPKI object rejection. */ +int pr_val_warn(const char *, ...) CHECK_FORMAT(1, 2); +/* Errors that trigger RPKI object rejection. */ +int pr_val_err(const char *, ...) CHECK_FORMAT(1, 2); +int pr_val_errno(int, const char *, ...) CHECK_FORMAT(2, 3); +int val_crypto_err(const char *, ...) CHECK_FORMAT(1, 2); + int pr_enomem(void); /* Programming errors */ __dead void pr_crit(const char *, ...) CHECK_FORMAT(1, 2); diff --git a/src/nid.c b/src/nid.c index 15084a5b..d3ac3b55 100644 --- a/src/nid.c +++ b/src/nid.c @@ -21,9 +21,9 @@ register_oid(const char *oid, const char *sn, const char *ln) nid = OBJ_create(oid, sn, ln); if (nid == 0) - return crypto_err("Unable to register the %s NID.", sn); + return op_crypto_err("Unable to register the %s NID.", sn); - pr_debug("%s registered. Its nid is %d.", sn, nid); + pr_op_debug("%s registered. Its nid is %d.", sn, nid); return nid; } diff --git a/src/object/bgpsec.c b/src/object/bgpsec.c index a2e8b16d..e847efb1 100644 --- a/src/object/bgpsec.c +++ b/src/object/bgpsec.c @@ -15,7 +15,7 @@ asn_cb(unsigned long asn, void *arg) struct resource_params *params = arg; if (!resources_contains_asn(params->resources, asn)) - return pr_err("BGPsec certificate is not allowed for ASN %lu.", + return pr_val_err("BGPsec certificate is not allowed for ASN %lu.", asn); return vhandler_handle_router_key(params->ski, asn, params->spk); @@ -32,7 +32,7 @@ handle_bgpsec(X509 *cert, unsigned char const *ski, struct resources *resources) pub_key = X509_get_X509_PUBKEY(cert); if (pub_key == NULL) - return crypto_err("X509_get_X509_PUBKEY() returned NULL at BGPsec"); + return val_crypto_err("X509_get_X509_PUBKEY() returned NULL at BGPsec"); cert_spk = malloc(RK_SPKI_LEN); if (cert_spk == NULL) @@ -42,7 +42,7 @@ handle_bgpsec(X509 *cert, unsigned char const *ski, struct resources *resources) tmp = cert_spk; cert_spk_len = i2d_X509_PUBKEY(pub_key, &tmp); if(cert_spk_len < 0) - return crypto_err("i2d_X509_PUBKEY() returned error"); + return val_crypto_err("i2d_X509_PUBKEY() returned error"); res_params.spk = cert_spk; res_params.ski = ski; diff --git a/src/object/certificate.c b/src/object/certificate.c index 24ec82ba..5f6fa9c6 100644 --- a/src/object/certificate.c +++ b/src/object/certificate.c @@ -82,11 +82,11 @@ debug_serial_number(BIGNUM *number) number_str = BN_bn2dec(number); if (number_str == NULL) { - crypto_err("Could not convert BN to string"); + val_crypto_err("Could not convert BN to string"); return; } - pr_debug("serial Number: %s", number_str); + pr_val_debug("serial Number: %s", number_str); free(number_str); } @@ -103,9 +103,9 @@ validate_serial_number(X509 *cert) number = ASN1_INTEGER_to_BN(X509_get0_serialNumber(cert), NULL); if (number == NULL) - return crypto_err("Could not parse certificate serial number"); + return val_crypto_err("Could not parse certificate serial number"); - if (log_debug_enabled()) + if (log_val_debug_enabled()) debug_serial_number(number); error = x509stack_store_serial(validation_certstack(state), number); @@ -139,7 +139,7 @@ validate_issuer(X509 *cert, bool is_ta) error = x509_name_decode(issuer, "issuer", &name); if (error) return error; - pr_debug("Issuer: %s", x509_name_commonName(name)); + pr_val_debug("Issuer: %s", x509_name_commonName(name)); x509_name_put(name); return 0; @@ -164,11 +164,11 @@ spki_cmp(X509_PUBKEY *tal_spki, X509_PUBKEY *cert_spki, ok = X509_PUBKEY_get0_param(&tal_alg, &tal_spk, &tal_spk_len, NULL, tal_spki); if (!ok) - return crypto_err("X509_PUBKEY_get0_param() 1 returned %d", ok); + return val_crypto_err("X509_PUBKEY_get0_param() 1 returned %d", ok); ok = X509_PUBKEY_get0_param(&cert_alg, &cert_spk, &cert_spk_len, NULL, cert_spki); if (!ok) - return crypto_err("X509_PUBKEY_get0_param() 2 returned %d", ok); + return val_crypto_err("X509_PUBKEY_get0_param() 2 returned %d", ok); if (OBJ_cmp(tal_alg, cert_alg) != 0) return diff_alg_cb(); @@ -258,21 +258,21 @@ check_dup_public_key(bool *duplicated, char const *file, void *arg) tmp_size); free(tmp); /* Release at once */ if (rcvd_cert == NULL) { - error = crypto_err("Signed object's '%s' 'certificate' element does not decode into a Certificate", - uri_get_printable(uri)); + error = val_crypto_err("Signed object's '%s' 'certificate' element does not decode into a Certificate", + uri_val_get_printable(uri)); goto free_uri; } } curr_pk = X509_get_X509_PUBKEY(curr_cert); if (curr_pk == NULL) { - error = crypto_err("X509_get_X509_PUBKEY() returned NULL"); + error = val_crypto_err("X509_get_X509_PUBKEY() returned NULL"); goto free_cert; } rcvd_pk = X509_get_X509_PUBKEY(rcvd_cert); if (rcvd_pk == NULL) { - error = crypto_err("X509_get_X509_PUBKEY() returned NULL"); + error = val_crypto_err("X509_get_X509_PUBKEY() returned NULL"); goto free_cert; } @@ -314,7 +314,7 @@ validate_subject(X509 *cert) error = x509_name_decode(X509_get_subject_name(cert), "subject", &name); if (error) return error; - pr_debug("Subject: %s", x509_name_commonName(name)); + pr_val_debug("Subject: %s", x509_name_commonName(name)); error = x509stack_store_subject(validation_certstack(state), name, check_dup_public_key, cert); @@ -326,13 +326,13 @@ validate_subject(X509 *cert) static int root_different_alg_err(void) { - return pr_err("TAL's public key algorithm is different than the root certificate's public key algorithm."); + return pr_val_err("TAL's public key algorithm is different than the root certificate's public key algorithm."); } static int root_different_pk_err(void) { - return pr_err("TAL's public key is different than the root certificate's public key."); + return pr_val_err("TAL's public key is different than the root certificate's public key."); } static int @@ -377,7 +377,7 @@ validate_spki(X509_PUBKEY *cert_spki) fnstack_pop(); if (tal_spki == NULL) { - crypto_err("The TAL's public key cannot be decoded"); + op_crypto_err("The TAL's public key cannot be decoded"); goto fail1; } @@ -414,24 +414,24 @@ validate_subject_public_key(X509_PUBKEY *pubkey) rsa = EVP_PKEY_get0_RSA(X509_PUBKEY_get0(pubkey)); if (rsa == NULL) - return crypto_err("EVP_PKEY_get0_RSA() returned NULL"); + return val_crypto_err("EVP_PKEY_get0_RSA() returned NULL"); modulus = RSA_bits(rsa); if (modulus != MODULUS) - return pr_err("Certificate's subjectPublicKey (RSAPublicKey) modulus is %d bits, not %d bits.", + return pr_val_err("Certificate's subjectPublicKey (RSAPublicKey) modulus is %d bits, not %d bits.", modulus, MODULUS); RSA_get0_key(rsa, NULL, &exp, NULL); if (exp == NULL) - return pr_err("Certificate's subjectPublicKey (RSAPublicKey) exponent isn't set, must be " + return pr_val_err("Certificate's subjectPublicKey (RSAPublicKey) exponent isn't set, must be " EXPONENT " bits."); exp_str = BN_bn2dec(exp); if (exp_str == NULL) - return crypto_err("Couldn't get subjectPublicKey exponent string"); + return val_crypto_err("Couldn't get subjectPublicKey exponent string"); if (strcmp(EXPONENT, exp_str) != 0) { - error = pr_err("Certificate's subjectPublicKey (RSAPublicKey) exponent is %s, must be " + error = pr_val_err("Certificate's subjectPublicKey (RSAPublicKey) exponent is %s, must be " EXPONENT " bits.", exp_str); free(exp_str); return error; @@ -455,11 +455,11 @@ validate_public_key(X509 *cert, enum cert_type type) /* Reminder: X509_PUBKEY is the same as SubjectPublicKeyInfo. */ pubkey = X509_get_X509_PUBKEY(cert); if (pubkey == NULL) - return crypto_err("X509_get_X509_PUBKEY() returned NULL"); + return val_crypto_err("X509_get_X509_PUBKEY() returned NULL"); ok = X509_PUBKEY_get0_param(&alg, NULL, NULL, &pa, pubkey); if (!ok) - return crypto_err("X509_PUBKEY_get0_param() returned %d", ok); + return val_crypto_err("X509_PUBKEY_get0_param() returned %d", ok); if (type == BGPSEC) return validate_certificate_public_key_algorithm_bgpsec(pa); @@ -513,7 +513,7 @@ certificate_validate_rfc6487(X509 *cert, enum cert_type type) /* rfc6487#section-4.1 */ if (X509_get_version(cert) != 2) - return pr_err("Certificate version is not v3."); + return pr_val_err("Certificate version is not v3."); /* rfc6487#section-4.2 */ error = validate_serial_number(cert); @@ -703,16 +703,16 @@ certificate_validate_signature(X509 *cert, ANY_t *signedData, public_key = X509_get_X509_PUBKEY(cert); if (public_key == NULL) - return crypto_err("Certificate seems to lack a public key"); + return val_crypto_err("Certificate seems to lack a public key"); /* Create the Message Digest Context */ ctx = EVP_MD_CTX_create(); if (ctx == NULL) - return crypto_err("EVP_MD_CTX_create() error"); + return val_crypto_err("EVP_MD_CTX_create() error"); if (1 != EVP_DigestVerifyInit(ctx, NULL, EVP_sha256(), NULL, X509_PUBKEY_get0(public_key))) { - error = crypto_err("EVP_DigestVerifyInit() error"); + error = val_crypto_err("EVP_DigestVerifyInit() error"); goto end; } @@ -769,19 +769,19 @@ certificate_validate_signature(X509 *cert, ANY_t *signedData, error = EVP_DigestVerifyUpdate(ctx, &EXPLICIT_SET_OF_TAG, sizeof(EXPLICIT_SET_OF_TAG)); if (1 != error) { - error = crypto_err("EVP_DigestVerifyInit() error"); + error = val_crypto_err("EVP_DigestVerifyInit() error"); goto end; } error = EVP_DigestVerifyUpdate(ctx, signedAttrs.buffer, signedAttrs.size); if (1 != error) { - error = crypto_err("EVP_DigestVerifyInit() error"); + error = val_crypto_err("EVP_DigestVerifyInit() error"); goto end; } if (1 != EVP_DigestVerifyFinal(ctx, signature->buf, signature->size)) { - error = crypto_err("Signed Object's signature is invalid"); + error = val_crypto_err("Signed Object's signature is invalid"); goto end; } @@ -801,15 +801,15 @@ certificate_load(struct rpki_uri *uri, X509 **result) bio = BIO_new(BIO_s_file()); if (bio == NULL) - return crypto_err("BIO_new(BIO_s_file()) returned NULL"); + return val_crypto_err("BIO_new(BIO_s_file()) returned NULL"); if (BIO_read_filename(bio, uri_get_local(uri)) <= 0) { - error = crypto_err("Error reading certificate"); + error = val_crypto_err("Error reading certificate"); goto end; } cert = d2i_X509_bio(bio, NULL); if (cert == NULL) { - error = crypto_err("Error parsing certificate"); + error = val_crypto_err("Error parsing certificate"); goto end; } @@ -839,14 +839,14 @@ certificate_validate_chain(X509 *cert, STACK_OF(X509_CRL) *crls) ctx = X509_STORE_CTX_new(); if (ctx == NULL) { - crypto_err("X509_STORE_CTX_new() returned NULL"); + val_crypto_err("X509_STORE_CTX_new() returned NULL"); return -EINVAL; } /* Returns 0 or 1 , all callers test ! only. */ ok = X509_STORE_CTX_init(ctx, validation_store(state), cert, NULL); if (!ok) { - crypto_err("X509_STORE_CTX_init() returned %d", ok); + val_crypto_err("X509_STORE_CTX_init() returned %d", ok); goto abort; } @@ -866,12 +866,12 @@ certificate_validate_chain(X509 *cert, STACK_OF(X509_CRL) *crls) if (ok <= 0) { /* * ARRRRGGGGGGGGGGGGG - * Do not use crypto_err() here; for some reason the proper + * Do not use val_crypto_err() here; for some reason the proper * error code is stored in the context. */ error = X509_STORE_CTX_get_error(ctx); if (error) { - pr_err("Certificate validation failed: %s", + pr_val_err("Certificate validation failed: %s", X509_verify_cert_error_string(error)); } else { /* @@ -879,7 +879,7 @@ certificate_validate_chain(X509 *cert, STACK_OF(X509_CRL) *crls) * That said, there's not much to do about !error, * so hope for the best. */ - crypto_err("Certificate validation failed: %d", ok); + val_crypto_err("Certificate validation failed: %d", ok); } goto abort; @@ -919,17 +919,17 @@ handle_ip_extension(X509_EXTENSION *ext, struct resources *resources) case 2: family = &blocks->list.array[0]->addressFamily; if (get_addr_family(family) != AF_INET) { - error = pr_err("First IP address block listed is not v4."); + error = pr_val_err("First IP address block listed is not v4."); goto end; } family = &blocks->list.array[1]->addressFamily; if (get_addr_family(family) != AF_INET6) { - error = pr_err("Second IP address block listed is not v6."); + error = pr_val_err("Second IP address block listed is not v6."); goto end; } break; default: - error = pr_err("Got %d IP address blocks Expected; 1 or 2 expected.", + error = pr_val_err("Got %d IP address blocks Expected; 1 or 2 expected.", blocks->list.count); goto end; } @@ -983,13 +983,13 @@ __certificate_get_resources(X509 *cert, struct resources *resources, if (nid == addr_nid) { if (ip_ext_found) - return pr_err("Multiple IP extensions found."); + return pr_val_err("Multiple IP extensions found."); if (!X509_EXTENSION_get_critical(ext)) - return pr_err("The IP extension is not marked as critical."); + return pr_val_err("The IP extension is not marked as critical."); - pr_debug("IP {"); + pr_val_debug("IP {"); error = handle_ip_extension(ext, resources); - pr_debug("}"); + pr_val_debug("}"); ip_ext_found = true; if (error) @@ -997,30 +997,30 @@ __certificate_get_resources(X509 *cert, struct resources *resources, } else if (nid == asn_nid) { if (asn_ext_found) - return pr_err("Multiple AS extensions found."); + return pr_val_err("Multiple AS extensions found."); if (!X509_EXTENSION_get_critical(ext)) - return pr_err("The AS extension is not marked as critical."); + return pr_val_err("The AS extension is not marked as critical."); - pr_debug("ASN {"); + pr_val_debug("ASN {"); error = handle_asn_extension(ext, resources, allow_asn_inherit); - pr_debug("}"); + pr_val_debug("}"); asn_ext_found = true; if (error) return error; } else if (nid == bad_addr_nid) { - return pr_err("Certificate has an RFC%s policy, but contains an RFC%s IP extension.", + return pr_val_err("Certificate has an RFC%s policy, but contains an RFC%s IP extension.", policy_rfc, bad_ext_rfc); } else if (nid == bad_asn_nid) { - return pr_err("Certificate has an RFC%s policy, but contains an RFC%s ASN extension.", + return pr_val_err("Certificate has an RFC%s policy, but contains an RFC%s ASN extension.", policy_rfc, bad_ext_rfc); } } if (!ip_ext_found && !asn_ext_found) - return pr_err("Certificate lacks both IP and AS extension."); + return pr_val_err("Certificate lacks both IP and AS extension."); return 0; } @@ -1079,7 +1079,7 @@ static int handle_caRepository(struct rpki_uri *uri, uint8_t pos, void *arg) { struct sia_uri *repo = arg; - pr_debug("caRepository: %s", uri_get_printable(uri)); + pr_val_debug("caRepository: %s", uri_val_get_printable(uri)); repo->position = pos; repo->uri = uri; uri_refget(uri); @@ -1090,7 +1090,7 @@ static int handle_rpkiNotify(struct rpki_uri *uri, uint8_t pos, void *arg) { struct sia_uri *notify = arg; - pr_debug("rpkiNotify: %s", uri_get_printable(uri)); + pr_val_debug("rpkiNotify: %s", uri_val_get_printable(uri)); notify->position = pos; notify->uri = uri; uri_refget(uri); @@ -1101,7 +1101,7 @@ static int handle_signedObject(struct rpki_uri *uri, uint8_t pos, void *arg) { struct certificate_refs *refs = arg; - pr_debug("signedObject: %s", uri_get_printable(uri)); + pr_val_debug("signedObject: %s", uri_val_get_printable(uri)); refs->signedObject = uri; uri_refget(uri); return 0; @@ -1125,7 +1125,7 @@ handle_bc(X509_EXTENSION *ext, void *arg) error = (bc->pathlen == NULL) ? 0 - : pr_err("%s extension contains a Path Length Constraint.", + : pr_val_err("%s extension contains a Path Length Constraint.", ext_bc()->name); BASIC_CONSTRAINTS_free(bc); @@ -1170,7 +1170,7 @@ handle_ski_ee(X509_EXTENSION *ext, void *arg) sid = args->sid; if (ski->length != sid->size || memcmp(ski->data, sid->buf, sid->size) != 0) { - error = pr_err("The EE certificate's subjectKeyIdentifier does not equal the Signed Object's sid."); + error = pr_val_err("The EE certificate's subjectKeyIdentifier does not equal the Signed Object's sid."); } end: @@ -1219,21 +1219,21 @@ handle_aki_ta(X509_EXTENSION *ext, void *arg) if (aki == NULL) return cannot_decode(ext_aki()); if (aki->keyid == NULL) { - error = pr_err("The '%s' extension lacks a keyIdentifier.", + error = pr_val_err("The '%s' extension lacks a keyIdentifier.", ext_aki()->name); goto revert_aki; } ski = X509_get_ext_d2i(arg, NID_subject_key_identifier, NULL, NULL); if (ski == NULL) { - pr_err("Certificate lacks the '%s' extension.", + pr_val_err("Certificate lacks the '%s' extension.", ext_ski()->name); error = -ESRCH; goto revert_aki; } if (ASN1_OCTET_STRING_cmp(aki->keyid, ski) != 0) { - error = pr_err("The '%s' does not equal the '%s'.", + error = pr_val_err("The '%s' does not equal the '%s'.", ext_aki()->name, ext_ski()->name); goto revert_ski; } @@ -1265,7 +1265,7 @@ handle_ku(X509_EXTENSION *ext, unsigned char byte1) return cannot_decode(ext_ku()); if (ku->length == 0) { - error = pr_err("%s bit string has no enabled bits.", + error = pr_val_err("%s bit string has no enabled bits.", ext_ku()->name); goto end; } @@ -1274,7 +1274,7 @@ handle_ku(X509_EXTENSION *ext, unsigned char byte1) memcpy(data, ku->data, ku->length); if (ku->data[0] != byte1) { - error = pr_err("Illegal key usage flag string: %d%d%d%d%d%d%d%d%d", + error = pr_val_err("Illegal key usage flag string: %d%d%d%d%d%d%d%d%d", !!(ku->data[0] & 0x80u), !!(ku->data[0] & 0x40u), !!(ku->data[0] & 0x20u), !!(ku->data[0] & 0x10u), !!(ku->data[0] & 0x08u), !!(ku->data[0] & 0x04u), @@ -1317,7 +1317,7 @@ handle_cdp(X509_EXTENSION *ext, void *arg) return cannot_decode(ext_cdp()); if (sk_DIST_POINT_num(crldp) != 1) { - error = pr_err("The %s extension has %d distribution points. (1 expected)", + error = pr_val_err("The %s extension has %d distribution points. (1 expected)", ext_cdp()->name, sk_DIST_POINT_num(crldp)); goto end; } @@ -1376,7 +1376,7 @@ handle_cdp(X509_EXTENSION *ext, void *arg) error_msg = "lacks an RSYNC URI"; dist_point_error: - error = pr_err("The %s extension's distribution point %s.", + error = pr_val_err("The %s extension's distribution point %s.", ext_cdp()->name, error_msg); end: @@ -1438,7 +1438,7 @@ handle_ad(char const *ia_name, SIGNATURE_INFO_ACCESS *ia, if (found) { uri_refput(uri); - return pr_err("Extension '%s' has multiple '%s' %s URIs.", + return pr_val_err("Extension '%s' has multiple '%s' %s URIs.", ia_name, ad_name, AD_METHOD); } @@ -1454,7 +1454,7 @@ handle_ad(char const *ia_name, SIGNATURE_INFO_ACCESS *ia, } if (required && !found) { - pr_err("Extension '%s' lacks a '%s' valid %s URI.", ia_name, + pr_val_err("Extension '%s' lacks a '%s' valid %s URI.", ia_name, ad_name, AD_METHOD); return -ESRCH; } @@ -1561,7 +1561,7 @@ handle_cp(X509_EXTENSION *ext, void *arg) return cannot_decode(ext_cp()); if (sk_POLICYINFO_num(cp) != 1) { - error = pr_err("The %s extension has %d policy information's. (1 expected)", + error = pr_val_err("The %s extension has %d policy information's. (1 expected)", ext_cp()->name, sk_POLICYINFO_num(cp)); goto end; } @@ -1573,11 +1573,11 @@ handle_cp(X509_EXTENSION *ext, void *arg) if (policy != NULL) *policy = RPKI_POLICY_RFC6484; } else if (nid_cp == nid_certPolicyRpkiV2()) { - pr_debug("Found RFC8360 policy!"); + pr_val_debug("Found RFC8360 policy!"); if (policy != NULL) *policy = RPKI_POLICY_RFC8360; } else { - error = pr_err("Invalid certificate policy OID, isn't 'id-cp-ipAddr-asNumber' nor 'id-cp-ipAddr-asNumber-v2'"); + error = pr_val_err("Invalid certificate policy OID, isn't 'id-cp-ipAddr-asNumber' nor 'id-cp-ipAddr-asNumber-v2'"); goto end; } @@ -1589,7 +1589,7 @@ handle_cp(X509_EXTENSION *ext, void *arg) if (pqi_num == 0) goto end; if (pqi_num != 1) { - error = pr_err("The %s extension has %d policy qualifiers. (none or only 1 expected)", + error = pr_val_err("The %s extension has %d policy qualifiers. (none or only 1 expected)", ext_cp()->name, pqi_num); goto end; } @@ -1597,7 +1597,7 @@ handle_cp(X509_EXTENSION *ext, void *arg) pqi = sk_POLICYQUALINFO_value(pi->qualifiers, 0); nid_qt_cps = OBJ_obj2nid(pqi->pqualid); if (nid_qt_cps != NID_id_qt_cps) { - error = pr_err("Policy qualifier ID isn't Certification Practice Statement (CPS)"); + error = pr_val_err("Policy qualifier ID isn't Certification Practice Statement (CPS)"); goto end; } end: @@ -1642,7 +1642,7 @@ handle_eku(X509_EXTENSION *ext, void *arg) } if (error) - pr_err("Extended Key Usage doesn't include id-kp-bgpsec-router."); + pr_val_err("Extended Key Usage doesn't include id-kp-bgpsec-router."); end: EXTENDED_KEY_USAGE_free(eku); return error; @@ -1787,7 +1787,7 @@ force_aia_validation(struct rpki_uri *caIssuers, void *arg) struct rfc5280_name *parent_name; int error; - pr_debug("AIA's URI didn't matched parent URI, doing AIA RSYNC"); + pr_val_debug("AIA's URI didn't matched parent URI, doing AIA RSYNC"); /* RSYNC is still the prefered access mechanism */ error = download_files(caIssuers, false, false); @@ -1811,8 +1811,8 @@ force_aia_validation(struct rpki_uri *caIssuers, void *arg) if (x509_name_equals(parent_name, son_name)) error = 0; /* Everything its ok */ else - error = pr_err("Certificate subject from AIA ('%s') isn't issuer of this certificate.", - uri_get_printable(caIssuers)); + error = pr_val_err("Certificate subject from AIA ('%s') isn't issuer of this certificate.", + uri_val_get_printable(caIssuers)); x509_name_put(son_name); free_parent_name: @@ -1884,7 +1884,8 @@ certificate_validate_aia(struct rpki_uri *caIssuers, X509 *cert) static int verify_mft_loc(struct rpki_uri *mft_uri) { - if (!valid_file_or_dir(uri_get_local(mft_uri), true, false)) + if (!valid_file_or_dir(uri_get_local(mft_uri), true, false, + pr_val_errno)) return -EINVAL; /* Error already logged */ return 0; @@ -1987,16 +1988,16 @@ use_access_method(struct sia_ca_uris *sia_uris, if (primary_rrdp) { working_repo_push(uri_get_global(sia_uris->rpkiNotify.uri)); if (error != -EPERM) - pr_info("Couldn't fetch data from RRDP repository '%s', trying to fetch data now from '%s'.", + pr_val_info("Couldn't fetch data from RRDP repository '%s', trying to fetch data now from '%s'.", uri_get_global(sia_uris->rpkiNotify.uri), uri_get_global(sia_uris->caRepository.uri)); else - pr_info("RRDP repository '%s' download/processing returned error previously, now I will try to fetch data from '%s'.", + pr_val_info("RRDP repository '%s' download/processing returned error previously, now I will try to fetch data from '%s'.", uri_get_global(sia_uris->rpkiNotify.uri), uri_get_global(sia_uris->caRepository.uri)); } else { working_repo_push(uri_get_global(sia_uris->caRepository.uri)); - pr_info("Couldn't fetch data from repository '%s', trying to fetch data now from RRDP '%s'.", + pr_val_info("Couldn't fetch data from repository '%s', trying to fetch data now from RRDP '%s'.", uri_get_global(sia_uris->caRepository.uri), uri_get_global(sia_uris->rpkiNotify.uri)); } @@ -2130,15 +2131,15 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) return -EINVAL; total_parents = certstack_get_x509_num(validation_certstack(state)); if (total_parents >= config_get_max_cert_depth()) - return pr_err("Certificate chain maximum depth exceeded."); + return pr_val_err("Certificate chain maximum depth exceeded."); /* Debug cert type */ if (IS_TA) - pr_debug("TA Certificate '%s' {", - uri_get_printable(cert_uri)); + pr_val_debug("TA Certificate '%s' {", + uri_val_get_printable(cert_uri)); else - pr_debug("Certificate '%s' {", - uri_get_printable(cert_uri)); + pr_val_debug("Certificate '%s' {", + uri_val_get_printable(cert_uri)); fnstack_push_uri(cert_uri); memset(&refs, 0, sizeof(refs)); @@ -2163,13 +2164,13 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) case TA: break; case CA: - pr_debug("Type: CA"); + pr_val_debug("Type: CA"); break; case BGPSEC: - pr_debug("Type: BGPsec EE"); + pr_val_debug("Type: BGPsec EE"); break; case EE: - pr_debug("Type: unexpected, validated as CA"); + pr_val_debug("Type: unexpected, validated as CA"); break; } @@ -2257,8 +2258,8 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) * - RRDP was utilized to fetch the manifest. * - There was a previous attempt to re-fetch the repository. */ - pr_info("Retrying repository download to discard 'transient inconsistency' manifest issue (see RFC 6481 section 5) '%s'", - uri_get_printable(sia_uris.caRepository.uri)); + pr_val_info("Retrying repository download to discard 'transient inconsistency' manifest issue (see RFC 6481 section 5) '%s'", + uri_val_get_printable(sia_uris.caRepository.uri)); error = download_files(sia_uris.caRepository.uri, false, true); if (error) break; @@ -2290,6 +2291,6 @@ revert_cert: X509_free(cert); revert_fnstack_and_debug: fnstack_pop(); - pr_debug("}"); + pr_val_debug("}"); return error; } diff --git a/src/object/crl.c b/src/object/crl.c index 53144960..ebf28332 100644 --- a/src/object/crl.c +++ b/src/object/crl.c @@ -16,17 +16,17 @@ __crl_load(struct rpki_uri *uri, X509_CRL **result) bio = BIO_new(BIO_s_file()); if (bio == NULL) - return crypto_err("BIO_new(BIO_s_file()) returned NULL"); + return val_crypto_err("BIO_new(BIO_s_file()) returned NULL"); if (BIO_read_filename(bio, uri_get_local(uri)) <= 0) { - error = crypto_err("Error reading CRL '%s'", - uri_get_printable(uri)); + error = val_crypto_err("Error reading CRL '%s'", + uri_val_get_printable(uri)); goto end; } crl = d2i_X509_CRL_bio(bio, NULL); if (crl == NULL) { - error = crypto_err("Error parsing CRL '%s'", - uri_get_printable(uri)); + error = val_crypto_err("Error parsing CRL '%s'", + uri_val_get_printable(uri)); goto end; } @@ -46,17 +46,17 @@ debug_revoked(ASN1_INTEGER const *serial_int) serial_bn = ASN1_INTEGER_to_BN(serial_int, NULL); if (serial_bn == NULL) { - crypto_err("Could not parse revoked serial number"); + val_crypto_err("Could not parse revoked serial number"); return; } serial_str = BN_bn2dec(serial_bn); if (serial_str == NULL) { - crypto_err("Could not convert BN to string"); + val_crypto_err("Could not convert BN to string"); goto end; } - pr_debug("Revoked: %s", serial_str); + pr_val_debug("Revoked: %s", serial_str); free(serial_str); end: BN_free(serial_bn); @@ -79,19 +79,19 @@ validate_revoked(X509_CRL *crl) serial_int = X509_REVOKED_get0_serialNumber(revoked); if (serial_int == NULL) { - return pr_err("CRL's revoked entry #%d lacks a serial number.", + return pr_val_err("CRL's revoked entry #%d lacks a serial number.", i + 1); } - if (log_debug_enabled()) + if (log_val_debug_enabled()) debug_revoked(serial_int); if (X509_REVOKED_get0_revocationDate(revoked) == NULL) { - return pr_err("CRL's revoked entry #%d lacks a revocation date.", + return pr_val_err("CRL's revoked entry #%d lacks a revocation date.", i + 1); } if (X509_REVOKED_get0_extensions(revoked) != NULL) { - return pr_err("CRL's revoked entry #%d has extensions.", + return pr_val_err("CRL's revoked entry #%d has extensions.", i + 1); } } @@ -130,7 +130,7 @@ crl_validate(X509_CRL *crl) version = X509_CRL_get_version(crl); if (version != 1) - return pr_err("CRL version (%ld) is not v2 (%d).", version, 1); + return pr_val_err("CRL version (%ld) is not v2 (%d).", version, 1); error = validate_certificate_signature_algorithm( X509_CRL_get_signature_nid(crl), "CRL"); @@ -152,12 +152,12 @@ int crl_load(struct rpki_uri *uri, X509_CRL **result) { int error; - pr_debug("CRL '%s' {", uri_get_printable(uri)); + pr_val_debug("CRL '%s' {", uri_val_get_printable(uri)); error = __crl_load(uri, result); if (!error) error = crl_validate(*result); - pr_debug("}"); + pr_val_debug("}"); return error; } diff --git a/src/object/ghostbusters.c b/src/object/ghostbusters.c index 46abc41d..b9372c9e 100644 --- a/src/object/ghostbusters.c +++ b/src/object/ghostbusters.c @@ -25,7 +25,7 @@ ghostbusters_traverse(struct rpki_uri *uri, struct rpp *pp) int error; /* Prepare */ - pr_debug("Ghostbusters '%s' {", uri_get_printable(uri)); + pr_val_debug("Ghostbusters '%s' {", uri_val_get_printable(uri)); fnstack_push_uri(uri); /* Decode */ @@ -55,7 +55,7 @@ revert_args: revert_sobj: signed_object_cleanup(&sobj); revert_log: - pr_debug("}"); + pr_val_debug("}"); fnstack_pop(); return error; } diff --git a/src/object/manifest.c b/src/object/manifest.c index d1e160b5..556665b0 100644 --- a/src/object/manifest.c +++ b/src/object/manifest.c @@ -53,7 +53,7 @@ validate_dates(GeneralizedTime_t *this, GeneralizedTime_t *next) nextUpdate = asn_GT2time(next, &nextUpdate_tm, false); if (difftime(thisUpdate, nextUpdate) > 0) { - return pr_err( + return pr_val_err( "Manifest's thisUpdate (" TM_FMT ") > nextUpdate (" TM_FMT ").", TM_ARGS(thisUpdate_tm), @@ -66,12 +66,12 @@ validate_dates(GeneralizedTime_t *this, GeneralizedTime_t *next) return error; if (difftime(now, thisUpdate) < 0) { - return pr_err( + return pr_val_err( "Manifest is not valid yet. (thisUpdate: " TM_FMT ")", TM_ARGS(thisUpdate_tm)); } if (difftime(now, nextUpdate) > 0) { - return pr_err( + return pr_val_err( "Manifest is expired. (nextUpdate: " TM_FMT ")", TM_ARGS(nextUpdate_tm)); } @@ -112,8 +112,8 @@ validate_manifest(struct Manifest *manifest) error = asn_INTEGER2ulong(manifest->version, &version); if (error) { if (errno) - pr_errno(errno, "Error casting manifest version"); - return pr_err("The manifest version isn't a valid unsigned long"); + pr_val_errno(errno, "Error casting manifest version"); + return pr_val_err("The manifest version isn't a valid unsigned long"); } if (version != 0) return -EINVAL; @@ -124,7 +124,7 @@ validate_manifest(struct Manifest *manifest) * 20 octets." */ if (manifest->manifestNumber.size > 20) - return pr_err("Manifest number is larger than 20 octets"); + return pr_val_err("Manifest number is larger than 20 octets"); /* rfc6486#section-4.4.3 */ error = validate_dates(&manifest->thisUpdate, &manifest->nextUpdate); @@ -212,7 +212,7 @@ build_rpp(struct Manifest *mft, struct rpki_uri *mft_uri, struct rpp **pp) /* rfc6486#section-7 */ if (rpp_get_crl(*pp) == NULL) { - error = pr_err("Manifest lacks a CRL."); + error = pr_val_err("Manifest lacks a CRL."); goto fail; } @@ -239,7 +239,7 @@ handle_manifest(struct rpki_uri *uri, struct rpp **pp) int error; /* Prepare */ - pr_debug("Manifest '%s' {", uri_get_printable(uri)); + pr_val_debug("Manifest '%s' {", uri_val_get_printable(uri)); fnstack_push_uri(uri); /* Decode */ @@ -287,7 +287,7 @@ revert_manifest: revert_sobj: signed_object_cleanup(&sobj); revert_log: - pr_debug("}"); + pr_val_debug("}"); fnstack_pop(); return error; } diff --git a/src/object/name.c b/src/object/name.c index dc981b78..8354d5b3 100644 --- a/src/object/name.c +++ b/src/object/name.c @@ -27,7 +27,7 @@ name2string(X509_NAME_ENTRY *name, char **_result) data = X509_NAME_ENTRY_get_data(name); if (data == NULL) - return crypto_err("X509_NAME_ENTRY_get_data() returned NULL"); + return val_crypto_err("X509_NAME_ENTRY_get_data() returned NULL"); result = malloc(data->length + 1); if (result == NULL) @@ -69,7 +69,7 @@ x509_name_decode(X509_NAME *name, char const *what, error = name2string(entry, &result->serialNumber); break; default: - error = pr_err("The '%s' name has an unknown attribute. (NID: %d)", + error = pr_val_err("The '%s' name has an unknown attribute. (NID: %d)", what, nid); break; } @@ -79,7 +79,7 @@ x509_name_decode(X509_NAME *name, char const *what, } if (result->commonName == NULL) { - error = pr_err("The '%s' name lacks a commonName attribute.", + error = pr_val_err("The '%s' name lacks a commonName attribute.", what); goto fail; } @@ -163,7 +163,7 @@ validate_issuer_name(char const *container, X509_NAME *issuer) return -EINVAL; parent = x509stack_peek(validation_certstack(state)); if (parent == NULL) { - return pr_err("%s appears to have no parent certificate.", + return pr_val_err("%s appears to have no parent certificate.", container); } @@ -174,7 +174,7 @@ validate_issuer_name(char const *container, X509_NAME *issuer) error = x509_name_decode(issuer, "issuer", &child_issuer); if (error) goto end; - pr_debug("Issuer: %s", child_issuer->commonName); + pr_val_debug("Issuer: %s", child_issuer->commonName); if (!x509_name_equals(parent_subject, child_issuer)) { char const *parent_serial; @@ -183,7 +183,7 @@ validate_issuer_name(char const *container, X509_NAME *issuer) parent_serial = x509_name_serialNumber(parent_subject); child_serial = x509_name_serialNumber(child_issuer); - error = pr_err("%s's issuer name ('%s%s%s') does not equal issuer certificate's name ('%s%s%s').", + error = pr_val_err("%s's issuer name ('%s%s%s') does not equal issuer certificate's name ('%s%s%s').", container, x509_name_commonName(child_issuer), (child_serial != NULL) ? "/" : "", @@ -201,19 +201,19 @@ end: x509_name_put(parent_subject); void x509_name_pr_debug(const char *prefix, X509_NAME *name) { - if (!log_debug_enabled()) + if (!log_val_debug_enabled()) return; struct rfc5280_name *printable; if (name == NULL) { - pr_debug("%s: (null)", prefix); + pr_val_debug("%s: (null)", prefix); return; } if (x509_name_decode(name, prefix, &printable) != 0) return; /* Error message already printed */ - pr_debug("%s: %s", prefix, printable->commonName); + pr_val_debug("%s: %s", prefix, printable->commonName); x509_name_put(printable); } diff --git a/src/object/roa.c b/src/object/roa.c index 4407f769..77c1cab1 100644 --- a/src/object/roa.c +++ b/src/object/roa.c @@ -36,27 +36,27 @@ ____handle_roa_v4(struct resources *parent, unsigned long asn, if (error) return error; - pr_debug("ROAIPAddress {"); - pr_debug("address: %s/%u", v4addr2str(&prefix.addr), prefix.len); + pr_val_debug("ROAIPAddress {"); + pr_val_debug("address: %s/%u", v4addr2str(&prefix.addr), prefix.len); if (roa_addr->maxLength != NULL) { error = asn_INTEGER2ulong(roa_addr->maxLength, &max_length); if (error) { if (errno) - pr_errno(errno, "Error casting ROA's IPv4 maxLength"); - error = pr_err("The ROA's IPv4 maxLength isn't a valid unsigned long"); + pr_val_errno(errno, "Error casting ROA's IPv4 maxLength"); + error = pr_val_err("The ROA's IPv4 maxLength isn't a valid unsigned long"); goto end_error; } - pr_debug("maxLength: %lu", max_length); + pr_val_debug("maxLength: %lu", max_length); if (max_length > 32) { - error = pr_err("maxLength (%lu) is out of bounds (0-32).", + error = pr_val_err("maxLength (%lu) is out of bounds (0-32).", max_length); goto end_error; } if (prefix.len > max_length) { - error = pr_err("Prefix length (%u) > maxLength (%lu)", + error = pr_val_err("Prefix length (%u) > maxLength (%lu)", prefix.len, max_length); goto end_error; } @@ -66,15 +66,15 @@ ____handle_roa_v4(struct resources *parent, unsigned long asn, } if (!resources_contains_ipv4(parent, &prefix)) { - error = pr_err("ROA is not allowed to advertise %s/%u.", + error = pr_val_err("ROA is not allowed to advertise %s/%u.", v4addr2str(&prefix.addr), prefix.len); goto end_error; } - pr_debug("}"); + pr_val_debug("}"); return vhandler_handle_roa_v4(asn, &prefix, max_length); end_error: - pr_debug("}"); + pr_val_debug("}"); return error; } @@ -90,27 +90,27 @@ ____handle_roa_v6(struct resources *parent, unsigned long asn, if (error) return error; - pr_debug("ROAIPAddress {"); - pr_debug("address: %s/%u", v6addr2str(&prefix.addr), prefix.len); + pr_val_debug("ROAIPAddress {"); + pr_val_debug("address: %s/%u", v6addr2str(&prefix.addr), prefix.len); if (roa_addr->maxLength != NULL) { error = asn_INTEGER2ulong(roa_addr->maxLength, &max_length); if (error) { if (errno) - pr_errno(errno, "Error casting ROA's IPv6 maxLength"); - error = pr_err("The ROA's IPv6 maxLength isn't a valid unsigned long"); + pr_val_errno(errno, "Error casting ROA's IPv6 maxLength"); + error = pr_val_err("The ROA's IPv6 maxLength isn't a valid unsigned long"); goto end_error; } - pr_debug("maxLength: %lu", max_length); + pr_val_debug("maxLength: %lu", max_length); if (max_length > 128) { - error = pr_err("maxLength (%lu) is out of bounds (0-128).", + error = pr_val_err("maxLength (%lu) is out of bounds (0-128).", max_length); goto end_error; } if (prefix.len > max_length) { - error = pr_err("Prefix length (%u) > maxLength (%lu)", + error = pr_val_err("Prefix length (%u) > maxLength (%lu)", prefix.len, max_length); goto end_error; } @@ -120,15 +120,15 @@ ____handle_roa_v6(struct resources *parent, unsigned long asn, } if (!resources_contains_ipv6(parent, &prefix)) { - error = pr_err("ROA is not allowed to advertise %s/%u.", + error = pr_val_err("ROA is not allowed to advertise %s/%u.", v6addr2str(&prefix.addr), prefix.len); goto end_error; } - pr_debug("}"); + pr_val_debug("}"); return vhandler_handle_roa_v6(asn, &prefix, max_length); end_error: - pr_debug("}"); + pr_val_debug("}"); return error; } @@ -143,7 +143,7 @@ ____handle_roa(struct resources *parent, unsigned long asn, uint8_t family, return ____handle_roa_v6(parent, asn, roa_addr); } - return pr_err("Unknown family value: %u", family); + return pr_val_err("Unknown family value: %u", family); } static int @@ -156,18 +156,18 @@ __handle_roa(struct RouteOriginAttestation *roa, struct resources *parent) int a; int error; - pr_debug("eContent {"); + pr_val_debug("eContent {"); if (roa->version != NULL) { error = asn_INTEGER2ulong(roa->version, &version); if (error) { if (errno) - pr_errno(errno, "Error casting ROA's version"); - error = pr_err("The ROA's version isn't a valid long"); + pr_val_errno(errno, "Error casting ROA's version"); + error = pr_val_err("The ROA's version isn't a valid long"); goto end_error; } /* rfc6482#section-3.1 */ if (version != 0) { - error = pr_err("ROA's version (%lu) is nonzero.", + error = pr_val_err("ROA's version (%lu) is nonzero.", version); goto end_error; } @@ -176,29 +176,29 @@ __handle_roa(struct RouteOriginAttestation *roa, struct resources *parent) /* rfc6482#section-3.2 */ if (asn_INTEGER2ulong(&roa->asID, &asn) != 0) { if (errno) - pr_errno(errno, "Error casting ROA's AS ID value"); - error = pr_err("ROA's AS ID couldn't be parsed as unsigned long"); + pr_val_errno(errno, "Error casting ROA's AS ID value"); + error = pr_val_err("ROA's AS ID couldn't be parsed as unsigned long"); goto end_error; } if (asn > UINT32_MAX) { - error = pr_err("AS value (%lu) is out of range.", asn); + error = pr_val_err("AS value (%lu) is out of range.", asn); goto end_error; } - pr_debug("asID: %lu", asn); + pr_val_debug("asID: %lu", asn); /* rfc6482#section-3.3 */ if (roa->ipAddrBlocks.list.array == NULL) { - error = pr_err("ipAddrBlocks array is NULL."); + error = pr_val_err("ipAddrBlocks array is NULL."); goto end_error; } - pr_debug("ipAddrBlocks {"); + pr_val_debug("ipAddrBlocks {"); for (b = 0; b < roa->ipAddrBlocks.list.count; b++) { block = roa->ipAddrBlocks.list.array[b]; if (block == NULL) { - error = pr_err("Address block array element is NULL."); + error = pr_val_err("Address block array element is NULL."); goto ip_error; } @@ -209,12 +209,12 @@ __handle_roa(struct RouteOriginAttestation *roa, struct resources *parent) if (block->addressFamily.buf[1] != 1 && block->addressFamily.buf[1] != 2) goto family_error; - pr_debug("%s {", + pr_val_debug("%s {", block->addressFamily.buf[1] == 1 ? "v4" : "v6"); if (block->addresses.list.array == NULL) { - error = pr_err("ROA's address list array is NULL."); - pr_debug("}"); + error = pr_val_err("ROA's address list array is NULL."); + pr_val_debug("}"); goto ip_error; } @@ -223,11 +223,11 @@ __handle_roa(struct RouteOriginAttestation *roa, struct resources *parent) block->addressFamily.buf[1], block->addresses.list.array[a]); if (error) { - pr_debug("}"); + pr_val_debug("}"); goto ip_error; } } - pr_debug("}"); + pr_val_debug("}"); } /* Error 0 it's ok */ @@ -235,11 +235,11 @@ __handle_roa(struct RouteOriginAttestation *roa, struct resources *parent) goto ip_error; family_error: - error = pr_err("ROA's IP family is not v4 or v6."); + error = pr_val_err("ROA's IP family is not v4 or v6."); ip_error: - pr_debug("}"); + pr_val_debug("}"); end_error: - pr_debug("}"); + pr_val_debug("}"); return error; } @@ -255,7 +255,7 @@ roa_traverse(struct rpki_uri *uri, struct rpp *pp) int error; /* Prepare */ - pr_debug("ROA '%s' {", uri_get_printable(uri)); + pr_val_debug("ROA '%s' {", uri_val_get_printable(uri)); fnstack_push_uri(uri); /* Decode */ @@ -291,6 +291,6 @@ revert_sobj: signed_object_cleanup(&sobj); revert_log: fnstack_pop(); - pr_debug("}"); + pr_val_debug("}"); return error; } diff --git a/src/object/signed_object.c b/src/object/signed_object.c index 25d17bd2..539f5c79 100644 --- a/src/object/signed_object.c +++ b/src/object/signed_object.c @@ -35,7 +35,7 @@ validate_eContentType(struct SignedData *sdata, struct oid_arcs const *oid) equals = arcs_equal(&arcs, oid); free_arcs(&arcs); if (!equals) { - return pr_err("The OID of the SignedObject's encapContentInfo is not '%s'.", + return pr_val_err("The OID of the SignedObject's encapContentInfo is not '%s'.", oid->name); } @@ -60,7 +60,7 @@ validate_content_type(struct SignedData *sdata, struct oid_arcs const *oid) equals = arcs_equal(&arcs, oid); free_arcs(&arcs); if (!equals) { - return pr_err("The OID of the SignedObject's content type attribute is not '%s'.", + return pr_val_err("The OID of the SignedObject's content type attribute is not '%s'.", oid->name); } diff --git a/src/object/tal.c b/src/object/tal.c index 39029a05..9c084184 100644 --- a/src/object/tal.c +++ b/src/object/tal.c @@ -92,7 +92,7 @@ uris_add(struct uris *uris, char *uri) error = uri_create_mixed_str(&new, uri, strlen(uri)); if (error == ENOTSUPPORTED) - return pr_err("TAL has non-RSYNC/HTTPS URI."); + return pr_op_err("TAL has non-RSYNC/HTTPS URI."); if (error) return error; @@ -123,10 +123,10 @@ read_uris(struct line_file *lfile, struct uris *uris) return error; if (uri == NULL) - return pr_err("TAL file is empty."); + return pr_op_err("TAL file is empty."); if (strcmp(uri, "") == 0) { free(uri); - return pr_err("There's no URI in the first line of the TAL."); + return pr_op_err("There's no URI in the first line of the TAL."); } else if (strncmp(uri, "#", 1) == 0) { /* More comments expected, or an URI */ do { @@ -135,10 +135,10 @@ read_uris(struct line_file *lfile, struct uris *uris) if (error) return error; if (uri == NULL) - return pr_err("TAL file ended prematurely. (Expected more comments or an URI list.)"); + return pr_op_err("TAL file ended prematurely. (Expected more comments or an URI list.)"); if (strcmp(uri, "") == 0) { free(uri); - return pr_err("TAL file comments syntax error. (Expected more comments or an URI list.)"); + return pr_op_err("TAL file comments syntax error. (Expected more comments or an URI list.)"); } /* Not a comment, probably the URI(s) */ if (strncmp(uri, "#", 1) != 0) @@ -157,7 +157,7 @@ read_uris(struct line_file *lfile, struct uris *uris) return error; if (uri == NULL) - return pr_err("TAL file ended prematurely. (Expected URI list, blank line and public key.)"); + return pr_op_err("TAL file ended prematurely. (Expected URI list, blank line and public key.)"); if (strcmp(uri, "") == 0) { free(uri); return 0; /* Happy path */ @@ -241,7 +241,7 @@ base64_sanitize(struct line_file *lfile, char **out) * code. It literally doesn't say how to get an error * code. */ - pr_errno(error, + pr_op_errno(error, "File reading error. Error message (apparently)"); goto free_result; } @@ -314,7 +314,7 @@ read_spki(struct line_file *lfile, struct tal *tal) if (encoded == NULL) { free(tal->spki); free(tmp); - return crypto_err("BIO_new_mem_buf() returned NULL"); + return op_crypto_err("BIO_new_mem_buf() returned NULL"); } error = base64_decode(encoded, tal->spki, true, alloc_size, @@ -339,7 +339,7 @@ tal_load(char const *file_name, struct tal **result) error = lfile_open(file_name, &lfile); if (error) { - pr_errno(error, "Error opening file '%s'", file_name); + pr_op_errno(error, "Error opening file '%s'", file_name); goto fail4; } @@ -499,15 +499,15 @@ handle_tal_uri(struct tal *tal, struct rpki_uri *uri, void *arg) /* FIXME (NOW) Try to work with local data on the first run? */ if (error) { validation_destroy(state); - return pr_warn("TAL '%s' could not be downloaded.", - uri_get_printable(uri)); + return pr_val_warn("TAL '%s' could not be downloaded.", + uri_val_get_printable(uri)); } - pr_debug("TAL URI '%s' {", uri_get_printable(uri)); + pr_val_debug("TAL URI '%s' {", uri_val_get_printable(uri)); if (!uri_is_certificate(uri)) { - error = pr_err("TAL file does not point to a certificate. (Expected .cer, got '%s')", - uri_get_printable(uri)); + error = pr_op_err("TAL file does not point to a certificate. (Expected .cer, got '%s')", + uri_op_get_printable(uri)); goto fail; } @@ -567,7 +567,7 @@ handle_tal_uri(struct tal *tal, struct rpki_uri *uri, void *arg) fail: error = ENSURE_NEGATIVE(error); end: validation_destroy(state); - pr_debug("}"); + pr_val_debug("}"); return error; } @@ -593,7 +593,7 @@ do_file_validation(void *thread_arg) if (error > 0) error = 0; else if (error == 0) - error = pr_err("None of the URIs of the TAL '%s' yielded a successful traversal.", + error = pr_op_err("None of the URIs of the TAL '%s' yielded a successful traversal.", thread->tal_file); tal_destroy(tal); @@ -639,7 +639,7 @@ __do_file_validation(char const *tal_file, void *arg) errno = pthread_create(&thread->pid, NULL, do_file_validation, thread); if (errno) { - error = -pr_errno(errno, + error = -pr_op_errno(errno, "Could not spawn the file validation thread"); goto free_tal_file; } @@ -701,7 +701,7 @@ perform_standalone_validation(struct db_table *table) SLIST_REMOVE_HEAD(&threads, next); if (thread->exit_status) { t_error = thread->exit_status; - pr_warn("Validation from TAL '%s' yielded error, discarding any other validation results.", + pr_val_warn("Validation from TAL '%s' yielded error, discarding any other validation results.", thread->tal_file); } thread_destroy(thread); diff --git a/src/object/vcard.c b/src/object/vcard.c index eb32fe9c..d16ab1a6 100644 --- a/src/object/vcard.c +++ b/src/object/vcard.c @@ -76,7 +76,7 @@ analyze_pos(struct utf8_string *string, size_t pos) next1 = next_chara(string, pos); if (next1 == NULL) { - pr_err("vCard's final newline is incomplete ('\\r')."); + pr_val_err("vCard's final newline is incomplete ('\\r')."); return SA_ERROR; } if (*next1 != '\n') @@ -139,7 +139,7 @@ line_next(struct vcard_line *line, OCTET_STRING_t *string8) int error; if (string8->size == line->octet_string_offset) - return pr_err("vCard ends prematurely. (Expected an END line)"); + return pr_val_err("vCard ends prematurely. (Expected an END line)"); string.val = string8->buf + line->octet_string_offset; string.len = string8->size - line->octet_string_offset; @@ -167,7 +167,7 @@ line_next(struct vcard_line *line, OCTET_STRING_t *string8) } } - return pr_err("vCard line does not end with a \\r\\n-style newline."); + return pr_val_err("vCard line does not end with a \\r\\n-style newline."); } static int @@ -190,7 +190,7 @@ line_validate(struct vcard_line *line, char const *expected) return 0; fail: - return pr_err("Expected vCard property '%s', got '%s'.", + return pr_val_err("Expected vCard property '%s', got '%s'.", expected, line->str.val); } @@ -243,7 +243,7 @@ __handle_ghostbusters_vcard(OCTET_STRING_t *vcard, struct vcard_line *line) break; } else { - return pr_err("Unexpected vCard line: '%s'", + return pr_val_err("Unexpected vCard line: '%s'", line->str.val); } @@ -253,12 +253,12 @@ __handle_ghostbusters_vcard(OCTET_STRING_t *vcard, struct vcard_line *line) if (error) return error; if (vcard->size != line->octet_string_offset) - return pr_err("vCard has content after the END tag."); + return pr_val_err("vCard has content after the END tag."); if (!fn_found) - return pr_err("vCard lacks the 'FN' property."); + return pr_val_err("vCard lacks the 'FN' property."); if (!useful_found) - return pr_err("vCard lacks the 'ORG', 'ADR', 'TEL' and/or 'EMAIL' properties."); + return pr_val_err("vCard lacks the 'ORG', 'ADR', 'TEL' and/or 'EMAIL' properties."); return 0; } diff --git a/src/output_printer.c b/src/output_printer.c index 1f13fb65..8dfd41fa 100644 --- a/src/output_printer.c +++ b/src/output_printer.c @@ -93,7 +93,7 @@ open_file(char const *loc, FILE **out, bool *fopen) error = load_output_file(loc, out, fopen); if (error) - return pr_err("Error getting file '%s'", loc); + return pr_op_err("Error getting file '%s'", loc); /* No output configured */ if (*out == NULL) @@ -119,7 +119,7 @@ print_roas(struct db_table *db) if (fopen) file_close(out); if (error) - pr_err("Error printing ROAs"); + pr_op_err("Error printing ROAs"); } static void @@ -139,7 +139,7 @@ print_router_keys(struct db_table *db) if (fopen) file_close(out); if (error) - pr_err("Error printing Router Keys"); + pr_op_err("Error printing Router Keys"); } void diff --git a/src/reqs_errors.c b/src/reqs_errors.c index ace84a3f..5ba80f66 100644 --- a/src/reqs_errors.c +++ b/src/reqs_errors.c @@ -93,7 +93,7 @@ reqs_errors_init(void) error = pthread_rwlock_init(&db_lock, NULL); if (error) - return pr_errno(error, "pthread_rwlock_init() errored"); + return pr_op_errno(error, "pthread_rwlock_init() errored"); err_uris_db = NULL; @@ -257,12 +257,10 @@ reqs_errors_log_summary(void) if (!node->log_summary) continue; if (first) { - /* FIXME (NOW) Send to operation log */ - pr_warn("The following repositories URIs couldn't be fetched (it can be a local issue or a server issue), please review previous log messages related to such URIs/servers:"); + pr_op_warn("The following repositories URIs couldn't be fetched (it can be a local issue or a server issue), please review previous log messages related to such URIs/servers:"); first = false; } - /* FIXME (NOW) Send to operation log */ - pr_warn("- '%s': can't be downloaded since %s", node->uri, + pr_op_warn("- '%s': can't be downloaded since %s", node->uri, asctime(localtime(&node->first_attempt))); } diff --git a/src/resource.c b/src/resource.c index fd655f2c..228b255a 100644 --- a/src/resource.c +++ b/src/resource.c @@ -63,7 +63,7 @@ int get_addr_family(OCTET_STRING_t *octets) { if (octets->size != 2) { - pr_err("Address family has %zu octets. (2 expected.)", + pr_val_err("Address family has %zu octets. (2 expected.)", octets->size); return -1; } @@ -78,7 +78,7 @@ get_addr_family(OCTET_STRING_t *octets) } unknown: - pr_err("Address family has unknown value 0x%02x%02x.", octets->buf[0], + pr_val_err("Address family has unknown value 0x%02x%02x.", octets->buf[0], octets->buf[1]); return -1; } @@ -104,20 +104,20 @@ inherit_aors(struct resources *resources, int family) switch (family) { case AF_INET: if (resources->ip4s != NULL) - return pr_err("Certificate inherits IPv4 resources while also defining others of its own."); + return pr_val_err("Certificate inherits IPv4 resources while also defining others of its own."); resources->ip4s = parent->ip4s; if (resources->ip4s != NULL) res4_get(resources->ip4s); - pr_debug(""); + pr_val_debug(""); return 0; case AF_INET6: if (resources->ip6s != NULL) - return pr_err("Certificate inherits IPv6 resources while also defining others of its own."); + return pr_val_err("Certificate inherits IPv6 resources while also defining others of its own."); resources->ip6s = parent->ip6s; if (resources->ip6s != NULL) res6_get(resources->ip6s); - pr_debug(""); + pr_val_debug(""); return 0; } @@ -134,7 +134,7 @@ add_prefix4(struct resources *resources, IPAddress_t *addr) parent = get_parent_resources(); if ((parent != NULL) && (resources->ip4s == parent->ip4s)) - return pr_err("Certificate defines IPv4 prefixes while also inheriting his parent's."); + return pr_val_err("Certificate defines IPv4 prefixes while also inheriting his parent's."); error = prefix4_decode(addr, &prefix); if (error) @@ -143,10 +143,10 @@ add_prefix4(struct resources *resources, IPAddress_t *addr) if (parent && !res4_contains_prefix(parent->ip4s, &prefix)) { switch (resources->policy) { case RPKI_POLICY_RFC6484: - return pr_err("Parent certificate doesn't own IPv4 prefix '%s/%u'.", + return pr_val_err("Parent certificate doesn't own IPv4 prefix '%s/%u'.", v4addr2str(&prefix.addr), prefix.len); case RPKI_POLICY_RFC8360: - return pr_warn("Certificate is overclaiming the IPv4 prefix '%s/%u'.", + return pr_val_warn("Certificate is overclaiming the IPv4 prefix '%s/%u'.", v4addr2str(&prefix.addr), prefix.len); } } @@ -159,13 +159,13 @@ add_prefix4(struct resources *resources, IPAddress_t *addr) error = res4_add_prefix(resources->ip4s, &prefix); if (error) { - pr_err("Error adding IPv4 prefix '%s/%u' to certificate resources: %s", + pr_val_err("Error adding IPv4 prefix '%s/%u' to certificate resources: %s", v4addr2str(&prefix.addr), prefix.len, sarray_err2str(error)); return error; } - pr_debug("Prefix: %s/%u", v4addr2str(&prefix.addr), prefix.len); + pr_val_debug("Prefix: %s/%u", v4addr2str(&prefix.addr), prefix.len); return 0; } @@ -179,7 +179,7 @@ add_prefix6(struct resources *resources, IPAddress_t *addr) parent = get_parent_resources(); if ((parent != NULL) && (resources->ip6s == parent->ip6s)) - return pr_err("Certificate defines IPv6 prefixes while also inheriting his parent's."); + return pr_val_err("Certificate defines IPv6 prefixes while also inheriting his parent's."); error = prefix6_decode(addr, &prefix); if (error) @@ -188,10 +188,10 @@ add_prefix6(struct resources *resources, IPAddress_t *addr) if (parent && !res6_contains_prefix(parent->ip6s, &prefix)) { switch (resources->policy) { case RPKI_POLICY_RFC6484: - return pr_err("Parent certificate doesn't own IPv6 prefix '%s/%u'.", + return pr_val_err("Parent certificate doesn't own IPv6 prefix '%s/%u'.", v6addr2str(&prefix.addr), prefix.len); case RPKI_POLICY_RFC8360: - return pr_warn("Certificate is overclaiming the IPv6 prefix '%s/%u'.", + return pr_val_warn("Certificate is overclaiming the IPv6 prefix '%s/%u'.", v6addr2str(&prefix.addr), prefix.len); } } @@ -204,13 +204,13 @@ add_prefix6(struct resources *resources, IPAddress_t *addr) error = res6_add_prefix(resources->ip6s, &prefix); if (error) { - pr_err("Error adding IPv6 prefix '%s/%u' to certificate resources: %s", + pr_val_err("Error adding IPv6 prefix '%s/%u' to certificate resources: %s", v6addr2str(&prefix.addr), prefix.len, sarray_err2str(error)); return error; } - pr_debug("Prefix: %s/%u", v6addr2str(&prefix.addr), prefix.len); + pr_val_debug("Prefix: %s/%u", v6addr2str(&prefix.addr), prefix.len); return 0; } @@ -237,7 +237,7 @@ add_range4(struct resources *resources, IPAddressRange_t *input) parent = get_parent_resources(); if (parent && (resources->ip4s == parent->ip4s)) - return pr_err("Certificate defines IPv4 ranges while also inheriting his parent's."); + return pr_val_err("Certificate defines IPv4 ranges while also inheriting his parent's."); error = range4_decode(input, &range); if (error) @@ -246,10 +246,10 @@ add_range4(struct resources *resources, IPAddressRange_t *input) if (parent && !res4_contains_range(parent->ip4s, &range)) { switch (resources->policy) { case RPKI_POLICY_RFC6484: - return pr_err("Parent certificate doesn't own IPv4 range '%s-%s'.", + return pr_val_err("Parent certificate doesn't own IPv4 range '%s-%s'.", v4addr2str(&range.min), v4addr2str2(&range.max)); case RPKI_POLICY_RFC8360: - return pr_warn("Certificate is overclaiming the IPv4 range '%s-%s'.", + return pr_val_warn("Certificate is overclaiming the IPv4 range '%s-%s'.", v4addr2str(&range.min), v4addr2str2(&range.max)); } } @@ -262,13 +262,13 @@ add_range4(struct resources *resources, IPAddressRange_t *input) error = res4_add_range(resources->ip4s, &range); if (error) { - pr_err("Error adding IPv4 range '%s-%s' to certificate resources: %s", + pr_val_err("Error adding IPv4 range '%s-%s' to certificate resources: %s", v4addr2str(&range.min), v4addr2str2(&range.max), sarray_err2str(error)); return error; } - pr_debug("Range: %s-%s", v4addr2str(&range.min), + pr_val_debug("Range: %s-%s", v4addr2str(&range.min), v4addr2str2(&range.max)); return 0; } @@ -283,7 +283,7 @@ add_range6(struct resources *resources, IPAddressRange_t *input) parent = get_parent_resources(); if ((parent != NULL) && (resources->ip6s == parent->ip6s)) - return pr_err("Certificate defines IPv6 ranges while also inheriting his parent's."); + return pr_val_err("Certificate defines IPv6 ranges while also inheriting his parent's."); error = range6_decode(input, &range); if (error) @@ -292,10 +292,10 @@ add_range6(struct resources *resources, IPAddressRange_t *input) if (parent && !res6_contains_range(parent->ip6s, &range)) { switch (resources->policy) { case RPKI_POLICY_RFC6484: - return pr_err("Parent certificate doesn't own IPv6 range '%s-%s'.", + return pr_val_err("Parent certificate doesn't own IPv6 range '%s-%s'.", v6addr2str(&range.min), v6addr2str2(&range.max)); case RPKI_POLICY_RFC8360: - return pr_warn("Certificate is overclaiming the IPv6 range '%s-%s'.", + return pr_val_warn("Certificate is overclaiming the IPv6 range '%s-%s'.", v6addr2str(&range.min), v6addr2str2(&range.max)); } } @@ -308,13 +308,13 @@ add_range6(struct resources *resources, IPAddressRange_t *input) error = res6_add_range(resources->ip6s, &range); if (error) { - pr_err("Error adding IPv6 range '%s-%s' to certificate resources: %s", + pr_val_err("Error adding IPv6 range '%s-%s' to certificate resources: %s", v6addr2str(&range.min), v6addr2str2(&range.max), sarray_err2str(error)); return error; } - pr_debug("Range: %s-%s", v6addr2str(&range.min), + pr_val_debug("Range: %s-%s", v6addr2str(&range.min), v6addr2str2(&range.max)); return 0; } @@ -341,9 +341,9 @@ add_aors(struct resources *resources, int family, int error; if (resources->force_inherit) - return pr_err("Certificate is only allowed to inherit resources, but defines its own IP addresses or ranges."); + return pr_val_err("Certificate is only allowed to inherit resources, but defines its own IP addresses or ranges."); if (aors->list.count == 0) - return pr_err("IP extension's set of IP address records is empty."); + return pr_val_err("IP extension's set of IP address records is empty."); for (i = 0; i < aors->list.count; i++) { aor = aors->list.array[i]; @@ -362,7 +362,7 @@ add_aors(struct resources *resources, int family, break; case IPAddressOrRange_PR_NOTHING: /* rfc3779#section-2.2.3.7 */ - return pr_err("Unknown IPAddressOrRange type: %u", + return pr_val_err("Unknown IPAddressOrRange type: %u", aor->present); } } @@ -390,7 +390,7 @@ resources_add_ip(struct resources *resources, struct IPAddressFamily *obj) } /* rfc3779#section-2.2.3.4 */ - return pr_err("Unknown ipAddressChoice type: %u", + return pr_val_err("Unknown ipAddressChoice type: %u", obj->ipAddressChoice.present); } @@ -404,12 +404,12 @@ inherit_asiors(struct resources *resources) pr_crit("Parent has no resources."); if (resources->asns != NULL) - return pr_err("Certificate inherits ASN resources while also defining others of its own."); + return pr_val_err("Certificate inherits ASN resources while also defining others of its own."); resources->asns = parent->asns; if (resources->asns != NULL) rasn_get(resources->asns); - pr_debug(""); + pr_val_debug(""); return 0; } @@ -422,12 +422,12 @@ ASId2ulong(ASId_t *as_id, unsigned long *result) error = asn_INTEGER2ulong(as_id, result); if (error) { if (errno) - pr_errno(errno, "Error converting ASN value"); - return pr_err("ASN value is not a valid unsigned long"); + pr_val_errno(errno, "Error converting ASN value"); + return pr_val_err("ASN value is not a valid unsigned long"); } if ((*result) > ASN_MAX) { - return pr_err("ASN value '%lu' is out of bounds. (0-%lu)", + return pr_val_err("ASN value '%lu' is out of bounds. (0-%lu)", *result, ASN_MAX); } @@ -441,15 +441,15 @@ add_asn(struct resources *resources, unsigned long min, unsigned long max, int error; if (min > max) - return pr_err("The ASN range %lu-%lu is inverted.", min, max); + return pr_val_err("The ASN range %lu-%lu is inverted.", min, max); if (parent && !rasn_contains(parent->asns, min, max)) { switch (resources->policy) { case RPKI_POLICY_RFC6484: - return pr_err("Parent certificate doesn't own ASN range '%lu-%lu'.", + return pr_val_err("Parent certificate doesn't own ASN range '%lu-%lu'.", min, max); case RPKI_POLICY_RFC8360: - return pr_warn("Certificate is overclaiming the ASN range '%lu-%lu'.", + return pr_val_warn("Certificate is overclaiming the ASN range '%lu-%lu'.", min, max); } } @@ -462,15 +462,15 @@ add_asn(struct resources *resources, unsigned long min, unsigned long max, error = rasn_add(resources->asns, min, max); if (error){ - pr_err("Error adding ASN range '%lu-%lu' to certificate resources: %s", + pr_val_err("Error adding ASN range '%lu-%lu' to certificate resources: %s", min, max, sarray_err2str(error)); return error; } if (min == max) - pr_debug("ASN: %lu", min); + pr_val_debug("ASN: %lu", min); else - pr_debug("ASN: %lu-%lu", min, max); + pr_val_debug("ASN: %lu-%lu", min, max); return 0; } @@ -485,7 +485,7 @@ add_asior(struct resources *resources, struct ASIdOrRange *obj) parent = get_parent_resources(); if ((parent != NULL) && (resources->asns == parent->asns)) - return pr_err("Certificate defines ASN resources while also inheriting his parent's."); + return pr_val_err("Certificate defines ASN resources while also inheriting his parent's."); switch (obj->present) { case ASIdOrRange_PR_NOTHING: @@ -507,7 +507,7 @@ add_asior(struct resources *resources, struct ASIdOrRange *obj) return add_asn(resources, asn_min, asn_max, parent); } - return pr_err("Unknown ASIdOrRange type: %u", obj->present); + return pr_val_err("Unknown ASIdOrRange type: %u", obj->present); } static int @@ -518,11 +518,11 @@ add_asiors(struct resources *resources, struct ASIdentifiers *ids) int error; if (resources->force_inherit) - return pr_err("Certificate is only allowed to inherit resources, but defines its own AS numbers."); + return pr_val_err("Certificate is only allowed to inherit resources, but defines its own AS numbers."); iors = &ids->asnum->choice.asIdsOrRanges; if (iors->list.count == 0) - return pr_err("AS extension's set of AS number records is empty."); + return pr_val_err("AS extension's set of AS number records is empty."); for (i = 0; i < iors->list.count; i++) { error = add_asior(resources, iors->list.array[i]); @@ -538,14 +538,14 @@ resources_add_asn(struct resources *resources, struct ASIdentifiers *ids, bool allow_inherit) { if (ids->asnum == NULL) - return pr_err("ASN extension lacks 'asnum' element."); + return pr_val_err("ASN extension lacks 'asnum' element."); if (ids->rdi != NULL) - return pr_err("ASN extension has 'rdi' element. (Prohibited by RFC6487)"); + return pr_val_err("ASN extension has 'rdi' element. (Prohibited by RFC6487)"); switch (ids->asnum->present) { case ASIdentifierChoice_PR_inherit: if (!allow_inherit) - return pr_err("ASIdentifierChoice %u isn't allowed", + return pr_val_err("ASIdentifierChoice %u isn't allowed", ids->asnum->present); return inherit_asiors(resources); case ASIdentifierChoice_PR_asIdsOrRanges: @@ -554,7 +554,7 @@ resources_add_asn(struct resources *resources, struct ASIdentifiers *ids, break; } - return pr_err("Unknown ASIdentifierChoice: %u", ids->asnum->present); + return pr_val_err("Unknown ASIdentifierChoice: %u", ids->asnum->present); } bool diff --git a/src/rpp.c b/src/rpp.c index c73c067c..f7bdd34d 100644 --- a/src/rpp.c +++ b/src/rpp.c @@ -125,7 +125,7 @@ rpp_add_crl(struct rpp *pp, struct rpki_uri *uri) { /* rfc6481#section-2.2 */ if (pp->crl.uri) - return pr_err("Repository Publication Point has more than one CRL."); + return pr_val_err("Repository Publication Point has more than one CRL."); pp->crl.uri = uri; return 0; @@ -152,7 +152,7 @@ add_crl_to_stack(struct rpp *pp, STACK_OF(X509_CRL) *crls) idx = sk_X509_CRL_push(crls, crl); if (idx <= 0) { - error = crypto_err("Could not add CRL to a CRL stack"); + error = val_crypto_err("Could not add CRL to a CRL stack"); X509_CRL_free(crl); goto end; } diff --git a/src/rrdp/db/db_rrdp.c b/src/rrdp/db/db_rrdp.c index d88d97ae..b6e0363b 100644 --- a/src/rrdp/db/db_rrdp.c +++ b/src/rrdp/db/db_rrdp.c @@ -74,7 +74,7 @@ db_rrdp_init(void) error = pthread_rwlock_init(&lock, NULL); if (error) - return pr_errno(error, "DB RRDP pthread_rwlock_init() errored"); + return pr_op_errno(error, "DB RRDP pthread_rwlock_init() errored"); SLIST_INIT(&db.tals); return 0; diff --git a/src/rrdp/db/db_rrdp_uris.c b/src/rrdp/db/db_rrdp_uris.c index c67f2c85..082db39c 100644 --- a/src/rrdp/db/db_rrdp_uris.c +++ b/src/rrdp/db/db_rrdp_uris.c @@ -109,7 +109,7 @@ get_thread_rrdp_uris(struct db_rrdp_uri **result) state = state_retrieve(); if (state == NULL) - return pr_err("No state related to this thread"); + return pr_val_err("No state related to this thread"); *result = validation_get_rrdp_uris(state); return 0; diff --git a/src/rrdp/rrdp_loader.c b/src/rrdp/rrdp_loader.c index 8ea25f50..62be80c6 100644 --- a/src/rrdp/rrdp_loader.c +++ b/src/rrdp/rrdp_loader.c @@ -76,7 +76,7 @@ mark_rrdp_uri_request_err(char const *notification_uri) struct visited_uris *tmp; int error; - pr_debug("RRDP data of '%s' won't be requested again during this cycle due to previous error.", + pr_val_debug("RRDP data of '%s' won't be requested again during this cycle due to previous error.", notification_uri); error = visited_uris_create(&tmp); @@ -142,7 +142,7 @@ rrdp_load(struct rpki_uri *uri) /* No updates at the file (yet), didn't pushed to fnstack */ if (upd_notification == NULL) { - pr_debug("No updates yet at '%s'.", uri_get_global(uri)); + pr_val_debug("No updates yet at '%s'.", uri_get_global(uri)); goto upd_end; } @@ -174,7 +174,7 @@ rrdp_load(struct rpki_uri *uri) break; } /* Something went wrong, use snapshot */ - pr_info("There was an error processing RRDP deltas, using the snapshot instead."); + pr_val_info("There was an error processing RRDP deltas, using the snapshot instead."); case RRDP_URI_NOTFOUND: error = process_snapshot(upd_notification, log_operation, &visited); @@ -186,9 +186,9 @@ rrdp_load(struct rpki_uri *uri) } /* Any update, and no error during the process, update db as well */ - pr_debug("Updating local RRDP data of '%s' to:", uri_get_global(uri)); - pr_debug("- Session ID: %s", upd_notification->global_data.session_id); - pr_debug("- Serial: %lu", upd_notification->global_data.serial); + pr_val_debug("Updating local RRDP data of '%s' to:", uri_get_global(uri)); + pr_val_debug("- Session ID: %s", upd_notification->global_data.session_id); + pr_val_debug("- Serial: %lu", upd_notification->global_data.serial); error = db_rrdp_uris_update(uri_get_global(uri), upd_notification->global_data.session_id, upd_notification->global_data.serial, @@ -199,7 +199,7 @@ rrdp_load(struct rpki_uri *uri) set_update: /* Set the last update to now */ - pr_debug("Set last update of RRDP data of '%s' to now.", + pr_val_debug("Set last update of RRDP data of '%s' to now.", uri_get_global(uri)); db_rrdp_uris_set_last_update(uri_get_global(uri)); upd_destroy: diff --git a/src/rrdp/rrdp_objects.c b/src/rrdp/rrdp_objects.c index 8bd3745d..24807ba2 100644 --- a/src/rrdp/rrdp_objects.c +++ b/src/rrdp/rrdp_objects.c @@ -215,11 +215,11 @@ deltas_head_for_each(struct deltas_head *deltas, unsigned long max_serial, /* No elements, send error so that the snapshot is processed */ if (deltas->capacity == 0) { - pr_warn("There's no delta list to process."); + pr_val_warn("There's no delta list to process."); return -ENOENT; } - pr_debug("Getting RRDP deltas from serial %lu to %lu.", from_serial, + pr_val_debug("Getting RRDP deltas from serial %lu to %lu.", from_serial, max_serial); from = deltas->capacity - (max_serial - from_serial); for (index = from; index < deltas->capacity; index++) { diff --git a/src/rrdp/rrdp_parser.c b/src/rrdp/rrdp_parser.c index c01cfdbf..cb978e83 100644 --- a/src/rrdp/rrdp_parser.c +++ b/src/rrdp/rrdp_parser.c @@ -129,7 +129,7 @@ download_file(struct rpki_uri *uri, long last_update, bool log_operation) return error; if (retries == config_get_rrdp_retry_count()) { - pr_info("Max RRDP retries (%u) reached fetching '%s', won't retry again.", + pr_val_info("Max RRDP retries (%u) reached fetching '%s', won't retry again.", retries, uri_get_global(uri)); /* * Since distinct files can be downloaded (notification, @@ -139,7 +139,7 @@ download_file(struct rpki_uri *uri, long last_update, bool log_operation) */ return EREQFAILED; } - pr_info("Retrying RRDP file download '%s' in %u seconds, %u attempts remaining.", + pr_val_info("Retrying RRDP file download '%s' in %u seconds, %u attempts remaining.", uri_get_global(uri), config_get_rrdp_retry_interval(), config_get_rrdp_retry_count() - retries); @@ -162,7 +162,7 @@ ltrim(char *from, char **result, size_t *result_size) tmp_size--; } if (*start == '\0') - return pr_err("Invalid base64 encoded string (seems to be empty or full of spaces)."); + return pr_val_err("Invalid base64 encoded string (seems to be empty or full of spaces)."); *result = start; *result_size = tmp_size; @@ -252,7 +252,7 @@ base64_read(char *content, unsigned char **out, size_t *out_len) encoded = BIO_new_mem_buf(sanitized, -1); if (encoded == NULL) { - error = crypto_err("BIO_new_mem_buf() returned NULL"); + error = val_crypto_err("BIO_new_mem_buf() returned NULL"); goto release_sanitized; } @@ -294,7 +294,7 @@ parse_string(xmlTextReaderPtr reader, char const *attr, char **result) xml_value = xmlTextReaderGetAttribute(reader, BAD_CAST attr); if (xml_value == NULL) - return pr_err("RRDP file: Couldn't find %s from '%s'", + return pr_val_err("RRDP file: Couldn't find %s from '%s'", (attr == NULL ? "string content" : "xml attribute"), xmlTextReaderConstLocalName(reader)); @@ -320,14 +320,14 @@ parse_long(xmlTextReaderPtr reader, char const *attr, unsigned long *result) xml_value = xmlTextReaderGetAttribute(reader, BAD_CAST attr); if (xml_value == NULL) - return pr_err("RRDP file: Couldn't find xml attribute '%s'", + return pr_val_err("RRDP file: Couldn't find xml attribute '%s'", attr); errno = 0; tmp = strtoul((char *) xml_value, NULL, 10); if (errno) { xmlFree(xml_value); - pr_errno(errno, "RRDP file: Invalid long value '%s'", + pr_val_errno(errno, "RRDP file: Invalid long value '%s'", xml_value); return -EINVAL; } @@ -350,13 +350,13 @@ parse_hex_string(xmlTextReaderPtr reader, bool required, char const *attr, xml_value = xmlTextReaderGetAttribute(reader, BAD_CAST attr); if (xml_value == NULL) return required ? - pr_err("RRDP file: Couldn't find xml attribute '%s'", attr) + pr_val_err("RRDP file: Couldn't find xml attribute '%s'", attr) : 0; /* The rest of the checks are done at the schema */ if (xmlStrlen(xml_value) % 2 != 0) { xmlFree(xml_value); - return pr_err("RRDP file: Attribute %s isn't a valid hex string", + return pr_val_err("RRDP file: Attribute %s isn't a valid hex string", attr); } @@ -394,7 +394,7 @@ validate_version(xmlTextReaderPtr reader, unsigned long expected) return error; if (version != expected) - return pr_err("Invalid version, must be '%lu' and is '%lu'.", + return pr_val_err("Invalid version, must be '%lu' and is '%lu'.", expected, version); return 0; @@ -416,7 +416,7 @@ parse_global_data(xmlTextReaderPtr reader, struct global_data *gdata, */ if (!xmlStrEqual(xmlTextReaderConstNamespaceUri(reader), BAD_CAST RRDP_NAMESPACE)) - return pr_err("Namespace isn't '%s', current value is '%s'", + return pr_val_err("Namespace isn't '%s', current value is '%s'", RRDP_NAMESPACE, xmlTextReaderConstNamespaceUri(reader)); error = validate_version(reader, 1); @@ -442,7 +442,7 @@ parse_global_data(xmlTextReaderPtr reader, struct global_data *gdata, * has a logic error (in this case, session ID doesn't match parent's). */ if (strcmp(expected_session, session_id) != 0) { - pr_info("File session id [%s] doesn't match parent's session id [%s]", + pr_val_info("File session id [%s] doesn't match parent's session id [%s]", expected_session, session_id); error = EINVAL; goto return_val; @@ -450,7 +450,7 @@ parse_global_data(xmlTextReaderPtr reader, struct global_data *gdata, /* ...and the serial must match to what's expected at the parent */ if (serial != expected_serial) { - pr_info("File serial '%lu' doesn't match expected serial '%lu'", + pr_val_info("File serial '%lu' doesn't match expected serial '%lu'", serial, expected_serial); error = EINVAL; } @@ -521,7 +521,7 @@ parse_publish(xmlTextReaderPtr reader, bool parse_hash, bool hash_required, /* Read the text */ if (xmlTextReaderRead(reader) != 1) { - error = pr_err("Couldn't read publish content of element '%s'", + error = pr_val_err("Couldn't read publish content of element '%s'", tmp->doc_data.uri); goto release_tmp; } @@ -547,7 +547,7 @@ parse_publish(xmlTextReaderPtr reader, bool parse_hash, bool hash_required, tmp->doc_data.hash_len); uri_refput(uri); if (error != 0) { - pr_info("Hash of base64 decoded element from URI '%s' doesn't match element hash", + pr_val_info("Hash of base64 decoded element from URI '%s' doesn't match element hash", tmp->doc_data.uri); error = EINVAL; goto release_base64; @@ -631,7 +631,7 @@ write_from_uri(char const *location, unsigned char *content, size_t content_len, if (written != content_len) { uri_refput(uri); file_close(out); - return pr_err("Couldn't write bytes to file %s", + return pr_val_err("Couldn't write bytes to file %s", uri_get_local(uri)); } @@ -803,11 +803,11 @@ order_notification_deltas(struct rdr_notification_ctx *ctx) continue; if (error == -EINVAL) - return pr_err("Serial '%lu' at delta elements isn't part of a contiguous list of serials.", + return pr_val_err("Serial '%lu' at delta elements isn't part of a contiguous list of serials.", (*ptr)->serial); if (error == -EEXIST) - return pr_err("Duplicated serial '%lu' at delta elements.", + return pr_val_err("Duplicated serial '%lu' at delta elements.", (*ptr)->serial); return error; @@ -822,7 +822,7 @@ order_notification_deltas(struct rdr_notification_ctx *ctx) * If all expected elements are set, everything is ok. */ if (!deltas_head_values_set(ctx->notification->deltas_list)) - return pr_err("Deltas listed don't have a contiguous sequence of serial numbers"); + return pr_val_err("Deltas listed don't have a contiguous sequence of serial numbers"); return 0; } @@ -852,7 +852,7 @@ xml_read_notification(xmlTextReaderPtr reader, void *arg) /* Init context for deltas and snapshot */ rdr_notification_ctx_init(ctx); } else { - return pr_err("Unexpected '%s' element", name); + return pr_val_err("Unexpected '%s' element", name); } break; case XML_READER_TYPE_END_ELEMENT: @@ -925,7 +925,7 @@ xml_read_snapshot(xmlTextReaderPtr reader, void *arg) ctx->parent->global_data.session_id, ctx->parent->global_data.serial); else - return pr_err("Unexpected '%s' element", name); + return pr_val_err("Unexpected '%s' element", name); if (error) return error; @@ -990,7 +990,7 @@ xml_read_delta(xmlTextReaderPtr reader, void *arg) ctx->parent->global_data.session_id, ctx->expected_serial); else - return pr_err("Unexpected '%s' element", name); + return pr_val_err("Unexpected '%s' element", name); if (error) return error; @@ -1046,7 +1046,7 @@ process_delta(struct delta_head *delta_head, void *arg) head_data = &delta_head->doc_data; - pr_debug("Processing delta '%s'.", delta_head->doc_data.uri); + pr_val_debug("Processing delta '%s'.", delta_head->doc_data.uri); error = uri_create_https_str(&uri, head_data->uri, strlen(head_data->uri)); if (error) @@ -1083,7 +1083,7 @@ rrdp_parse_notification(struct rpki_uri *uri, bool log_operation, if (uri == NULL || uri_is_rsync(uri)) pr_crit("Wrong call, trying to parse a non HTTPS URI"); - pr_debug("Processing notification '%s'.", uri_get_global(uri)); + pr_val_debug("Processing notification '%s'.", uri_get_global(uri)); last_update = 0; error = db_rrdp_uris_get_last_update(uri_get_global(uri), &last_update); if (error && error != -ENOENT) @@ -1105,7 +1105,7 @@ rrdp_parse_notification(struct rpki_uri *uri, bool log_operation, vis_err = db_rrdp_uris_set_request_status(uri_get_global(uri), RRDP_URI_REQ_VISITED); if (vis_err && vis_err != -ENOENT) - return pr_err("Couldn't mark '%s' as visited", + return pr_val_err("Couldn't mark '%s' as visited", uri_get_global(uri)); /* No updates yet */ @@ -1137,7 +1137,7 @@ rrdp_parse_snapshot(struct update_notification *parent, args.parent = parent; args.visited_uris = visited_uris; - pr_debug("Processing snapshot '%s'.", parent->snapshot.uri); + pr_val_debug("Processing snapshot '%s'.", parent->snapshot.uri); error = uri_create_https_str(&uri, parent->snapshot.uri, strlen(parent->snapshot.uri)); if (error) diff --git a/src/rsync/rsync.c b/src/rsync/rsync.c index e2b47454..896e4984 100644 --- a/src/rsync/rsync.c +++ b/src/rsync/rsync.c @@ -226,15 +226,15 @@ handle_child_thread(struct rpki_uri *uri, bool is_ta, int fds[2][2]) exit(pr_enomem()); } - pr_debug("Executing RSYNC:"); + pr_val_debug("Executing RSYNC:"); for (i = 0; i < config_args->length + 1; i++) - pr_debug(" %s", copy_args[i]); + pr_val_debug(" %s", copy_args[i]); duplicate_fds(fds); execvp(copy_args[0], copy_args); error = errno; - pr_err("Could not execute the rsync command: %s", + pr_val_err("Could not execute the rsync command: %s", strerror(error)); /* https://stackoverflow.com/a/14493459/1735458 */ @@ -245,9 +245,9 @@ static int create_pipes(int fds[2][2]) { if (pipe(fds[0]) == -1) - return -pr_errno(errno, "Piping rsync stderr"); + return -pr_op_errno(errno, "Piping rsync stderr"); if (pipe(fds[1]) == -1) - return -pr_errno(errno, "Piping rsync stdout"); + return -pr_op_errno(errno, "Piping rsync stdout"); return 0; } @@ -274,17 +274,13 @@ log_buffer(char const *buffer, ssize_t read, int type, bool log_operation) continue; } if (type == 0) { - /* FIXME (NOW) Send to operation log if requested */ if (log_operation) - pr_err(PRE_RSYNC "%s", cur); - /* FIXME (NOW) Always send this to validation log */ - pr_err(PRE_RSYNC "%s", cur); + pr_op_err(PRE_RSYNC "%s", cur); + pr_val_err(PRE_RSYNC "%s", cur); } else { - /* FIXME (NOW) Send to operation log if requested */ if (log_operation) - pr_info(PRE_RSYNC "%s", cur); - /* FIXME (NOW) Always send this to validation log */ - pr_info(PRE_RSYNC "%s", cur); + pr_op_info(PRE_RSYNC "%s", cur); + pr_val_info(PRE_RSYNC "%s", cur); } cur = tmp + 1; } @@ -303,7 +299,7 @@ read_pipe(int fd_pipe[2][2], int type, bool log_operation) if (count == -1) { if (errno == EINTR) continue; - return -pr_errno(errno, "Reading rsync buffer"); + return -pr_val_errno(errno, "Reading rsync buffer"); } if (count == 0) break; @@ -372,7 +368,7 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation) do { if (error == -1) { error = errno; - pr_err("The rsync sub-process returned error %d (%s)", + pr_op_err("The rsync sub-process returned error %d (%s)", error, strerror(error)); if (child_status > 0) break; @@ -383,18 +379,18 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation) if (WIFEXITED(child_status)) { /* Happy path (but also sad path sometimes). */ error = WEXITSTATUS(child_status); - pr_debug("Child terminated with error code %d.", error); + pr_val_debug("Child terminated with error code %d.", error); if (!error) { reqs_errors_rem_uri(uri_get_global(uri)); return 0; } if (retries == config_get_rsync_retry_count()) { - pr_info("Max RSYNC retries (%u) reached on '%s', won't retry again.", + pr_val_info("Max RSYNC retries (%u) reached on '%s', won't retry again.", retries, uri_get_global(uri)); return EREQFAILED; } - pr_info("Retrying RSYNC '%s' in %u seconds, %u attempts remaining.", + pr_val_info("Retrying RSYNC '%s' in %u seconds, %u attempts remaining.", uri_get_global(uri), config_get_rsync_retry_interval(), config_get_rsync_retry_count() - retries); @@ -408,23 +404,23 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation) if (WIFSIGNALED(child_status)) { switch (WTERMSIG(child_status)) { case SIGINT: - pr_err("RSYNC was user-interrupted. Guess I'll interrupt myself too."); + pr_op_err("RSYNC was user-interrupted. Guess I'll interrupt myself too."); break; case SIGQUIT: - pr_err("RSYNC received a quit signal. Guess I'll quit as well."); + pr_op_err("RSYNC received a quit signal. Guess I'll quit as well."); break; case SIGKILL: - pr_err("Killed."); + pr_op_err("Killed."); break; default: - pr_err("The RSYNC was terminated by a signal [%d] I don't have a handler for. Dunno; guess I'll just die.", + pr_op_err("The RSYNC was terminated by a signal [%d] I don't have a handler for. Dunno; guess I'll just die.", WTERMSIG(child_status)); break; } return -EINTR; /* Meh? */ } - pr_err("The RSYNC command died in a way I don't have a handler for. Dunno; guess I'll die as well."); + pr_op_err("The RSYNC command died in a way I don't have a handler for. Dunno; guess I'll die as well."); return -EINVAL; } @@ -460,8 +456,8 @@ download_files(struct rpki_uri *requested_uri, bool is_ta, bool force) visited_uris = validation_rsync_visited_uris(state); if (!force && is_already_downloaded(requested_uri, visited_uris)) { - pr_debug("No need to redownload '%s'.", - uri_get_printable(requested_uri)); + pr_val_debug("No need to redownload '%s'.", + uri_val_get_printable(requested_uri)); return 0; } @@ -473,7 +469,7 @@ download_files(struct rpki_uri *requested_uri, bool is_ta, bool force) if (error) return error; - pr_debug("Going to RSYNC '%s'.", uri_get_printable(rsync_uri)); + pr_val_debug("Going to RSYNC '%s'.", uri_val_get_printable(rsync_uri)); to_op_log = reqs_errors_log_uri(uri_get_global(requested_uri)); error = do_rsync(rsync_uri, is_ta, to_op_log); diff --git a/src/rtr/db/db_table.c b/src/rtr/db/db_table.c index 195f6c2a..58a095e3 100644 --- a/src/rtr/db/db_table.c +++ b/src/rtr/db/db_table.c @@ -110,7 +110,7 @@ add_roa(struct db_table *table, struct hashable_roa *new) errno = 0; HASH_REPLACE(hh, table->roas, data, sizeof(new->data), new, old); if (errno) - return -pr_errno(errno, "ROA couldn't be added to hash table"); + return -pr_val_errno(errno, "ROA couldn't be added to hash table"); if (old != NULL) free(old); @@ -125,7 +125,7 @@ add_router_key(struct db_table *table, struct hashable_key *new) errno = 0; HASH_REPLACE(hh, table->router_keys, data, sizeof(new->data), new, old); if (errno) - return -pr_errno(errno, "Router Key couldn't be added to hash table"); + return -pr_val_errno(errno, "Router Key couldn't be added to hash table"); if (old != NULL) free(old); diff --git a/src/rtr/db/roa.c b/src/rtr/db/roa.c index 1ea7d757..9537a09b 100644 --- a/src/rtr/db/roa.c +++ b/src/rtr/db/roa.c @@ -34,7 +34,7 @@ roa_add_v4(struct roa *roa, uint32_t as, struct ipv4_prefix const *prefix, struct v4_address addr; if (roa->as != as) { - return pr_err("ROA has more than one ASN. (%u and %u)", + return pr_val_err("ROA has more than one ASN. (%u and %u)", roa->as, as); } @@ -50,7 +50,7 @@ roa_add_v6(struct roa *roa, uint32_t as, struct ipv6_prefix const *prefix, struct v6_address addr; if (roa->as != as) { - return pr_err("ROA has more than one ASN. (%u and %u)", + return pr_val_err("ROA has more than one ASN. (%u and %u)", roa->as, as); } diff --git a/src/rtr/db/vrps.c b/src/rtr/db/vrps.c index 5dce2fa5..ec6901c1 100644 --- a/src/rtr/db/vrps.c +++ b/src/rtr/db/vrps.c @@ -109,13 +109,13 @@ vrps_init(void) error = pthread_rwlock_init(&state_lock, NULL); if (error) { - error = pr_errno(error, "state pthread_rwlock_init() errored"); + error = pr_op_errno(error, "state pthread_rwlock_init() errored"); goto release_deltas; } error = pthread_rwlock_init(&table_lock, NULL); if (error) { - error = pr_errno(error, "table pthread_rwlock_init() errored"); + error = pr_op_errno(error, "table pthread_rwlock_init() errored"); goto release_state_lock; } @@ -387,15 +387,15 @@ vrps_update(bool *changed) * This wrapper is mainly for log informational data, so if there's no * need don't do unnecessary calls */ - if (!log_info_enabled()) + if (!log_op_info_enabled()) return __vrps_update(changed); - pr_info("Starting validation."); + pr_op_info("Starting validation."); serial = START_SERIAL; if (config_get_mode() == SERVER) { error = get_last_serial_number(&serial); if (!error) - pr_info("- Current serial number is %u.", serial); + pr_op_info("- Current serial number is %u.", serial); } time(&start); @@ -403,29 +403,29 @@ vrps_update(bool *changed) time(&finish); exec_time = finish - start; - pr_info("Validation finished:"); + pr_op_info("Validation finished:"); rwlock_read_lock(&state_lock); do { if (state.base == NULL) { rwlock_unlock(&state_lock); - pr_info("- Valid Prefixes: 0"); - pr_info("- Valid Router Keys: 0"); + pr_op_info("- Valid Prefixes: 0"); + pr_op_info("- Valid Router Keys: 0"); if (config_get_mode() == SERVER) - pr_info("- No serial number."); + pr_op_info("- No serial number."); break; } - pr_info("- Valid Prefixes: %u", db_table_roa_count(state.base)); - pr_info("- Valid Router Keys: %u", + pr_op_info("- Valid Prefixes: %u", db_table_roa_count(state.base)); + pr_op_info("- Valid Router Keys: %u", db_table_router_key_count(state.base)); if (config_get_mode() == SERVER) { - pr_info("- %s serial number is %u.", + pr_op_info("- %s serial number is %u.", serial == state.next_serial - 1 ? "Current" : "New", state.next_serial - 1); } rwlock_unlock(&state_lock); } while(0); - pr_info("- Real execution time: %ld secs.", exec_time); + pr_op_info("- Real execution time: %ld secs.", exec_time); return error; } diff --git a/src/rtr/pdu.c b/src/rtr/pdu.c index f238c639..f6e4c7de 100644 --- a/src/rtr/pdu.c +++ b/src/rtr/pdu.c @@ -126,9 +126,9 @@ pdu_load(int fd, struct sockaddr_storage *client_addr, return error; - if (log_debug_enabled()) { + if (log_op_debug_enabled()) { char buffer[INET6_ADDRSTRLEN]; - pr_debug("Received a %s from %s.", + pr_op_debug("Received a %s from %s.", pdutype2str(header.pdu_type), sockaddr2str(client_addr, buffer)); } diff --git a/src/rtr/pdu_handler.c b/src/rtr/pdu_handler.c index 4edb858d..de9f45a3 100644 --- a/src/rtr/pdu_handler.c +++ b/src/rtr/pdu_handler.c @@ -239,10 +239,10 @@ handle_error_report_pdu(int fd, struct rtr_request const *request) error_name = err_pdu_to_string(received->header.m.error_code); if (received->error_message != NULL) - pr_info("Client responded with error PDU '%s' ('%s'). Closing socket.", + pr_op_info("Client responded with error PDU '%s' ('%s'). Closing socket.", error_name, received->error_message); else - pr_info("Client responded with error PDU '%s'. Closing socket.", + pr_op_info("Client responded with error PDU '%s'. Closing socket.", error_name); return -EINVAL; diff --git a/src/rtr/pdu_sender.c b/src/rtr/pdu_sender.c index 01e2d7a4..8dd9138d 100644 --- a/src/rtr/pdu_sender.c +++ b/src/rtr/pdu_sender.c @@ -31,11 +31,11 @@ send_response(int fd, uint8_t pdu_type, unsigned char *data, size_t data_len) { int error; - pr_debug("Sending %s to client.", pdutype2str(pdu_type)); + pr_op_debug("Sending %s to client.", pdutype2str(pdu_type)); error = write(fd, data, data_len); if (error < 0) - return pr_errno(errno, "Error sending %s to client.", + return pr_op_errno(errno, "Error sending %s to client.", pdutype2str(pdu_type)); return 0; @@ -103,7 +103,7 @@ pr_debug_prefix4(struct ipv4_prefix_pdu *pdu) { char buffer[INET_ADDRSTRLEN]; - pr_debug("Encoded prefix %s/%u into a PDU.", + pr_op_debug("Encoded prefix %s/%u into a PDU.", addr2str4(&pdu->ipv4_prefix, buffer), pdu->prefix_length); } @@ -128,7 +128,7 @@ send_ipv4_prefix_pdu(int fd, uint8_t version, struct vrp const *vrp, len = serialize_ipv4_prefix_pdu(&pdu, data); if (len != RTRPDU_IPV4_PREFIX_LEN) pr_crit("Serialized IPv4 Prefix is %zu bytes.", len); - if (log_debug_enabled()) + if (log_op_debug_enabled()) pr_debug_prefix4(&pdu); return send_response(fd, pdu.header.pdu_type, data, len); @@ -139,7 +139,7 @@ pr_debug_prefix6(struct ipv6_prefix_pdu *pdu) { char buffer[INET6_ADDRSTRLEN]; - pr_debug("Encoded prefix %s/%u into a PDU.", + pr_op_debug("Encoded prefix %s/%u into a PDU.", addr2str6(&pdu->ipv6_prefix, buffer), pdu->prefix_length); } @@ -164,7 +164,7 @@ send_ipv6_prefix_pdu(int fd, uint8_t version, struct vrp const *vrp, len = serialize_ipv6_prefix_pdu(&pdu, data); if (len != RTRPDU_IPV6_PREFIX_LEN) pr_crit("Serialized IPv6 Prefix is %zu bytes.", len); - if (log_debug_enabled()) + if (log_op_debug_enabled()) pr_debug_prefix6(&pdu); return send_response(fd, pdu.header.pdu_type, data, len); diff --git a/src/rtr/primitive_reader.c b/src/rtr/primitive_reader.c index f2073bbb..25063ebc 100644 --- a/src/rtr/primitive_reader.c +++ b/src/rtr/primitive_reader.c @@ -33,11 +33,11 @@ read_exact(int fd, unsigned char *buffer, size_t buffer_len, bool allow_eof) for (offset = 0; offset < buffer_len; offset += read_result) { read_result = read(fd, &buffer[offset], buffer_len - offset); if (read_result == -1) - return -pr_errno(errno, "Client socket read interrupted"); + return -pr_op_errno(errno, "Client socket read interrupted"); if (read_result == 0) { if (!allow_eof) - pr_warn("Stream ended mid-PDU."); + pr_op_warn("Stream ended mid-PDU."); return -EPIPE; } @@ -63,7 +63,7 @@ pdu_reader_init(struct pdu_reader *reader, int fd, unsigned char *buffer, static int insufficient_bytes(void) { - pr_debug("Attempted to read past the end of a PDU Reader."); + pr_op_debug("Attempted to read past the end of a PDU Reader."); return -EINVAL; } @@ -218,7 +218,7 @@ read_string(struct pdu_reader *reader, uint32_t string_len, rtr_char **result) rtr_char *string; if (reader->size < string_len) - return pr_err("Erroneous PDU's error message is larger than its slot in the PDU."); + return pr_op_err("Erroneous PDU's error message is larger than its slot in the PDU."); /* * Ok. Since the PDU size is already sanitized, string_len is guaranteed diff --git a/src/rtr/rtr.c b/src/rtr/rtr.c index 257535d8..fe050b14 100644 --- a/src/rtr/rtr.c +++ b/src/rtr/rtr.c @@ -48,7 +48,7 @@ init_addrinfo(struct addrinfo **result) error = getaddrinfo(hostname, service, &hints, result); if (error) { - pr_err("Could not infer a bindable address out of address '%s' and port '%s': %s", + pr_op_err("Could not infer a bindable address out of address '%s' and port '%s': %s", (hostname != NULL) ? hostname : "any", service, gai_strerror(error)); return error; @@ -71,7 +71,7 @@ init_addrinfo(struct addrinfo **result) port = (unsigned char)((*result)->ai_addr->sa_data[0]) << 8; port += (unsigned char)((*result)->ai_addr->sa_data[1]); if (parsed != port) - return pr_err("Service port %s is out of range (max value is %d)", + return pr_op_err("Service port %s is out of range (max value is %d)", service, USHRT_MAX); return 0; @@ -99,33 +99,33 @@ create_server_socket(int *result) return error; for (addr = addrs; addr != NULL; addr = addr->ai_next) { - pr_info( + pr_op_info( "Attempting to bind socket to address '%s', port '%s'.", (addr->ai_canonname != NULL) ? addr->ai_canonname : "any", config_get_server_port()); fd = socket(addr->ai_family, SOCK_STREAM, 0); if (fd < 0) { - pr_errno(errno, "socket() failed"); + pr_op_errno(errno, "socket() failed"); continue; } /* enable SO_REUSEADDR */ if (setsockopt(fd, SOL_SOCKET, SO_REUSEADDR, &reuse, sizeof(int)) < 0) { - pr_errno(errno, "setsockopt(SO_REUSEADDR) failed"); + pr_op_errno(errno, "setsockopt(SO_REUSEADDR) failed"); continue; } /* enable SO_REUSEPORT */ if (setsockopt(fd, SOL_SOCKET, SO_REUSEPORT, &reuse, sizeof(int)) < 0) { - pr_errno(errno, "setsockopt(SO_REUSEPORT) failed"); + pr_op_errno(errno, "setsockopt(SO_REUSEPORT) failed"); continue; } if (bind(fd, addr->ai_addr, addr->ai_addrlen) < 0) { - pr_errno(errno, "bind() failed"); + pr_op_errno(errno, "bind() failed"); continue; } @@ -133,12 +133,12 @@ create_server_socket(int *result) if (error) { close(fd); freeaddrinfo(addrs); - return pr_errno(errno, "getsockname() failed"); + return pr_op_errno(errno, "getsockname() failed"); } port = (unsigned char)(addr->ai_addr->sa_data[0]) << 8; port += (unsigned char)(addr->ai_addr->sa_data[1]); - pr_info("Success; bound to address '%s', port '%ld'.", + pr_op_info("Success; bound to address '%s', port '%ld'.", (addr->ai_canonname != NULL) ? addr->ai_canonname : "any", port); freeaddrinfo(addrs); @@ -147,7 +147,7 @@ create_server_socket(int *result) } freeaddrinfo(addrs); - return pr_err("None of the addrinfo candidates could be bound."); + return pr_op_err("None of the addrinfo candidates could be bound."); } enum verdict { @@ -197,12 +197,12 @@ handle_accept_result(int client_fd, int err) goto retry; #pragma GCC diagnostic pop - pr_info("Client connection attempt not accepted: %s. Quitting...", + pr_op_info("Client connection attempt not accepted: %s. Quitting...", strerror(err)); return VERDICT_EXIT; retry: - pr_info("Client connection attempt not accepted: %s. Retrying...", + pr_op_info("Client connection attempt not accepted: %s. Retrying...", strerror(err)); return VERDICT_RETRY; } @@ -225,7 +225,7 @@ print_close_failure(int error, int fd) ? sockaddr2str(&sockaddr, buffer) : "(unknown)"; - pr_errno(error, "close() failed on socket of client %s", addr_str); + pr_op_errno(error, "close() failed on socket of client %s", addr_str); } static void @@ -239,7 +239,7 @@ static void print_client_addr(struct sockaddr_storage *addr, char const *action, int fd) { char buffer[INET6_ADDRSTRLEN]; - pr_info("Client %s [ID %d]: %s", action, fd, + pr_op_info("Client %s [ID %d]: %s", action, fd, sockaddr2str(addr, buffer)); } @@ -306,7 +306,7 @@ handle_client_connections(int server_fd) sizeof_client_addr = sizeof(client_addr); - pr_debug("Waiting for client connections..."); + pr_op_debug("Waiting for client connections..."); do { client_fd = accept(server_fd, (struct sockaddr *) &client_addr, &sizeof_client_addr); @@ -331,7 +331,7 @@ handle_client_connections(int server_fd) param = malloc(sizeof(struct thread_param)); if (param == NULL) { /* No error response PDU on memory allocation. */ - pr_err("Couldn't create thread parameters struct"); + pr_op_err("Couldn't create thread parameters struct"); close(client_fd); continue; } @@ -344,7 +344,7 @@ handle_client_connections(int server_fd) /* Error with min RTR version */ err_pdu_send_internal_error(client_fd, RTR_V0); if (error) { - pr_errno(error, "Could not spawn the client's thread"); + pr_op_errno(error, "Could not spawn the client's thread"); close(client_fd); free(param); } @@ -402,7 +402,7 @@ rtr_listen(void) if (config_get_mode() == STANDALONE) { error = vrps_update(&changed); if (error) - pr_err("Error %d while trying to update the ROA database.", + pr_op_err("Error %d while trying to update the ROA database.", error); goto revert_clients_db; /* Error 0 it's ok */ } diff --git a/src/slurm/db_slurm.c b/src/slurm/db_slurm.c index b50f8990..a4735107 100644 --- a/src/slurm/db_slurm.c +++ b/src/slurm/db_slurm.c @@ -456,19 +456,19 @@ print_prefix_data(struct slurm_prefix *prefix, void *arg) { char *pad = " "; - pr_info(" {"); + pr_op_info(" {"); if (prefix->data_flag & SLURM_COM_FLAG_ASN) - pr_info("%s ASN: %u", pad, prefix->vrp.asn); + pr_op_info("%s ASN: %u", pad, prefix->vrp.asn); if (prefix->data_flag & SLURM_PFX_FLAG_PREFIX) { switch (prefix->vrp.addr_fam) { case AF_INET: - pr_info("%s Prefix: %s/%u", pad, + pr_op_info("%s Prefix: %s/%u", pad, addr2str4(&prefix->vrp.prefix.v4, addr_buf), prefix->vrp.prefix_length); break; case AF_INET6: - pr_info("%s Prefix: %s/%u", pad, + pr_op_info("%s Prefix: %s/%u", pad, addr2str6(&prefix->vrp.prefix.v6, addr_buf), prefix->vrp.prefix_length); break; @@ -479,9 +479,9 @@ print_prefix_data(struct slurm_prefix *prefix, void *arg) } if (prefix->data_flag & SLURM_PFX_FLAG_MAX_LENGTH) - pr_info("%s Max prefix length: %u", pad, + pr_op_info("%s Max prefix length: %u", pad, prefix->vrp.max_prefix_length); - pr_info(" }"); + pr_op_info(" }"); return 0; } @@ -493,18 +493,19 @@ print_bgpsec_data(struct slurm_bgpsec *bgpsec, void *arg) char *buf; int error; - pr_info(" {"); + pr_op_info(" {"); if (bgpsec->data_flag & SLURM_COM_FLAG_ASN) - pr_info("%s ASN: %u", pad, bgpsec->asn); + pr_op_info("%s ASN: %u", pad, bgpsec->asn); if (bgpsec->data_flag & SLURM_BGPS_FLAG_SKI) { do { error = base64url_encode(bgpsec->ski, RK_SKI_LEN, &buf); if (error) { - pr_info("%s SKI: ", pad); + pr_op_info("%s SKI: ", + pad); break; } - pr_info("%s SKI: %s", pad, buf); + pr_op_info("%s SKI: %s", pad, buf); free(buf); } while (0); } @@ -514,15 +515,15 @@ print_bgpsec_data(struct slurm_bgpsec *bgpsec, void *arg) error = base64url_encode(bgpsec->router_public_key, RK_SPKI_LEN, &buf); if (error) { - pr_info("%s Router public key: ", + pr_op_info("%s Router public key: ", pad); break; } - pr_info("%s Router public key: %s", pad, buf); + pr_op_info("%s Router public key: %s", pad, buf); free(buf); } while (0); } - pr_info(" }"); + pr_op_info(" }"); return 0; } @@ -531,25 +532,25 @@ void db_slurm_log(struct db_slurm *db) { if (db->loaded_date_set) - pr_info("SLURM loaded at %s", + pr_op_info("SLURM loaded at %s", asctime(localtime(&db->loaded_date))); - pr_info("Validation output filters {"); - pr_info(" Prefix filters {"); + pr_op_info("Validation output filters {"); + pr_op_info(" Prefix filters {"); foreach_filter_prefix(&db->lists, print_prefix_data, NULL); - pr_info(" }"); - pr_info(" BGPsec filters {"); + pr_op_info(" }"); + pr_op_info(" BGPsec filters {"); foreach_filter_bgpsec(&db->lists, print_bgpsec_data, NULL); - pr_info(" }"); - pr_info("}"); + pr_op_info(" }"); + pr_op_info("}"); - pr_info("Locally added assertions {"); - pr_info(" Prefix assertions {"); + pr_op_info("Locally added assertions {"); + pr_op_info(" Prefix assertions {"); foreach_assertion_prefix(&db->lists, print_prefix_data, NULL); - pr_info(" }"); - pr_info(" BGPsec assertions {"); + pr_op_info(" }"); + pr_op_info(" BGPsec assertions {"); foreach_assertion_bgpsec(&db->lists, print_bgpsec_data, NULL); - pr_info(" }"); - pr_info("}"); + pr_op_info(" }"); + pr_op_info("}"); } int @@ -695,7 +696,7 @@ int db_slurm_set_csum_list(struct db_slurm *db, struct slurm_csum_list *list) { if (!SLIST_EMPTY(&db->csum_list)) - return pr_err("Checksum list for SLURM DB must be empty"); + pr_crit("Checksum list for SLURM DB must be empty"); db->csum_list.slh_first = list->slh_first; db->csum_list.list_size = list->list_size; diff --git a/src/slurm/slurm_loader.c b/src/slurm/slurm_loader.c index 9305daec..4bac7e89 100644 --- a/src/slurm/slurm_loader.c +++ b/src/slurm/slurm_loader.c @@ -153,7 +153,7 @@ __slurm_load_checksums(char const *location, void *arg) &csum->csum_len); if (error) { free(csum); - return pr_err("Calculating slurm hash"); + return pr_op_err("Calculating slurm hash"); } SLIST_INSERT_HEAD(list, csum, next); @@ -206,9 +206,9 @@ __load_slurm_files(struct db_slurm **last_slurm, error = load_slurm_files(params); if (error) { /* Any error: use last valid SLURM */ - pr_warn("Error loading SLURM, the validation will still continue."); + pr_op_info("Error loading SLURM, the validation will still continue."); if (*last_slurm != NULL) { - pr_warn("A previous valid version of the SLURM exists and will be applied."); + pr_op_info("A previous valid version of the SLURM exists and will be applied."); params->db_slurm = *last_slurm; /* Log applied SLURM as info */ db_slurm_log(params->db_slurm); @@ -272,7 +272,7 @@ load_updated_slurm(struct db_slurm **last_slurm, list_equals = false; - pr_info("Checking if there are new or modified SLURM files"); + pr_op_info("Checking if there are new or modified SLURM files"); error = slurm_load_checksums(&csum_list); if (error) return error; @@ -284,7 +284,7 @@ load_updated_slurm(struct db_slurm **last_slurm, if (list_equals) { if (*last_slurm != NULL) { - pr_info("Applying same old SLURM, no changes found."); + pr_op_info("Applying same old SLURM, no changes found."); params->db_slurm = *last_slurm; } destroy_local_csum_list(&csum_list); @@ -300,7 +300,7 @@ load_updated_slurm(struct db_slurm **last_slurm, return 0; } - pr_info("Applying configured SLURM"); + pr_op_info("Applying configured SLURM"); __load_slurm_files(last_slurm, params, &csum_list); return 0; diff --git a/src/slurm/slurm_parser.c b/src/slurm/slurm_parser.c index cbfb2467..de86085b 100644 --- a/src/slurm/slurm_parser.c +++ b/src/slurm/slurm_parser.c @@ -34,7 +34,7 @@ #define CHECK_REQUIRED(element, name) \ if (element == NULL) \ - return pr_err("SLURM member '%s' is required", name); + return pr_op_err("SLURM member '%s' is required", name); static int handle_json(json_t *, struct db_slurm *); @@ -55,7 +55,7 @@ slurm_parse(char const *location, void *arg) &json_error); if (json_root == NULL) /* File wasn't read or has a content error */ - return pr_err("SLURM JSON error on line %d, column %d: %s", + return pr_op_err("SLURM JSON error on line %d, column %d: %s", json_error.line, json_error.column, json_error.text); error = handle_json(json_root, params->db_slurm); @@ -76,7 +76,7 @@ set_asn(json_t *object, bool is_assertion, uint32_t *result, uint8_t *flag, error = json_get_int(object, ASN, &int_tmp); if (error == -ENOENT) { if (is_assertion) - return pr_err("ASN is required"); + return pr_op_err("ASN is required"); else return 0; /* Optional for filters */ } else if (error) @@ -84,7 +84,7 @@ set_asn(json_t *object, bool is_assertion, uint32_t *result, uint8_t *flag, /* An underflow or overflow will be considered here */ if (int_tmp < 0 || UINT32_MAX < int_tmp) - return pr_err("ASN (%lld) is out of range [0 - %u].", int_tmp, + return pr_op_err("ASN (%lld) is out of range [0 - %u].", int_tmp, UINT32_MAX); *flag = *flag | SLURM_COM_FLAG_ASN; *result = (uint32_t) int_tmp; @@ -126,7 +126,7 @@ set_prefix(json_t *object, bool is_assertion, struct slurm_prefix *result, error = json_get_string(object, PREFIX, &str_prefix); if (error && error == -ENOENT) { if (is_assertion) - return pr_err("SLURM assertion prefix is required"); + return pr_op_err("SLURM assertion prefix is required"); else return 0; /* Optional for filters */ } else if (error) @@ -134,7 +134,7 @@ set_prefix(json_t *object, bool is_assertion, struct slurm_prefix *result, clone = strdup(str_prefix); if (clone == NULL) - return -pr_errno(errno, "Couldn't allocate string to parse prefix"); + return -pr_op_errno(errno, "Couldn't allocate string to parse prefix"); token = strtok(clone, "/"); isv4 = strchr(token, ':') == NULL; @@ -193,11 +193,11 @@ set_max_prefix_length(json_t *object, bool is_assertion, uint8_t addr_fam, /* Unsupported by filters */ if (!is_assertion) - return pr_err("Prefix filter can't have a max prefix length"); + return pr_op_err("Prefix filter can't have a max prefix length"); /* An underflow or overflow will be considered here */ if (int_tmp <= 0 || (addr_fam == AF_INET ? 32 : 128) < int_tmp) - return pr_err("Max prefix length (%lld) is out of range [1 - %d].", + return pr_op_err("Max prefix length (%lld) is out of range [1 - %d].", int_tmp, (addr_fam == AF_INET ? 32 : 128)); *flag = *flag | SLURM_PFX_FLAG_MAX_LENGTH; @@ -216,7 +216,7 @@ validate_base64url_encoded(const char *encoded) * without trailing '=' (Section 5 of [RFC4648])" */ if (strrchr(encoded, '=') != NULL) - return pr_err("The base64 encoded value has trailing '='"); + return pr_op_err("The base64 encoded value has trailing '='"); /* * IMHO there's an error at RFC 8416 regarding the use of base64 @@ -246,7 +246,7 @@ set_ski(json_t *object, bool is_assertion, struct slurm_bgpsec *result, error = json_get_string(object, SKI, &str_encoded); if (error && error == -ENOENT) { if (is_assertion) - return pr_err("SLURM assertion %s is required", SKI); + return pr_op_err("SLURM assertion %s is required", SKI); else return 0; /* Optional for filters */ } else if (error) @@ -263,7 +263,7 @@ set_ski(json_t *object, bool is_assertion, struct slurm_bgpsec *result, /* Validate that's at least 20 octects long */ if (ski_len != RK_SKI_LEN) { free(result->ski); - return pr_err("The decoded SKI must be 20 octets long"); + return pr_op_err("The decoded SKI must be 20 octets long"); } result->data_flag = result->data_flag | SLURM_BGPS_FLAG_SKI; @@ -288,12 +288,12 @@ validate_router_spki(unsigned char *data, size_t len) tmp = data; spki = d2i_X509_PUBKEY(NULL, &tmp, len); if (spki == NULL) - return crypto_err("Not a valid router public key"); + return op_crypto_err("Not a valid router public key"); ok = X509_PUBKEY_get0_param(&alg, NULL, NULL, &pa, spki); if (!ok) { X509_PUBKEY_free(spki); - return crypto_err("X509_PUBKEY_get0_param() returned %d", ok); + return op_crypto_err("X509_PUBKEY_get0_param() returned %d", ok); } error = validate_certificate_public_key_algorithm_bgpsec(pa); @@ -316,14 +316,14 @@ set_router_pub_key(json_t *object, bool is_assertion, /* Required by assertions */ if (error && is_assertion) { if (error == -ENOENT) - return pr_err("SLURM assertion %s is required", + return pr_op_err("SLURM assertion %s is required", ROUTER_PUBLIC_KEY); return error; } /* Unsupported by filters */ if (!is_assertion) - return pr_err("BGPsec filter can't have a router public key"); + return pr_op_err("BGPsec filter can't have a router public key"); error = validate_base64url_encoded(str_encoded); if (error) @@ -332,7 +332,7 @@ set_router_pub_key(json_t *object, bool is_assertion, error = base64url_decode(str_encoded, &result->router_public_key, &spk_len); if (error) - return pr_err("'%s' couldn't be decoded", str_encoded); + return pr_op_err("'%s' couldn't be decoded", str_encoded); /* * Validate that "is the full ASN.1 DER encoding of the @@ -369,7 +369,7 @@ load_single_prefix(json_t *object, struct db_slurm *db, bool is_assertion) int error; if (!json_is_object(object)) - return pr_err("Not a valid JSON object"); + return pr_op_err("Not a valid JSON object"); init_slurm_prefix(&result); member_count = 0; @@ -395,17 +395,17 @@ load_single_prefix(json_t *object, struct db_slurm *db, bool is_assertion) /* A single comment isn't valid */ if (result.data_flag == SLURM_COM_FLAG_COMMENT) - return pr_err("Single comments aren't valid"); + return pr_op_err("Single comments aren't valid"); /* A filter must have ASN and/or prefix */ if (!is_assertion) { if ((result.data_flag & (SLURM_COM_FLAG_ASN | SLURM_PFX_FLAG_PREFIX)) == 0) - return pr_err("Prefix filter must have an asn and/or prefix"); + return pr_op_err("Prefix filter must have an asn and/or prefix"); /* Validate expected members */ if (!json_valid_members_count(object, member_count)) - return pr_err("Prefix filter has unknown members (see RFC 8416 section 3.3.1)"); + return pr_op_err("Prefix filter has unknown members (see RFC 8416 section 3.3.1)"); error = db_slurm_add_prefix_filter(db, &result); if (error) @@ -421,11 +421,11 @@ load_single_prefix(json_t *object, struct db_slurm *db, bool is_assertion) if ((result.data_flag & SLURM_PFX_FLAG_MAX_LENGTH) > 0 && result.vrp.prefix_length > result.vrp.max_prefix_length) - return pr_err("Prefix length is greater than max prefix length"); + return pr_op_err("Prefix length is greater than max prefix length"); /* Validate expected members */ if (!json_valid_members_count(object, member_count)) - return pr_err("Prefix assertion has unknown members (see RFC 8416 section 3.4.1)"); + return pr_op_err("Prefix assertion has unknown members (see RFC 8416 section 3.4.1)"); error = db_slurm_add_prefix_assertion(db, &result); if (error) @@ -445,13 +445,13 @@ load_prefix_array(json_t *array, struct db_slurm *db, bool is_assertion) if (!error) continue; if (error == -EEXIST) - pr_err( + pr_op_err( "The prefix %s element \"%s\", covers or is covered by another assertion/filter; SLURM loading will be stopped. %s", (is_assertion ? "assertion" : "filter"), json_dumps(element, 0), "TIP: More than 1 SLURM files were found, check if the prefix is contained in multiple files (see RFC 8416 section 4.2)."); else - pr_err( + pr_op_err( "Error at prefix %s, element \"%s\", SLURM loading will be stopped", (is_assertion ? "assertions" : "filters"), json_dumps(element, 0)); @@ -479,7 +479,7 @@ load_single_bgpsec(json_t *object, struct db_slurm *db, bool is_assertion) int error; if (!json_is_object(object)) - return pr_err("Not a valid JSON object"); + return pr_op_err("Not a valid JSON object"); init_slurm_bgpsec(&result); member_count = 0; @@ -504,7 +504,7 @@ load_single_bgpsec(json_t *object, struct db_slurm *db, bool is_assertion) /* A single comment isn't valid */ if (result.data_flag == SLURM_COM_FLAG_COMMENT) { - pr_err("Single comments aren't valid"); + pr_op_err("Single comments aren't valid"); error = -EINVAL; goto release_router_key; } @@ -513,14 +513,14 @@ load_single_bgpsec(json_t *object, struct db_slurm *db, bool is_assertion) if (!is_assertion) { if ((result.data_flag & (SLURM_COM_FLAG_ASN | SLURM_BGPS_FLAG_SKI)) == 0) { - pr_err("BGPsec filter must have an asn and/or SKI"); + pr_op_err("BGPsec filter must have an asn and/or SKI"); error = -EINVAL; goto release_router_key; } /* Validate expected members */ if (!json_valid_members_count(object, member_count)) { - pr_err("BGPsec filter has unknown members (see RFC 8416 section 3.3.2)"); + pr_op_err("BGPsec filter has unknown members (see RFC 8416 section 3.3.2)"); error = -EINVAL; goto release_router_key; } @@ -534,7 +534,7 @@ load_single_bgpsec(json_t *object, struct db_slurm *db, bool is_assertion) /* Validate expected members */ if (!json_valid_members_count(object, member_count)) { - pr_err("BGPsec assertion has unknown members (see RFC 8416 section 3.4.2)"); + pr_op_err("BGPsec assertion has unknown members (see RFC 8416 section 3.4.2)"); error = -EINVAL; goto release_router_key; } @@ -563,13 +563,13 @@ load_bgpsec_array(json_t *array, struct db_slurm *db, bool is_assertion) if (!error) continue; if (error == -EEXIST) - pr_err( + pr_op_err( "The ASN at bgpsec %s element \"%s\", is duplicated in another assertion/filter; SLURM loading will be stopped. %s", (is_assertion ? "assertion" : "filter"), json_dumps(element, 0), "TIP: More than 1 SLURM files were found, check if the ASN is contained in multiple files (see RFC 8416 section 4.2)."); else - pr_err( + pr_op_err( "Error at bgpsec %s, element \"%s\", SLURM loading will be stopped", (is_assertion ? "assertions" : "filters"), json_dumps(element, 0)); @@ -590,12 +590,12 @@ load_version(json_t *root) error = json_get_int(root, SLURM_VERSION, &version); if (error) return error == -ENOENT ? - pr_err("SLURM member '"SLURM_VERSION"' is required.") : + pr_op_err("SLURM member '"SLURM_VERSION"' is required.") : error; /* Validate data */ if (version != 1) - return pr_err("'%s' must be 1", SLURM_VERSION); + return pr_op_err("'%s' must be 1", SLURM_VERSION); return 0; } @@ -618,7 +618,7 @@ load_filters(json_t *root, struct db_slurm *db) expected_members = 2; if (!json_valid_members_count(filters, expected_members)) - return pr_err( + return pr_op_err( "SLURM '%s' must contain only %lu members (RFC 8416 section 3.2)", VALIDATION_OUTPUT_FILTERS, expected_members); @@ -653,7 +653,7 @@ load_assertions(json_t *root, struct db_slurm *db) expected_members = 2; if (!json_valid_members_count(assertions, expected_members)) - return pr_err( + return pr_op_err( "SLURM '%s' must contain only %lu members (RFC 8416 section 3.2)", LOCALLY_ADDED_ASSERTIONS, expected_members); @@ -676,7 +676,7 @@ handle_json(json_t *root, struct db_slurm *db) int error; if (!json_is_object(root)) - return pr_err("The root of the SLURM is not a JSON object."); + return pr_op_err("The root of the SLURM is not a JSON object."); error = load_version(root); if (error) @@ -695,7 +695,7 @@ handle_json(json_t *root, struct db_slurm *db) expected_members = 3; if (!json_valid_members_count(root, expected_members)) - return pr_err( + return pr_op_err( "SLURM root must have only %lu members (RFC 8416 section 3.2)", expected_members); diff --git a/src/state.c b/src/state.c index d8974d13..d31bedfb 100644 --- a/src/state.c +++ b/src/state.c @@ -104,7 +104,7 @@ validation_prepare(struct validation **out, struct tal *tal, result->x509_data.store = X509_STORE_new(); if (!result->x509_data.store) { - error = crypto_err("X509_STORE_new() returned NULL"); + error = val_crypto_err("X509_STORE_new() returned NULL"); goto abort1; } diff --git a/src/str.c b/src/str.c index 8d6991ae..58771667 100644 --- a/src/str.c +++ b/src/str.c @@ -27,7 +27,7 @@ int ia5s2string(ASN1_IA5STRING *ia5, char **result) { return (ia5->flags & ASN1_STRING_FLAG_BITS_LEFT) - ? pr_err("CRL URI IA5String has unused bits.") + ? pr_val_err("CRL URI IA5String has unused bits.") : string_clone(ia5->data, ia5->length, result); } @@ -47,7 +47,7 @@ BN2string(BIGNUM *bn, char **_result) if (BN_print(bio, bn) == 0) { BIO_free(bio); - return crypto_err("Unable to print the BIGNUM into a BIO"); + return val_crypto_err("Unable to print the BIGNUM into a BIO"); } written = BIO_number_written(bio); diff --git a/src/thread_var.c b/src/thread_var.c index 85875fd1..e6eab3fa 100644 --- a/src/thread_var.c +++ b/src/thread_var.c @@ -49,7 +49,7 @@ thvar_init(void) error = pthread_key_create(&state_key, NULL); if (error) { - pr_err( + pr_op_err( "Fatal: Errcode %d while initializing the validation state thread variable.", error); return error; @@ -63,7 +63,7 @@ thvar_init(void) */ error = pthread_key_create(&filenames_key, fnstack_discard); if (error) { - pr_err( + pr_op_err( "Fatal: Errcode %d while initializing the file name stack thread variable.", error); return error; @@ -71,7 +71,7 @@ thvar_init(void) error = pthread_key_create(&repository_key, working_repo_discard); if (error) { - pr_err( + pr_op_err( "Fatal: Errcode %d while initializing the 'working repository' thread variable.", error); return error; @@ -88,7 +88,7 @@ state_store(struct validation *state) error = pthread_setspecific(state_key, state); if (error) - pr_err("pthread_setspecific() returned %d.", error); + pr_op_err("pthread_setspecific() returned %d.", error); return error; } @@ -101,7 +101,7 @@ state_retrieve(void) state = pthread_getspecific(state_key); if (state == NULL) - pr_err("Programming error: This thread lacks a validation state."); + pr_op_err("Programming error: This thread lacks a validation state."); return state; } @@ -128,7 +128,7 @@ fnstack_init(void) error = pthread_setspecific(filenames_key, files); if (error) - pr_err("pthread_setspecific() returned %d.", error); + pr_op_err("pthread_setspecific() returned %d.", error); } void @@ -145,12 +145,12 @@ fnstack_cleanup(void) error = pthread_setspecific(filenames_key, NULL); if (error) - pr_err("pthread_setspecific() returned %d.", error); + pr_op_err("pthread_setspecific() returned %d.", error); } /** * Call this function every time you're about to start processing a new file. - * Any pr_err()s and friends will now include the new file name. + * Any pr_op_err()s and friends will now include the new file name. * Use fnstack_pop() to revert back to the previously stacked file name. * @file is not cloned; it's expected to outlive the push/pop operation. */ @@ -189,7 +189,7 @@ fnstack_push(char const *file) void fnstack_push_uri(struct rpki_uri *uri) { - fnstack_push(uri_get_printable(uri)); + fnstack_push(uri_val_get_printable(uri)); } /* Returns the file name on the top of the file name stack. */ @@ -234,7 +234,7 @@ working_repo_init(void) error = pthread_setspecific(repository_key, repo); if (error) - pr_err("pthread_setspecific() returned %d.", error); + pr_op_err("pthread_setspecific() returned %d.", error); } void @@ -251,7 +251,7 @@ working_repo_cleanup(void) error = pthread_setspecific(repository_key, NULL); if (error) - pr_err("pthread_setspecific() returned %d.", error); + pr_op_err("pthread_setspecific() returned %d.", error); } /* diff --git a/src/updates_daemon.c b/src/updates_daemon.c index 54c3de61..7adf70f3 100644 --- a/src/updates_daemon.c +++ b/src/updates_daemon.c @@ -27,17 +27,17 @@ check_vrps_updates(void *param_void) break; /* Process interrupted, terminate thread */ if (error) { - pr_err("Error while trying to update the ROA database. Sleeping..."); + pr_op_err("Error while trying to update the ROA database. Sleeping..."); continue; } if (changed) { error = notify_clients(); if (error) - pr_debug("Couldn't notify clients of the new VRPs. (Error code %d.) Sleeping...", + pr_op_debug("Couldn't notify clients of the new VRPs. (Error code %d.) Sleeping...", error); else - pr_debug("Database updated successfully. Sleeping..."); + pr_op_debug("Database updated successfully. Sleeping..."); } } while (true); @@ -52,11 +52,11 @@ updates_daemon_start(void) error = vrps_update(&changed); if (error) - return pr_err("First validation wasn't successful."); + return pr_op_err("First validation wasn't successful."); errno = pthread_create(&thread, NULL, check_vrps_updates, NULL); if (errno) - return -pr_errno(errno, + return -pr_op_errno(errno, "Could not spawn the update daemon thread"); return 0; diff --git a/src/uri.c b/src/uri.c index e9ac2466..dad25e60 100644 --- a/src/uri.c +++ b/src/uri.c @@ -102,7 +102,7 @@ validate_url_character(int character) */ return (0x20 <= character && character <= 0x7E) ? 0 - : pr_err("URL has non-printable character code '%d'.", character); + : pr_val_err("URL has non-printable character code '%d'.", character); } /** @@ -196,7 +196,7 @@ validate_uri_begin(char const *uri_pfx, const size_t uri_pfx_len, || strncmp(uri_pfx, global, uri_pfx_len) != 0) { if (!error) return -EINVAL; - pr_err("Global URI '%s' does not begin with '%s'.", + pr_val_err("Global URI '%s' does not begin with '%s'.", global, uri_pfx); return error; } @@ -238,7 +238,7 @@ validate_gprefix(char const *global, size_t global_len, uint8_t flags, error = validate_uri_begin(PFX_HTTPS, PFX_HTTPS_LEN, global, global_len, size, 0); if (error) { - pr_warn("URI '%s' does not begin with '%s' nor '%s'.", + pr_val_warn("URI '%s' does not begin with '%s' nor '%s'.", global, PFX_RSYNC, PFX_HTTPS); return ENOTSUPPORTED; } @@ -424,7 +424,7 @@ uri_create_ad(struct rpki_uri **uri, ACCESS_DESCRIPTION *ad, int flags) * to. */ if (type != GEN_URI) { - pr_err("Unknown GENERAL_NAME type: %d", type); + pr_val_err("Unknown GENERAL_NAME type: %d", type); return ENOTSUPPORTED; } @@ -520,12 +520,9 @@ get_filename(char const *file_path) return (slash != NULL) ? (slash + 1) : file_path; } -char const * -uri_get_printable(struct rpki_uri *uri) +static char const * +uri_get_printable(struct rpki_uri *uri, enum filename_format format) { - enum filename_format format; - - format = config_get_filename_format(); switch (format) { case FNF_GLOBAL: return uri->global; @@ -536,4 +533,22 @@ uri_get_printable(struct rpki_uri *uri) } pr_crit("Unknown file name format: %u", format); + return NULL; } + +char const * +uri_val_get_printable(struct rpki_uri *uri) { + enum filename_format format; + + format = config_get_val_log_filename_format(); + return uri_get_printable(uri, format); +} + +char const * +uri_op_get_printable(struct rpki_uri *uri) { + enum filename_format format; + + format = config_get_op_log_filename_format(); + return uri_get_printable(uri, format); +} + diff --git a/src/uri.h b/src/uri.h index 693c8a4f..0e7be926 100644 --- a/src/uri.h +++ b/src/uri.h @@ -33,6 +33,7 @@ bool uri_has_extension(struct rpki_uri *, char const *); bool uri_is_certificate(struct rpki_uri *); bool uri_is_rsync(struct rpki_uri *); -char const *uri_get_printable(struct rpki_uri *); +char const *uri_val_get_printable(struct rpki_uri *); +char const *uri_op_get_printable(struct rpki_uri *); #endif /* SRC_URI_H_ */ diff --git a/src/visited_uris.c b/src/visited_uris.c index 7bd4448d..a1ee1e8c 100644 --- a/src/visited_uris.c +++ b/src/visited_uris.c @@ -127,7 +127,7 @@ visited_uris_remove(struct visited_uris *uris, char const *uri) elem = elem_find(uris, uri); if (elem == NULL) - return pr_err("Trying to remove a nonexistent URI '%s'", uri); + return pr_val_err("Trying to remove a nonexistent URI '%s'", uri); HASH_DEL(uris->table, elem); visited_elem_destroy(elem); diff --git a/src/xml/relax_ng.c b/src/xml/relax_ng.c index ee8d7eae..e99c4599 100644 --- a/src/xml/relax_ng.c +++ b/src/xml/relax_ng.c @@ -21,13 +21,13 @@ relax_ng_init(void) rngparser = xmlRelaxNGNewMemParserCtxt(RRDP_V1_RNG, RRDP_V1_RNG_SIZE); if (rngparser == NULL) { - error = pr_err("xmlRelaxNGNewMemParserCtxt() returned NULL"); + error = pr_val_err("xmlRelaxNGNewMemParserCtxt() returned NULL"); goto cleanup_parser; } schema = xmlRelaxNGParse(rngparser); if (schema == NULL) { - error = pr_err("xmlRelaxNGParse() returned NULL"); + error = pr_val_err("xmlRelaxNGParse() returned NULL"); goto free_parser_ctx; } @@ -56,11 +56,11 @@ relax_ng_parse(const char *path, xml_read_cb cb, void *arg) reader = xmlNewTextReaderFilename(path); if (reader == NULL) - return pr_err("Couldn't get XML '%s' file.", path); + return pr_val_err("Couldn't get XML '%s' file.", path); error = xmlTextReaderRelaxNGSetSchema(reader, schema); if (error) { - error = pr_err("Couldn't set Relax NG schema."); + error = pr_val_err("Couldn't set Relax NG schema."); goto free_reader; } @@ -71,12 +71,12 @@ relax_ng_parse(const char *path, xml_read_cb cb, void *arg) } if (read < 0) { - error = pr_err("Error parsing XML document."); + error = pr_val_err("Error parsing XML document."); goto free_reader; } if (xmlTextReaderIsValid(reader) <= 0) { - error = pr_err("XML document isn't valid."); + error = pr_val_err("XML document isn't valid."); goto free_reader; }