[ofw] [PATCH] IBAL: Make CM debug output useful
Fab Tillier
ftillier at windows.microsoft.com
Wed Feb 25 15:09:51 PST 2009
I have been spending some time looking at connection related issues at scale, and quickly came to realize that the entry/exit debug output lacks important information that would aid in debugging and understanding what goes on when looking at trace files.
I modified the entry/exit tracing in the CEP manager to give more information by using the AL_PRINT macro instead of AL_ENTER/EXIT.
Signed-off-by: Fab Tillier <ftillier at microsoft.com>
Index: core/al/kernel/al_cm_cep.c
===================================================================
--- core/al/kernel/al_cm_cep.c (revision 1978)
+++ core/al/kernel/al_cm_cep.c (working copy)
@@ -739,6 +739,7 @@ __format_req_av(
p_cep->av[idx].port_guid = p_port_cep->port_guid;
p_cep->av[idx].attr.port_num = p_port_cep->port_num;
+ AL_PRINT( TRACE_LEVEL_INFORMATION, AL_DBG_CM, ("Received REQ SL %d", conn_req_path_get_svc_lvl( p_path )) );
p_cep->av[idx].attr.sl = conn_req_path_get_svc_lvl( p_path );
p_cep->av[idx].attr.dlid = p_path->local_lid;
@@ -2742,11 +2743,11 @@ pdata_cmp:
match:
/* Everything matched. */
- AL_EXIT( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("] matched CID = %d\n", p_cep->cid) );
return p_cep;
}
- AL_EXIT( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("] not found\n") );
return NULL;
}
@@ -3387,6 +3388,9 @@ __complete_ndi_irp(
net32_t* p_new_cid = (net32_t*)cl_ioctl_out_buf( p_irp );
kcep_t* p_cep = (kcep_t*)p_mad->send_context1;
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM,
+ ("Completing al_cep_get_cid IRP with CID = %d\n", p_cep->cid) );
+
*p_new_cid = p_cep->cid;
p_irp->IoStatus.Information = sizeof(uint32_t);
p_irp->IoStatus.Status = STATUS_SUCCESS;
@@ -3401,7 +3405,7 @@ __cep_queue_mad(
IN kcep_t* const p_cep,
IN ib_mad_element_t* p_mad )
{
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", p_cep->cid) );
CL_ASSERT( !p_mad->p_next );
@@ -3665,10 +3669,14 @@ kal_cep_alloc(
KeReleaseInStackQueuedSpinLock( &hdl );
if( !p_cep )
+ {
+ AL_PRINT( TRACE_LEVEL_ERROR, AL_DBG_ERROR, ("Failed\n") );
return IB_INSUFFICIENT_MEMORY;
+ }
__bind_cep(p_cep, h_al, NULL, NULL);
*p_cid = p_cep->cid;
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("allocated CID = %d\n", p_cep->cid) );
return IB_SUCCESS;
}
@@ -3952,7 +3960,8 @@ __cleanup_cep(
ib_mad_element_t *p_mad;
kcep_t *p_new_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM,
+ ("[ p_cep = %p (CID = %d)\n", p_cep, p_cep->cid) );
CL_ASSERT( p_cep );
CL_ASSERT( KeGetCurrentIrql() == DISPATCH_LEVEL );
@@ -4138,7 +4147,7 @@ al_destroy_cep(
ib_pfn_destroy_cb_t pfn_destroy_cb;
int32_t ref_cnt;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM,("[ CID = %d\n", *p_cid) );
CL_ASSERT( h_al );
@@ -4226,7 +4235,7 @@ al_cep_listen(
intn_t cmp;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_listen_info );
@@ -4678,7 +4687,7 @@ kal_cep_pre_req(
KLOCK_QUEUE_HANDLE hdl;
cep_agent_t *p_port_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_cm_req );
@@ -4791,7 +4800,7 @@ al_cep_send_req(
KLOCK_QUEUE_HANDLE hdl;
cep_agent_t *p_port_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5127,7 +5136,7 @@ kal_cep_pre_rep(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_cm_rep );
@@ -5158,7 +5167,7 @@ al_cep_send_rep(
KLOCK_QUEUE_HANDLE hdl;
cep_agent_t *p_port_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5254,7 +5263,7 @@ al_cep_rtu(
cep_agent_t *p_port_cep;
ib_mad_element_t *p_mad;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5317,7 +5326,7 @@ al_cep_rej(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5410,7 +5419,7 @@ al_cep_mra(
ib_mad_element_t *p_mad;
uint8_t msg_mraed;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_cm_mra );
@@ -5547,7 +5556,7 @@ al_cep_lap(
cep_agent_t *p_port_cep;
ib_mad_element_t *p_mad;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_cm_lap );
@@ -5678,7 +5687,7 @@ al_cep_pre_apr(
KLOCK_QUEUE_HANDLE hdl;
cep_agent_t *p_port_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_cm_apr );
@@ -5766,7 +5775,7 @@ al_cep_send_apr(
KLOCK_QUEUE_HANDLE hdl;
cep_agent_t *p_port_cep;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5825,7 +5834,7 @@ al_cep_dreq(
cep_agent_t *p_port_cep;
ib_mad_element_t *p_mad;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5895,7 +5904,7 @@ al_cep_drep(
cep_agent_t *p_port_cep;
ib_mad_element_t *p_mad;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5946,7 +5955,7 @@ al_cep_migrate(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -5998,7 +6007,7 @@ al_cep_established(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
@@ -6301,7 +6310,7 @@ al_cep_get_rtr_attr(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_rtr );
@@ -6369,7 +6378,7 @@ al_cep_get_rts_attr(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_rts );
@@ -6475,7 +6484,7 @@ al_cep_poll(
kcep_t *p_cep;
KLOCK_QUEUE_HANDLE hdl;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
CL_ASSERT( p_new_cid );
@@ -6515,7 +6524,7 @@ al_cep_poll(
done:
KeReleaseInStackQueuedSpinLock( &hdl );
- AL_EXIT( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("] return %d\n", status) );
return status;
}
@@ -6678,7 +6687,7 @@ al_cep_get_cid(
KLOCK_QUEUE_HANDLE hdl;
ib_mad_element_t* p_mad = NULL;
- AL_ENTER( AL_DBG_NDI );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
KeAcquireInStackQueuedSpinLock( &gp_cep_mgr->lock, &hdl );
p_cep = __lookup_cep( h_al, cid );
@@ -6716,7 +6725,7 @@ al_cep_get_cid(
exit:
KeReleaseInStackQueuedSpinLock( &hdl );
- AL_EXIT( AL_DBG_NDI );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("] returned %08x\n", nt_status) );
return nt_status;
}
@@ -6734,7 +6743,7 @@ al_cep_get_pdata(
KLOCK_QUEUE_HANDLE hdl;
uint8_t copy_len;
- AL_ENTER( AL_DBG_CM );
+ AL_PRINT( TRACE_LEVEL_VERBOSE, AL_DBG_CM, ("[ CID = %d\n", cid) );
CL_ASSERT( h_al );
-------------- next part --------------
A non-text attachment was scrubbed...
Name: cep_dbg.patch
Type: application/octet-stream
Size: 7599 bytes
Desc: cep_dbg.patch
URL: <http://lists.openfabrics.org/pipermail/ofw/attachments/20090225/89f79ed0/attachment.obj>
More information about the ofw
mailing list