[Swan-dev] logging proposals and algorithms

[Andrew Cagney]

I've a TODO item sitting here asking that proposals always be logged
(it makes diagnosing a failing connection easier).

The current code will log the proposal if nothing is chosen (this is
still progress since the old code simply logged "no proposal chosen"
:-), however it isn't ideal.  The fix is "easy", but like the comment
says:

                /*
                 * For the moment don't libreswan_log() this as it
                 * gets written to the console, altering output, and
                 * causing test noise.
                 */
                pexpect(!accepted || matching_local_propnum ==
best_proposal->propnum);
                DBG(DBG_CONTROL, DBG_log("proposals: %s",
remote_proposals_buf->buf));
                /* transfer ownership of BEST_PROPOSAL to caller */
                *chosen_proposal = best_proposal;
                best_proposal = NULL;
                status = STF_OK;

I guess that could be dealt with by just sanitizing (deleting) the new
lines, not ideal.

But wait there's more; and the real reason I put this into the
too-painful basket.  The output isn't exactly pretty:

proposals:  IKE:AES_GCM_C(20)_256,PRF_HMAC_SHA1(2),PRF_HMAC_SHA2-256(5),AUTH_NONE(0),OAKLEY_GROUP_MODP2048(14),OAKLEY_GROUP_MODP4096(16),OAKLEY_GROUP_MODP8192(18)[first-match]
IKE:AES_GCM_A(18)_128,PRF_HMAC_SHA1(2),PRF_HMAC_SHA2-256(5),AUTH_NONE(0),OAKLEY_GROUP_MODP2048(14),OAKLEY_GROUP_MODP4096(16),OAKLEY_GROUP_MODP8192(18)
IKE:AES_CBC(12)_256,PRF_HMAC_SHA1(2),PRF_HMAC_SHA2-256(5),PRF_AES128-XCBC(4),AUTH_HMAC_SHA1_96(2),AUTH_HMAC_SHA2_256_128(12),AUTH_AES_XCBC_96(5),OAKLEY_GROUP_MODP1536(5),OAKLEY_GROUP_MODP2048(14)
IKE:AES_CBC(12)_128,PRF_HMAC_SHA1(2),PRF_HMAC_SHA2-256(5),PRF_AES128-XCBC(4),AUTH_HMAC_SHA1_96(2),AUTH_HMAC_SHA2_256_128(12),AUTH_AES_XCBC_96(5),OAKLEY_GROUP_MODP1536(5),OAKLEY_GROUP_MODP2048(14)

notice how some algorithms have OAKLEY_GROUP_ as a prefix yet others,
such as AES_GCM_C, do not.  This inconsistency stems from the enum
code and calls like:

        print_name_value(buf, prefix,
                         enum_name(ikev2_transid_val_descs[type],
                                   transform->id),
                         transform->id);
        if (transform->attr_keylen > 0) {
                print_join(buf,
                           snprintf(buf->buf + buf->pos,
sizeof(buf->buf) - buf->pos,
                                    "_%d", transform->attr_keylen));
        }

which print what ever the enum table defines.  When the prefix isn't
desired arbitrary bits get stripped off:

        strip_prefix(enum_name(&ikev2_trans_type_names, type), "TRANS_TYPE_");
        strip_prefix(enum_name(&ikev2_sec_proto_id_names, protoid),
"IKEv2_SEC_PROTO_");
        strip_prefix(enum_showb(&oakley_hash_names,
st->st_oakley.prf_hash, &prfbuf), "OAKLEY_");
        strip_prefix(enum_showb(&oakley_group_names,
st->st_oakley.group->group, &groupbuf), "OAKLEY_GROUP_"));
         strip_prefix(strip_prefix(enum_name(&auth_alg_names,
esp_info->auth), "AUTH_ALGORITHM_HMAC_"), "AUTH_ALGORITHM_"),

and this bubbles up to the log file.

While I can add to the hacks to fix this, I suspect it would be better
to just have the enum code handle it.

Andrew

(along with my buffer hack :-)