Add higher level debugging for all rpc calls

Print everything, except octet string buffers which are truncated.

Signed-off-by: Simo Sorce <simo@redhat.com>
Reviewed-by: Robbie Harwood <rharwood@redhat.com>

15 files changed, 805 insertions, 0 deletions

diff --git a/proxy/Makefile.am b/proxy/Makefile.am
index d7012d1..f13e740 100644
--- a/proxy/Makefile.am
+++ b/proxy/Makefile.am
@@ -149,6 +149,7 @@ gssproxy_SOURCES = \
     src/gp_workers.c \
     src/gp_creds.c \
     $(GP_RPCGEN_OBJ) \
+    src/gp_rpc_debug.c \
     src/gp_rpc_process.c \
     src/gp_conv.c \
     src/gp_export.c \
diff --git a/proxy/src/gp_rpc_accept_sec_context.c b/proxy/src/gp_rpc_accept_sec_context.c
index 97a465b..7b9d5df 100644
--- a/proxy/src/gp_rpc_accept_sec_context.c
+++ b/proxy/src/gp_rpc_accept_sec_context.c
@@ -30,6 +30,8 @@ int gp_accept_sec_context(struct gp_call_ctx *gpcall,
     asca = &arg->accept_sec_context;
     ascr = &res->accept_sec_context;
 
+    GPRPCDEBUG(gssx_arg_accept_sec_context, asca);
+
     exp_ctx_type = gp_get_exported_context_type(&asca->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -153,6 +155,7 @@ done:
     ret = gp_conv_status_to_gssx(&asca->call_ctx,
                                  ret_maj, ret_min, oid,
                                  &ascr->status);
+    GPRPCDEBUG(gssx_res_accept_sec_context, ascr);
 
     gss_release_name(&ret_min, &src_name);
     gss_release_buffer(&ret_min, &obuf);
diff --git a/proxy/src/gp_rpc_acquire_cred.c b/proxy/src/gp_rpc_acquire_cred.c
index 2a81bb8..e9deabf 100644
--- a/proxy/src/gp_rpc_acquire_cred.c
+++ b/proxy/src/gp_rpc_acquire_cred.c
@@ -24,6 +24,8 @@ int gp_acquire_cred(struct gp_call_ctx *gpcall,
     aca = &arg->acquire_cred;
     acr = &res->acquire_cred;
 
+    GPRPCDEBUG(gssx_arg_acquire_cred, aca);
+
     if (aca->input_cred_handle) {
         ret_maj = gp_import_gssx_cred(&ret_min, gpcall,
                                       aca->input_cred_handle, &in_cred);
@@ -137,6 +139,8 @@ done:
                                  ret_maj, ret_min, desired_mech,
                                  &acr->status);
 
+    GPRPCDEBUG(gssx_res_acquire_cred, acr);
+
     gss_release_cred(&ret_min, &out_cred);
     gss_release_oid_set(&ret_min, &use_mechs);
     gss_release_oid_set(&ret_min, &desired_mechs);
diff --git a/proxy/src/gp_rpc_debug.c b/proxy/src/gp_rpc_debug.c
new file mode 100644
index 0000000..2e2c050
--- /dev/null
+++ b/proxy/src/gp_rpc_debug.c
@@ -0,0 +1,693 @@
+/* Copyright (C) 2011 the GSS-PROXY contributors, see COPYING for license */
+
+#include "rpcgen/gss_proxy.h"
+#include "gp_rpc_debug.h"
+#include <ctype.h>
+
+void gpdbg_utf8string(utf8string *x)
+{
+    gp_debug_printf("\"%.*s\" ", (int)x->utf8string_len, x->utf8string_val);
+}
+
+void gpdbg_octet_string(octet_string *x)
+{
+    fprintf(stderr, "[ ");
+    if ((GP_RPC_DEBUG_FULL > gp_debug) && (x->octet_string_len > 16)) {
+        for (int i = 0; i < 16; i++) {
+            char c = x->octet_string_val[i];
+            fprintf(stderr, "%c", isalnum(c) ? c : '.');
+        }
+        fprintf(stderr, "... ] ");
+    } else {
+        for (int i = 0; i < x->octet_string_len; i++) {
+            fprintf(stderr, "%x", x->octet_string_val[i]);
+        }
+        fprintf(stderr, " ] ");
+    }
+}
+
+void gpdbg_gssx_uint64(gssx_uint64 *x)
+{
+    gp_debug_printf("%llu ", (long long unsigned)*x);
+}
+
+
+void gpdbg_gssx_OID(gssx_OID *x)
+{
+    gss_OID_desc oid = { x->octet_string_len, x->octet_string_val };
+    gss_buffer_desc oidbuf;
+    uint32_t maj, min;
+
+    if (x->octet_string_len == 0) {
+        gp_debug_printf("<None> ");
+        return;
+    }
+
+    maj = gss_oid_to_str(&min, &oid, &oidbuf);
+    if (GSS_ERROR(maj)) {
+        gp_debug_printf("<BAD OID> ");
+    } else {
+        gp_debug_printf("%.*s ", oidbuf.length, (char *)oidbuf.value);
+    }
+    maj = gss_release_buffer(&min, &oidbuf);
+}
+
+void gpdbg_gssx_OID_set(gssx_OID_set *x)
+{
+    gp_debug_printf("{ ");
+    for (int i = 0; i < x->gssx_OID_set_len; i++) {
+        gpdbg_gssx_OID(&x->gssx_OID_set_val[i]);
+    }
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_cred_usage(gssx_cred_usage *x)
+{
+    switch (*x) {
+    case GSSX_C_INITIATE:
+        gp_debug_printf("INITIATE ");
+        break;
+    case GSSX_C_ACCEPT:
+        gp_debug_printf("ACCEPT ");
+        break;
+    case GSSX_C_BOTH:
+        gp_debug_printf("BOTH ");
+        break;
+    default:
+        gp_debug_printf("<BAD CRED USAGE (%u)> ", (unsigned)*x);
+        break;
+    }
+}
+
+void gpdbg_gssx_option(gssx_option *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_buffer(&x->option);
+    gpdbg_gssx_buffer(&x->value);
+    gp_debug_printf("} ");
+}
+
+#define gpdbg_extensions(x) do { \
+    if ((x)->extensions.extensions_len > 0) { \
+        gp_debug_printf("[ "); \
+        for (int i = 0; i < (x)->extensions.extensions_len; i++) { \
+            gpdbg_gssx_option(&(x)->extensions.extensions_val[i]); \
+        } \
+        gp_debug_printf("] "); \
+    } \
+} while(0)
+
+#define gpdbg_options(x) do { \
+    if ((x)->options.options_len > 0) { \
+        gp_debug_printf("[ "); \
+        for (int i = 0; i < (x)->options.options_len; i++) { \
+            gpdbg_gssx_option(&(x)->options.options_val[i]); \
+        } \
+        gp_debug_printf("] "); \
+    } \
+} while(0)
+
+void gpdbg_gssx_mech_attr(gssx_mech_attr *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_OID(&x->attr);
+    gpdbg_gssx_buffer(&x->name);
+    gpdbg_gssx_buffer(&x->short_desc);
+    gpdbg_gssx_buffer(&x->long_desc);
+    gpdbg_extensions(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_mech_info(gssx_mech_info *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_OID(&x->mech);
+    gpdbg_gssx_OID_set(&x->name_types);
+    gpdbg_gssx_OID_set(&x->mech_attrs);
+    gpdbg_gssx_OID_set(&x->known_mech_attrs);
+    gpdbg_gssx_OID_set(&x->cred_options);
+    gpdbg_gssx_OID_set(&x->sec_ctx_options);
+    gpdbg_gssx_buffer(&x->saslname_sasl_mech_name);
+    gpdbg_gssx_buffer(&x->saslname_mech_name);
+    gpdbg_gssx_buffer(&x->saslname_mech_desc);
+    gpdbg_extensions(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_name_attr(gssx_name_attr *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_buffer(&x->attr);
+    gpdbg_gssx_buffer(&x->value);
+    gpdbg_extensions(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_status(gssx_status *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_uint64(&x->major_status);
+    gpdbg_gssx_OID(&x->mech);
+    gpdbg_gssx_uint64(&x->minor_status);
+    gpdbg_utf8string(&x->major_status_string);
+    gpdbg_utf8string(&x->minor_status_string);
+    gpdbg_octet_string(&x->server_ctx);
+    gpdbg_options(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_call_ctx(gssx_call_ctx *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_utf8string(&x->locale);
+    gpdbg_octet_string(&x->server_ctx);
+    gpdbg_options(x);
+    gp_debug_printf("} ");
+}
+
+#define gpdbg_name_attributes(X) do { \
+    gp_debug_printf("[ "); \
+    if (x->name_attributes.name_attributes_len > 0) { \
+        for (int i = 0; i < x->name_attributes.name_attributes_len; i++) { \
+            gpdbg_gssx_name_attr( \
+                &x->name_attributes.name_attributes_val[i]); \
+        } \
+    } \
+    gp_debug_printf("] "); \
+} while(0)
+
+void gpdbg_gssx_name(gssx_name *x)
+{
+    if (GP_RPC_DEBUG_FULL <= gp_debug) {
+        gp_debug_printf("{ ");
+    }
+    gpdbg_utf8string((utf8string *)&x->display_name);
+    if (GP_RPC_DEBUG_FULL <= gp_debug) {
+        gpdbg_gssx_OID(&x->name_type);
+        gpdbg_gssx_buffer(&x->exported_name);
+        gpdbg_gssx_buffer(&x->exported_composite_name);
+        gpdbg_name_attributes(x);
+        gpdbg_extensions(x);
+        gp_debug_printf("} ");
+    }
+}
+
+void gpdbg_gssx_cred_element(gssx_cred_element *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_name(&x->MN);
+    gpdbg_gssx_OID(&x->mech);
+    gpdbg_gssx_cred_usage(&x->cred_usage);
+    gpdbg_gssx_time(&x->initiator_time_rec);
+    gpdbg_gssx_time(&x->acceptor_time_rec);
+    gpdbg_options(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_cred(gssx_cred *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_name(&x->desired_name);
+    gp_debug_printf("[ ");
+    for (int i = 0; i < x->elements.elements_len; i++) {
+        gpdbg_gssx_cred_element(&x->elements.elements_val[i]);
+    }
+    gp_debug_printf("] ");
+    gpdbg_octet_string(&x->cred_handle_reference);
+    gp_debug_printf("%d } ", (int)x->needs_release);
+}
+
+void gpdbg_gssx_ctx(gssx_ctx *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_octet_string((octet_string *)&x->exported_context_token);
+    gpdbg_octet_string(&x->state);
+    gp_debug_printf("%d ", (int)x->needs_release);
+    gpdbg_gssx_OID(&x->mech);
+    gpdbg_gssx_name(&x->src_name);
+    gpdbg_gssx_name(&x->targ_name);
+    gpdbg_gssx_time(&x->lifetime);
+    gpdbg_gssx_uint64(&x->ctx_flags);
+    gp_debug_printf("%d ", (int)x->locally_initiated);
+    gp_debug_printf("%d ", (int)x->open);
+    gpdbg_options(x);
+    gp_debug_printf("} ");
+}
+
+void gpdbg_gssx_handle(gssx_handle *x)
+{
+    switch (x->handle_type) {
+    case GSSX_C_HANDLE_SEC_CTX:
+        gpdbg_gssx_ctx(&x->gssx_handle_u.sec_ctx_info);
+        break;
+    case GSSX_C_HANDLE_CRED:
+        gpdbg_gssx_cred(&x->gssx_handle_u.cred_info);
+        break;
+    default:
+        gp_debug_printf("<BAD HANDLE> ");
+        break;
+    }
+}
+
+void gpdbg_gssx_cb(gssx_cb *x)
+{
+    gp_debug_printf("{ ");
+    gpdbg_gssx_uint64(&x->initiator_addrtype);
+    gpdbg_gssx_buffer(&x->initiator_address);
+    gpdbg_gssx_uint64(&x->acceptor_addrtype);
+    gpdbg_gssx_buffer(&x->acceptor_address);
+    gpdbg_gssx_buffer(&x->application_data);
+    gp_debug_printf("} ");
+}
+
+/* Actual RPCs Start Here */
+void gpdbg_gssx_arg_release_handle(gssx_arg_release_handle *x)
+{
+    gp_debug_printf("    GSSX_ARG_RELEASE_HANDLE( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("cred_handle: ");
+    gpdbg_gssx_handle(&x->cred_handle);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_release_handle(gssx_res_release_handle *x)
+{
+    gp_debug_printf("    GSSX_RES_RELEASE_HANDLE( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_indicate_mechs(gssx_arg_indicate_mechs *x)
+{
+    gp_debug_printf("    GSSX_ARG_INDICATE_MECHS( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_indicate_mechs(gssx_res_indicate_mechs *x)
+{
+    gp_debug_printf("    GSSX_RES_INDICATE_MECHS( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("mechs: [ ");
+    for (int i = 0; i < x->mechs.mechs_len; i++) {
+        gpdbg_gssx_mech_info(&x->mechs.mechs_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("mech_attr_descs: [ ");
+    for (int i = 0; i < x->mech_attr_descs.mech_attr_descs_len; i++) {
+        gpdbg_gssx_mech_attr(&x->mech_attr_descs.mech_attr_descs_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("supported_extensions: [ ");
+    for (int i = 0;
+         i < x->supported_extensions.supported_extensions_len; i++) {
+        gpdbg_gssx_buffer(
+            &x->supported_extensions.supported_extensions_val[i]);
+    }
+    gp_debug_printf("] ");
+    gpdbg_extensions(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_import_and_canon_name(gssx_arg_import_and_canon_name *x)
+{
+    gp_debug_printf("    GSSX_ARG_IMPORT_AND_CANON_NAME( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("input_name: ");
+    gpdbg_gssx_name(&x->input_name);
+    gp_debug_printf("mech: ");
+    gpdbg_gssx_OID(&x->mech);
+    gp_debug_printf("name_attributes: ");
+    gpdbg_name_attributes(x);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_import_and_canon_name(gssx_res_import_and_canon_name *x)
+{
+    gp_debug_printf("    GSSX_RES_IMPORT_AND_CANON_NAME( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("output_name: ");
+    GPRPCDEBUG(gssx_name, x->output_name);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_get_call_context(gssx_arg_get_call_context *x)
+{
+    gp_debug_printf("    GSSX_ARG_GET_CALL_CONTEXT( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_get_call_context(gssx_res_get_call_context *x)
+{
+    gp_debug_printf("    GSSX_RES_GET_CALL_CONTEXT( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("server_call_ctx: ");
+    gpdbg_octet_string(&x->server_call_ctx);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_acquire_cred(gssx_arg_acquire_cred *x)
+{
+    gp_debug_printf("    GSSX_ARG_ACQUIRE_CRED( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("input_cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->input_cred_handle);
+    gp_debug_printf("add_cred: ");
+    gp_debug_printf("%d ", (int)x->add_cred_to_input_handle);
+    gp_debug_printf("desired_name: ");
+    GPRPCDEBUG(gssx_name, x->desired_name);
+    gp_debug_printf("time_req: ");
+    gpdbg_gssx_time(&x->time_req);
+    gp_debug_printf("desired_mechs: ");
+    gpdbg_gssx_OID_set(&x->desired_mechs);
+    gp_debug_printf("cred_usage: ");
+    gpdbg_gssx_cred_usage(&x->cred_usage);
+    gp_debug_printf("initiator_time_req: ");
+    gpdbg_gssx_time(&x->initiator_time_req);
+    gp_debug_printf("acceptor_time_req: ");
+    gpdbg_gssx_time(&x->acceptor_time_req);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_acquire_cred(gssx_res_acquire_cred *x)
+{
+    gp_debug_printf("    GSSX_RES_ACQUIRE_CRED( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("output_cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->output_cred_handle);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_export_cred(gssx_arg_export_cred *x)
+{
+    gp_debug_printf("    GSSX_ARG_EXPORT_CRED( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("input_cred_handle: ");
+    gpdbg_gssx_cred(&x->input_cred_handle);
+    gp_debug_printf("cred_usage: ");
+    gpdbg_gssx_cred_usage(&x->cred_usage);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_export_cred(gssx_res_export_cred *x)
+{
+    gp_debug_printf("    GSSX_RES_EXPORT_CRED( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("usage_exported: ");
+    gpdbg_gssx_cred_usage(&x->usage_exported);
+    gp_debug_printf("exported_handle: ");
+    if (x->exported_handle) {
+        gpdbg_octet_string(x->exported_handle);
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_import_cred(gssx_arg_import_cred *x)
+{
+    gp_debug_printf("    GSSX_ARG_IMPORT_CRED( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("exported_handle: ");
+    gpdbg_octet_string(&x->exported_handle);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_import_cred(gssx_res_import_cred *x)
+{
+    gp_debug_printf("    GSSX_RES_IMPORT_CRED( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("output_cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->output_cred_handle);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_store_cred(gssx_arg_store_cred *x)
+{
+    gp_debug_printf("    GSSX_ARG_STORE_CRED( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("input_cred_handle: ");
+    gpdbg_gssx_cred(&x->input_cred_handle);
+    gp_debug_printf("cred_usage: ");
+    gpdbg_gssx_cred_usage(&x->cred_usage);
+    gp_debug_printf("desired_mech: ");
+    gpdbg_gssx_OID(&x->desired_mech);
+    gp_debug_printf("overwrite_cred: ");
+    gp_debug_printf("%d ", (int)x->overwrite_cred);
+    gp_debug_printf("default_cred: ");
+    gp_debug_printf("%d ", (int)x->default_cred);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_store_cred(gssx_res_store_cred *x)
+{
+    gp_debug_printf("    GSSX_RES_STORE_CRED( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("elements_stored: ");
+    gpdbg_gssx_OID_set(&x->elements_stored);
+    gp_debug_printf("cred_usage_stored: ");
+    gpdbg_gssx_cred_usage(&x->cred_usage_stored);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_init_sec_context(gssx_arg_init_sec_context *x)
+{
+    gp_debug_printf("    GSSX_ARG_INIT_SEC_CONTEXT( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->cred_handle);
+    gp_debug_printf("target_name: ");
+    GPRPCDEBUG(gssx_name, x->target_name);
+    gp_debug_printf("mech_type: ");
+    gpdbg_gssx_OID(&x->mech_type);
+    gp_debug_printf("req_flags: ");
+    gpdbg_gssx_uint64(&x->req_flags);
+    gp_debug_printf("time_req: ");
+    gpdbg_gssx_time(&x->time_req);
+    gp_debug_printf("input_cb: ");
+    GPRPCDEBUG(gssx_cb, x->input_cb);
+    gp_debug_printf("input_token: ");
+    if (x->input_token) {
+        gpdbg_octet_string(x->input_token);
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_init_sec_context(gssx_res_init_sec_context *x)
+{
+    gp_debug_printf("    GSSX_RES_INIT_SEC_CONTEXT( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("output_token: ");
+    if (x->output_token) {
+        gpdbg_octet_string(x->output_token);
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_accept_sec_context(gssx_arg_accept_sec_context *x)
+{
+    gp_debug_printf("    GSSX_ARG_ACCEPT_SEC_CONTEXT( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->cred_handle);
+    gp_debug_printf("input_token: ");
+    gpdbg_octet_string(&x->input_token);
+    gp_debug_printf("input_cb: ");
+    GPRPCDEBUG(gssx_cb, x->input_cb);
+    gp_debug_printf("ret_deleg_cred: ");
+    gp_debug_printf("%d ", (int)x->ret_deleg_cred);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_accept_sec_context(gssx_res_accept_sec_context *x)
+{
+    gp_debug_printf("    GSSX_RES_ACCEPT_SEC_CONTEXT( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("output_token: ");
+    if (x->output_token) {
+        gpdbg_octet_string(x->output_token);
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gp_debug_printf("delegated_cred_handle: ");
+    GPRPCDEBUG(gssx_cred, x->delegated_cred_handle);
+    gpdbg_options(x);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_get_mic(gssx_arg_get_mic *x)
+{
+    gp_debug_printf("    GSSX_ARG_GET_MIC( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    gpdbg_gssx_ctx(&x->context_handle);
+    gp_debug_printf("qop_req: ");
+    gpdbg_gssx_qop(&x->qop_req);
+    gp_debug_printf("message_buffer: ");
+    gpdbg_octet_string(&x->message_buffer);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_get_mic(gssx_res_get_mic *x)
+{
+    gp_debug_printf("    GSSX_RES_GET_MIC( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("token_buffer: ");
+    gpdbg_octet_string(&x->token_buffer);
+    gp_debug_printf("qop_state: ");
+    GPRPCDEBUG(gssx_qop, x->qop_state);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_verify_mic(gssx_arg_verify_mic *x)
+{
+    gp_debug_printf("    GSSX_ARG_VERIFY_MIC( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    gpdbg_gssx_ctx(&x->context_handle);
+    gp_debug_printf("message_buffer: ");
+    gpdbg_octet_string(&x->message_buffer);
+    gp_debug_printf("token_buffer: ");
+    gpdbg_octet_string(&x->token_buffer);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_verify_mic(gssx_res_verify_mic *x)
+{
+    gp_debug_printf("    GSSX_RES_VERIFY_MIC( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("qop_state: ");
+    GPRPCDEBUG(gssx_qop, x->qop_state);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_wrap(gssx_arg_wrap *x)
+{
+    gp_debug_printf("    GSSX_ARG_WRAP( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    gpdbg_gssx_ctx(&x->context_handle);
+    gp_debug_printf("conf_req: ");
+    gp_debug_printf("%d ", (int)x->conf_req);
+    gp_debug_printf("message_buffer: [ ");
+    for (int i = 0; i < x->message_buffer.message_buffer_len; i++) {
+        gpdbg_octet_string(&x->message_buffer.message_buffer_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("qop_state: ");
+    gpdbg_gssx_qop(&x->qop_state);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_wrap(gssx_res_wrap *x)
+{
+    gp_debug_printf("    GSSX_RES_WRAP( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("token_buffer: [ ");
+    for (int i = 0; i < x->token_buffer.token_buffer_len; i++) {
+        gpdbg_octet_string(&x->token_buffer.token_buffer_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("conf_state: ");
+    if (x->conf_state) {
+        gp_debug_printf("%d ", (int)*(x->conf_state));
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gp_debug_printf("qop_state: ");
+    GPRPCDEBUG(gssx_qop, x->qop_state);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_arg_unwrap(gssx_arg_unwrap *x)
+{
+    gp_debug_printf("    GSSX_ARG_UNWRAP( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    gpdbg_gssx_ctx(&x->context_handle);
+    gp_debug_printf("token_buffer: [ ");
+    for (int i = 0; i < x->token_buffer.token_buffer_len; i++) {
+        gpdbg_octet_string(&x->token_buffer.token_buffer_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("qop_state: ");
+    gpdbg_gssx_qop(&x->qop_state);
+    gp_debug_printf(")\n");
+}
+
+void gpdbg_gssx_res_unwrap(gssx_res_unwrap *x)
+{
+    gp_debug_printf("    GSSX_RES_UNWRAP( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("context_handle: ");
+    GPRPCDEBUG(gssx_ctx, x->context_handle);
+    gp_debug_printf("message_buffer: [ ");
+    for (int i = 0; i < x->message_buffer.message_buffer_len; i++) {
+        gpdbg_octet_string(&x->message_buffer.message_buffer_val[i]);
+    }
+    gp_debug_printf("] ");
+    gp_debug_printf("conf_state: ");
+    if (x->conf_state) {
+        gp_debug_printf("%d ", (int)*(x->conf_state));
+    } else {
+        gp_debug_printf("<Null> ");
+    }
+    gp_debug_printf("qop_state: ");
+    GPRPCDEBUG(gssx_qop, x->qop_state);
+}
+
+void gpdbg_gssx_arg_wrap_size_limit(gssx_arg_wrap_size_limit *x)
+{
+    gp_debug_printf("    GSSX_ARG_WRAP_SIZE_LIMIT( call_ctx: ");
+    gpdbg_gssx_call_ctx(&x->call_ctx);
+    gp_debug_printf("context_handle: ");
+    gpdbg_gssx_ctx(&x->context_handle);
+    gp_debug_printf("conf_req: ");
+    gp_debug_printf("%d ", (int)x->conf_req);
+    gp_debug_printf("qop_state: ");
+    gpdbg_gssx_qop(&x->qop_state);
+    gp_debug_printf("req_output_size: ");
+    gpdbg_gssx_uint64(&x->req_output_size);
+}
+
+void gpdbg_gssx_res_wrap_size_limit(gssx_res_wrap_size_limit *x)
+{
+    gp_debug_printf("    GSSX_RES_WRAP_SIZE_LIMIT( status: ");
+    gpdbg_gssx_status(&x->status);
+    gp_debug_printf("max_input_size: ");
+    gpdbg_gssx_uint64(&x->max_input_size);
+}
diff --git a/proxy/src/gp_rpc_debug.h b/proxy/src/gp_rpc_debug.h
new file mode 100644
index 0000000..e6b2440
--- /dev/null
+++ b/proxy/src/gp_rpc_debug.h
@@ -0,0 +1,74 @@
+/* Copyright (C) 2011 the GSS-PROXY contributors, see COPYING for license */
+
+#ifndef _GP_RPC_DEBUG_H_
+#define _GP_RPC_DEBUG_H_
+
+#include "gp_debug.h"
+
+void gpdbg_utf8string(utf8string *x);
+void gpdbg_octet_string(octet_string *x);
+void gpdbg_gssx_uint64(gssx_uint64 *x);
+#define gpdbg_gssx_qop gpdbg_gssx_uint64
+#define gpdbg_gssx_buffer gpdbg_octet_string
+void gpdbg_gssx_OID(gssx_OID *x);
+void gpdbg_gssx_OID_set(gssx_OID_set *x);
+void gpdbg_gssx_cred_usage(gssx_cred_usage *x);
+#define gpdbg_gssx_time gpdbg_gssx_uint64
+void gpdbg_gssx_option(gssx_option *x);
+void gpdbg_gssx_mech_attr(gssx_mech_attr *x);
+void gpdbg_gssx_mech_info(gssx_mech_info *x);
+void gpdbg_gssx_name_attr(gssx_name_attr *x);
+void gpdbg_gssx_status(gssx_status *x);
+void gpdbg_gssx_call_ctx(gssx_call_ctx *x);
+void gpdbg_gssx_name(gssx_name *x);
+void gpdbg_gssx_cred_element(gssx_cred_element *x);
+void gpdbg_gssx_cred(gssx_cred *x);
+void gpdbg_gssx_ctx(gssx_ctx *x);
+void gpdbg_gssx_handle(gssx_handle *x);
+void gpdbg_gssx_cb(gssx_cb *x);
+
+void gpdbg_gssx_arg_release_handle(gssx_arg_release_handle *x);
+void gpdbg_gssx_res_release_handle(gssx_res_release_handle *x);
+void gpdbg_gssx_arg_indicate_mechs(gssx_arg_indicate_mechs *x);
+void gpdbg_gssx_res_indicate_mechs(gssx_res_indicate_mechs *x);
+void gpdbg_gssx_arg_import_and_canon_name(gssx_arg_import_and_canon_name *x);
+void gpdbg_gssx_res_import_and_canon_name(gssx_res_import_and_canon_name *x);
+void gpdbg_gssx_arg_get_call_context(gssx_arg_get_call_context *x);
+void gpdbg_gssx_res_get_call_context(gssx_res_get_call_context *x);
+void gpdbg_gssx_arg_acquire_cred(gssx_arg_acquire_cred *x);
+void gpdbg_gssx_res_acquire_cred(gssx_res_acquire_cred *x);
+void gpdbg_gssx_arg_export_cred(gssx_arg_export_cred *x);
+void gpdbg_gssx_res_export_cred(gssx_res_export_cred *x);
+void gpdbg_gssx_arg_import_cred(gssx_arg_import_cred *x);
+void gpdbg_gssx_res_import_cred(gssx_res_import_cred *x);
+void gpdbg_gssx_arg_store_cred(gssx_arg_store_cred *x);
+void gpdbg_gssx_res_store_cred(gssx_res_store_cred *x);
+void gpdbg_gssx_arg_init_sec_context(gssx_arg_init_sec_context *x);
+void gpdbg_gssx_res_init_sec_context(gssx_res_init_sec_context *x);
+void gpdbg_gssx_arg_accept_sec_context(gssx_arg_accept_sec_context *x);
+void gpdbg_gssx_res_accept_sec_context(gssx_res_accept_sec_context *x);
+void gpdbg_gssx_arg_get_mic(gssx_arg_get_mic *x);
+void gpdbg_gssx_res_get_mic(gssx_res_get_mic *x);
+void gpdbg_gssx_arg_verify_mic(gssx_arg_verify_mic *x);
+void gpdbg_gssx_res_verify_mic(gssx_res_verify_mic *x);
+void gpdbg_gssx_arg_wrap(gssx_arg_wrap *x);
+void gpdbg_gssx_res_wrap(gssx_res_wrap *x);
+void gpdbg_gssx_arg_unwrap(gssx_arg_unwrap *x);
+void gpdbg_gssx_res_unwrap(gssx_res_unwrap *x);
+void gpdbg_gssx_arg_wrap_size_limit(gssx_arg_wrap_size_limit *x);
+void gpdbg_gssx_res_wrap_size_limit(gssx_res_wrap_size_limit *x);
+
+#define GP_RPC_DEBUG_LVL 2
+#define GP_RPC_DEBUG_FULL 3
+
+#define GPRPCDEBUG(name, x) do { \
+    if (GP_RPC_DEBUG_LVL <= gp_debug) { \
+        if (x == NULL) { \
+            gp_debug_printf("<Null> "); \
+        } else { \
+            gpdbg_##name(x); \
+        } \
+    } \
+} while(0)
+
+#endif /* _GP_RPC_DEBUG_H_ */
diff --git a/proxy/src/gp_rpc_get_mic.c b/proxy/src/gp_rpc_get_mic.c
index 0a9a2c0..1d9a1fe 100644
--- a/proxy/src/gp_rpc_get_mic.c
+++ b/proxy/src/gp_rpc_get_mic.c
@@ -20,6 +20,8 @@ int gp_get_mic(struct gp_call_ctx *gpcall,
     gma = &arg->get_mic;
     gmr = &res->get_mic;
 
+    GPRPCDEBUG(gssx_arg_get_mic, gma);
+
     exp_ctx_type = gp_get_exported_context_type(&gma->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -79,6 +81,7 @@ int gp_get_mic(struct gp_call_ctx *gpcall,
 done:
     ret = gp_conv_status_to_gssx(&gma->call_ctx, ret_maj, ret_min,
                                  GSS_C_NO_OID, &gmr->status);
+    GPRPCDEBUG(gssx_res_get_mic, gmr);
     gss_release_buffer(&ret_min, &message_token);
     return ret;
 }
diff --git a/proxy/src/gp_rpc_import_and_canon_name.c b/proxy/src/gp_rpc_import_and_canon_name.c
index 7d7f974..3d67f40 100644
--- a/proxy/src/gp_rpc_import_and_canon_name.c
+++ b/proxy/src/gp_rpc_import_and_canon_name.c
@@ -24,6 +24,8 @@ int gp_import_and_canon_name(struct gp_call_ctx *gpcall,
     icna = &arg->import_and_canon_name;
     icnr = &res->import_and_canon_name;
 
+    GPRPCDEBUG(gssx_arg_import_and_canon_name, icna);
+
     if (icna->input_name.display_name.octet_string_len == 0 &&
         icna->input_name.exported_name.octet_string_len == 0) {
         ret_maj = GSS_S_FAILURE;
@@ -65,6 +67,7 @@ done:
     ret = gp_conv_status_to_gssx(&icna->call_ctx,
                                  ret_maj, ret_min, mech,
                                  &icnr->status);
+    GPRPCDEBUG(gssx_res_import_and_canon_name, icnr);
 
     gss_release_oid(&ret_min, &mech);
     gss_release_name(&ret_min, &import_name);
diff --git a/proxy/src/gp_rpc_indicate_mechs.c b/proxy/src/gp_rpc_indicate_mechs.c
index 886e076..c24b926 100644
--- a/proxy/src/gp_rpc_indicate_mechs.c
+++ b/proxy/src/gp_rpc_indicate_mechs.c
@@ -31,6 +31,8 @@ int gp_indicate_mechs(struct gp_call_ctx *gpcall,
     ima = &arg->indicate_mechs;
     imr = &res->indicate_mechs;
 
+    GPRPCDEBUG(gssx_arg_indicate_mechs, ima);
+
     /* get all mechs */
     ret_maj = gss_indicate_mechs(&ret_min, &mech_set);
     if (ret_maj) {
@@ -252,6 +254,7 @@ done:
     ret = gp_conv_status_to_gssx(&ima->call_ctx,
                                  ret_maj, ret_min, GSS_C_NO_OID,
                                  &imr->status);
+    GPRPCDEBUG(gssx_res_indicate_mechs, imr);
 
     gss_release_buffer(&ret_min, &long_desc);
     gss_release_buffer(&ret_min, &short_desc);
diff --git a/proxy/src/gp_rpc_init_sec_context.c b/proxy/src/gp_rpc_init_sec_context.c
index f006374..563275d 100644
--- a/proxy/src/gp_rpc_init_sec_context.c
+++ b/proxy/src/gp_rpc_init_sec_context.c
@@ -31,6 +31,8 @@ int gp_init_sec_context(struct gp_call_ctx *gpcall,
     isca = &arg->init_sec_context;
     iscr = &res->init_sec_context;
 
+    GPRPCDEBUG(gssx_arg_init_sec_context, isca);
+
     exp_ctx_type = gp_get_exported_context_type(&isca->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -159,6 +161,9 @@ done:
     ret = gp_conv_status_to_gssx(&isca->call_ctx,
                                  ret_maj, ret_min, mech_type,
                                  &iscr->status);
+
+    GPRPCDEBUG(gssx_res_init_sec_context, iscr);
+
     gss_release_name(&ret_min, &target_name);
     gss_release_oid(&ret_min, &mech_type);
     gss_release_cred(&ret_min, &ich);
diff --git a/proxy/src/gp_rpc_process.h b/proxy/src/gp_rpc_process.h
index a9436a6..eb02c95 100644
--- a/proxy/src/gp_rpc_process.h
+++ b/proxy/src/gp_rpc_process.h
@@ -15,6 +15,7 @@
 #include "rpcgen/gss_proxy.h"
 #include "rpcgen/gp_rpc.h"
 #include "gp_rpc_creds.h"
+#include "gp_rpc_debug.h"
 
 struct gssproxy_ctx;
 struct gp_service;
diff --git a/proxy/src/gp_rpc_release_handle.c b/proxy/src/gp_rpc_release_handle.c
index 4766750..4ffdfb9 100644
--- a/proxy/src/gp_rpc_release_handle.c
+++ b/proxy/src/gp_rpc_release_handle.c
@@ -15,6 +15,8 @@ int gp_release_handle(struct gp_call_ctx *gpcall,
     rha = &arg->release_handle;
     rhr = &res->release_handle;
 
+    GPRPCDEBUG(gssx_arg_release_handle, rha);
+
     switch (rha->cred_handle.handle_type) {
     case GSSX_C_HANDLE_SEC_CTX:
         /* We do not need release for any security
@@ -36,6 +38,7 @@ int gp_release_handle(struct gp_call_ctx *gpcall,
     ret = gp_conv_status_to_gssx(&rha->call_ctx,
                                  ret_maj, ret_min, GSS_C_NO_OID,
                                  &rhr->status);
+    GPRPCDEBUG(gssx_res_release_handle, rhr);
 
     return ret;
 }
diff --git a/proxy/src/gp_rpc_unwrap.c b/proxy/src/gp_rpc_unwrap.c
index 427f362..bc052cb 100644
--- a/proxy/src/gp_rpc_unwrap.c
+++ b/proxy/src/gp_rpc_unwrap.c
@@ -22,6 +22,8 @@ int gp_unwrap(struct gp_call_ctx *gpcall,
     uwa = &arg->unwrap;
     uwr = &res->unwrap;
 
+    GPRPCDEBUG(gssx_arg_unwrap, uwa);
+
     exp_ctx_type = gp_get_exported_context_type(&uwa->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -108,6 +110,7 @@ done:
                                  ret_maj, ret_min,
                                  GSS_C_NO_OID,
                                  &uwr->status);
+    GPRPCDEBUG(gssx_res_unwrap, uwr);
     gss_release_buffer(&ret_min, &output_message_buffer);
     return ret;
 }
diff --git a/proxy/src/gp_rpc_verify_mic.c b/proxy/src/gp_rpc_verify_mic.c
index 085a20d..d2920d2 100644
--- a/proxy/src/gp_rpc_verify_mic.c
+++ b/proxy/src/gp_rpc_verify_mic.c
@@ -21,6 +21,8 @@ int gp_verify_mic(struct gp_call_ctx *gpcall,
     vma = &arg->verify_mic;
     vmr = &res->verify_mic;
 
+    GPRPCDEBUG(gssx_arg_verify_mic, vma);
+
     exp_ctx_type = gp_get_exported_context_type(&vma->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -76,5 +78,6 @@ done:
                                  ret_maj, ret_min,
                                  GSS_C_NO_OID,
                                  &vmr->status);
+    GPRPCDEBUG(gssx_res_verify_mic, vmr);
     return ret;
 }
diff --git a/proxy/src/gp_rpc_wrap.c b/proxy/src/gp_rpc_wrap.c
index f892dcc..d5c950e 100644
--- a/proxy/src/gp_rpc_wrap.c
+++ b/proxy/src/gp_rpc_wrap.c
@@ -21,6 +21,8 @@ int gp_wrap(struct gp_call_ctx *gpcall,
     wa = &arg->wrap;
     wr = &res->wrap;
 
+    GPRPCDEBUG(gssx_arg_wrap, wa);
+
     exp_ctx_type = gp_get_exported_context_type(&wa->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -105,6 +107,7 @@ int gp_wrap(struct gp_call_ctx *gpcall,
 done:
     ret = gp_conv_status_to_gssx(&wa->call_ctx, ret_maj, ret_min,
                                  GSS_C_NO_OID, &wr->status);
+    GPRPCDEBUG(gssx_res_wrap, wr);
     gss_release_buffer(&ret_min, &output_message_buffer);
     return ret;
 }
diff --git a/proxy/src/gp_rpc_wrap_size_limit.c b/proxy/src/gp_rpc_wrap_size_limit.c
index 9c37d88..355113c 100644
--- a/proxy/src/gp_rpc_wrap_size_limit.c
+++ b/proxy/src/gp_rpc_wrap_size_limit.c
@@ -19,6 +19,8 @@ int gp_wrap_size_limit(struct gp_call_ctx *gpcall,
     wsla = &arg->wrap_size_limit;
     wslr = &res->wrap_size_limit;
 
+    GPRPCDEBUG(gssx_arg_wrap_size_limit, wsla);
+
     exp_ctx_type = gp_get_exported_context_type(&wsla->call_ctx);
     if (exp_ctx_type == -1) {
         ret_maj = GSS_S_FAILURE;
@@ -53,5 +55,6 @@ done:
                                  ret_maj, ret_min,
                                  GSS_C_NO_OID,
                                  &wslr->status);
+    GPRPCDEBUG(gssx_res_wrap_size_limit, wslr);
     return ret;
 }