[WSD] Add support for logging last 20MB for each of sent and received
authorftillier <ftillier@ad392aa1-c5ef-ae45-8dd8-e69d62a5ef86>
Wed, 2 Nov 2005 22:31:26 +0000 (22:31 +0000)
committerftillier <ftillier@ad392aa1-c5ef-ae45-8dd8-e69d62a5ef86>
Wed, 2 Nov 2005 22:31:26 +0000 (22:31 +0000)
data, based on work by Tzachi Dar.  Also fixed bug with flushed receive
work requests during socket duplictaion.

git-svn-id: svn://openib.tc.cornell.edu/gen1/trunk@141 ad392aa1-c5ef-ae45-8dd8-e69d62a5ef86

ulp/wsd/user/ib_cm.c
ulp/wsd/user/ibsp_duplicate.c
ulp/wsd/user/ibsp_iblow.c
ulp/wsd/user/ibspdebug.c
ulp/wsd/user/ibspdebug.h
ulp/wsd/user/ibspdll.c
ulp/wsd/user/ibspstruct.h

index 7c28c0b..b77376a 100644 (file)
@@ -156,12 +156,14 @@ cm_req_callback(
                {\r
                        int ret;\r
 \r
-                       wait_cq_drain( socket_info );\r
-\r
                        /* Non-blocking cancel since we're in CM callback context */\r
                        ib_cm_cancel( socket_info->listen.handle, NULL );\r
                        socket_info->listen.handle = NULL;\r
+                       cl_spinlock_release( &socket_info->mutex );\r
+\r
+                       wait_cq_drain( socket_info );\r
 \r
+                       cl_spinlock_acquire( &socket_info->mutex );\r
                        ret = ib_accept( socket_info, p_cm_req_rec );\r
                        if( ret )\r
                        {\r
index 6a1d0ad..4d093bf 100644 (file)
@@ -310,10 +310,10 @@ prepare_duplicate_socket(
 \r
        cl_spinlock_release( &socket_info->mutex );\r
        ib_disconnect( socket_info, &reason );\r
-       cl_spinlock_acquire( &socket_info->mutex );\r
 \r
        wait_cq_drain( socket_info );\r
 \r
+       cl_spinlock_acquire( &socket_info->mutex );\r
        ib_destroy_socket( socket_info );\r
 \r
        /* Put enough info in dup_info so that the remote socket can recreate the connection. */\r
index ca68250..67ec7ac 100644 (file)
@@ -90,8 +90,18 @@ complete_wq(
                 * GetOverlappedResult() even if we call lpWPUCompleteOverlappedRequest()\r
                 */\r
                if( wc->wc_type == IB_WC_RECV )\r
+               {\r
                        lpOverlapped->InternalHigh = wc->length;\r
 \r
+#ifdef IBSP_LOGGING\r
+                       cl_spinlock_acquire( &socket_info->recv_lock );\r
+                       DataLogger_WriteData(&socket_info->RecvDataLogger,\r
+                               p_recv_wr->idx, (void * __ptr64)p_recv_wr->ds_array[0].vaddr,\r
+                               wc->length);\r
+                       cl_spinlock_release( &socket_info->recv_lock );\r
+#endif\r
+               }\r
+\r
                lpOverlapped->OffsetHigh = 0;\r
                break;\r
 \r
@@ -127,6 +137,7 @@ complete_wq(
                        cl_spinlock_release( &socket_info->recv_lock );\r
 \r
                        cl_spinlock_release( &socket_info->mutex );\r
+                       p_io_info->p_ov = NULL;\r
                        IBSP_EXIT( IBSP_DBG_IO );\r
                        return;\r
                }\r
@@ -269,12 +280,6 @@ complete_wq(
                                 g_ibsp.overlap_h1_comp_count, g_ibsp.send_count, g_ibsp.recv_count));\r
 #endif\r
 \r
-               IBSP_TRACE1( IBSP_DBG_IO,\r
-                       ("Calling lpWPUCompleteOverlappedRequest: "\r
-                       "socket=%p, ov=%p OffsetHigh=%d InternalHigh=%d hEvent=%p\n",\r
-                       socket_info, lpOverlapped, lpOverlapped->OffsetHigh,\r
-                       lpOverlapped->InternalHigh, lpOverlapped->hEvent) );\r
-\r
                p_io_info->p_ov = lpOverlapped;\r
                cl_atomic_inc( &socket_info->ref_cnt );\r
        }\r
@@ -372,8 +377,11 @@ ib_cq_comp(
                        if( info[i].p_ov )\r
                        {\r
                                IBSP_TRACE1( IBSP_DBG_IO,\r
-                                       ("Calling WPUCompleteOverlappedRequest for ov=%p\n",\r
-                                       info[i].p_ov) );\r
+                                       ("Calling lpWPUCompleteOverlappedRequest: "\r
+                                       "socket=%p, ov=%p OffsetHigh=%d "\r
+                                       "InternalHigh=%d hEvent=%p\n",\r
+                                       info[i].p_socket, info[i].p_ov, info[i].p_ov->OffsetHigh,\r
+                                       info[i].p_ov->InternalHigh, info[i].p_ov->hEvent) );\r
 \r
                                ret = g_ibsp.up_call_table.lpWPUCompleteOverlappedRequest(\r
                                        info[i].p_socket->switch_socket, info[i].p_ov,\r
@@ -438,7 +446,7 @@ ib_cq_thread(
                }\r
 \r
                /* \r
-                * TODO: By rearanging thread creation and cq creation, this check\r
+                * TODO: By rearranging thread creation and cq creation, this check\r
                 * may be eliminated.\r
                 */\r
                if( cq_tinfo->cq != NULL )\r
@@ -515,7 +523,6 @@ ib_alloc_cq_tinfo(
        cq_tinfo->hca = hca;\r
        cq_tinfo->ib_cq_thread_exit_wanted = FALSE;\r
 \r
-       /* Create a cleanup thread */\r
        cq_tinfo->ib_cq_thread = CreateThread( NULL, 0, ib_cq_thread, cq_tinfo, 0, (LPDWORD)&cq_tinfo->ib_cq_thread_id );\r
 \r
        if( cq_tinfo->ib_cq_thread == NULL )\r
@@ -533,9 +540,8 @@ ib_alloc_cq_tinfo(
        cq_create.pfn_comp_cb = NULL;\r
        cq_create.h_wait_obj = cq_tinfo->cq_waitobj;\r
 \r
-       status = ib_create_cq( hca->hca_handle, &cq_create, cq_tinfo,   /* context */\r
-               NULL,   /* async handler */\r
-               &cq_tinfo->cq );\r
+       status = ib_create_cq( hca->hca_handle, &cq_create, cq_tinfo,\r
+               NULL, &cq_tinfo->cq );\r
        if( status )\r
        {\r
                ib_destroy_cq_tinfo( cq_tinfo );\r
@@ -1147,6 +1153,11 @@ shutdown_and_destroy_socket_info(
 \r
        ib_destroy_socket( socket_info );\r
 \r
+#ifdef IBSP_LOGGING\r
+       DataLogger_Shutdown(&socket_info->SendDataLogger);\r
+       DataLogger_Shutdown(&socket_info->RecvDataLogger);\r
+#endif\r
+\r
        /* Release the initial reference and clean up. */\r
        deref_socket_info( socket_info );\r
 \r
index a2e98c0..a8da7d9 100644 (file)
@@ -161,3 +161,137 @@ debug_dump_overlapped(
 }\r
 \r
 #endif /* _DEBUG_ */\r
+\r
+\r
+#ifdef IBSP_LOGGING\r
+\r
+VOID DataLogger_Init(\r
+                                       DataLogger                                      *pLogger,\r
+                                       char                                            *prefix,\r
+                                       struct sockaddr_in                      *addr1,\r
+                                       struct sockaddr_in                      *addr2 )\r
+{\r
+       HANDLE hFile;\r
+       HANDLE hMapFile;\r
+\r
+       char Name[100];\r
+       DWORD DataSize = 20 * 1024 * 1024; \r
+\r
+       sprintf(Name,"c:\\%s_%d.%d.%d.%d_%d_%d.%d.%d.%d_%d", \r
+               prefix,\r
+               addr1->sin_addr.S_un.S_un_b.s_b1,\r
+               addr1->sin_addr.S_un.S_un_b.s_b2,\r
+               addr1->sin_addr.S_un.S_un_b.s_b3,\r
+               addr1->sin_addr.S_un.S_un_b.s_b4,\r
+               CL_NTOH16(addr1->sin_port),\r
+               addr2->sin_addr.S_un.S_un_b.s_b1,\r
+               addr2->sin_addr.S_un.S_un_b.s_b2,\r
+               addr2->sin_addr.S_un.S_un_b.s_b3,\r
+               addr2->sin_addr.S_un.S_un_b.s_b4,\r
+               CL_NTOH16(addr2->sin_port)\r
+               );\r
+\r
+       pLogger->NextPrint = NULL;\r
+       pLogger->BufferStart = NULL;\r
+       pLogger->ShutdownClosed = FALSE;\r
+       pLogger->ToatalPrinted = 0;\r
+       pLogger->TotalSize = DataSize;\r
+\r
+       hFile = CreateFile( Name, GENERIC_READ|GENERIC_WRITE,\r
+               FILE_SHARE_READ | FILE_SHARE_WRITE, NULL, OPEN_ALWAYS,\r
+               FILE_ATTRIBUTE_NORMAL, NULL );\r
+\r
+       if (hFile != INVALID_HANDLE_VALUE)\r
+       {\r
+               IBSP_ERROR( ("CreateFile failed with error %d\n", GetLastError()) );\r
+               return;\r
+       }\r
+\r
+       hMapFile = CreateFileMapping(hFile,    // current file handle \r
+               NULL,                              // default security \r
+               PAGE_READWRITE,                    // read/write permission \r
+               0,                                 // max. object size \r
+               DataSize,                           // size of hFile \r
+               NULL);            // name of mapping object\r
+\r
+       CloseHandle( hFile );\r
+\r
+       if (hMapFile == NULL) \r
+       { \r
+               IBSP_ERROR( ("Could not create file mapping object.\n") );\r
+               return;\r
+       }\r
+\r
+       pLogger->BufferStart = MapViewOfFile(hMapFile, // handle to mapping object \r
+               FILE_MAP_ALL_ACCESS,               // read/write permission \r
+               0,                                 // max. object size \r
+               0,                                 // size of hFile \r
+               0);                                // map entire file \r
+\r
+       CloseHandle( hMapFile );\r
+\r
+       if( pLogger->BufferStart == NULL )\r
+       {\r
+               IBSP_ERROR( ("Could not MapViewOfFile.\n") );\r
+               return;\r
+       }\r
+\r
+       pLogger->NextPrint = pLogger->BufferStart;\r
+       cl_memclr(pLogger->NextPrint, DataSize);\r
+}\r
+\r
+\r
+VOID DataLogger_WriteData(\r
+                                       DataLogger                                      *pLogger,\r
+                                       long                                            Idx,\r
+                                       char                                            *Data,\r
+                                       DWORD                                           Len )\r
+{\r
+       char MessageHeader[16];\r
+       CL_ASSERT(Len < 64000);\r
+       CL_ASSERT(pLogger->ShutdownClosed == FALSE);\r
+       CL_ASSERT(Len < pLogger->TotalSize / 3);\r
+\r
+       if( !pLogger->BufferStart )\r
+               return;\r
+\r
+       cl_memset( MessageHeader, 0xff, sizeof(MessageHeader) );\r
+       cl_memcpy( MessageHeader+4, &Idx, sizeof(Idx) );\r
+       cl_memcpy( MessageHeader+8, &Len, sizeof(Len) );\r
+\r
+       pLogger->ToatalPrinted += Len;\r
+\r
+       if( pLogger->NextPrint + Len + (2 * sizeof (MessageHeader)) >\r
+               pLogger->BufferStart + pLogger->TotalSize )\r
+       {\r
+               /* We will now zero the remaing of the buffer, and restart */\r
+               cl_memclr( pLogger->NextPrint,\r
+                       pLogger->TotalSize - (pLogger->NextPrint - pLogger->BufferStart) );\r
+               pLogger->NextPrint = pLogger->BufferStart;\r
+       }\r
+\r
+       /* Just simple copy */\r
+       cl_memcpy( pLogger->NextPrint, MessageHeader, sizeof(MessageHeader) );\r
+       pLogger->NextPrint += sizeof(MessageHeader);\r
+\r
+       cl_memcpy( pLogger->NextPrint, Data, Len );\r
+       pLogger->NextPrint += Len;\r
+\r
+       /*\r
+        * Add the end marker but don't update NextPrint so the next message\r
+        * overwrites the previous message's end marker.\r
+        */\r
+       cl_memset( pLogger->NextPrint, 0xff, sizeof(MessageHeader) );\r
+}\r
+\r
+\r
+VOID DataLogger_Shutdown(\r
+                                       DataLogger                                      *pLogger )\r
+{\r
+       if( !pLogger->BufferStart )\r
+               return;\r
+\r
+       UnmapViewOfFile( pLogger->BufferStart );\r
+}\r
+\r
+#endif /* IBSP_LOGGING */\r
index 7d14e57..3a9f84e 100644 (file)
@@ -129,3 +129,41 @@ debug_dump_overlapped(
 #define STATS(expr)\r
 \r
 #endif /* _DEBUG_ */\r
+\r
+/*\r
+ * To enable logging of all Send/Receive data for each socket\r
+ * uncomment the following line.\r
+ */\r
+//#define IBSP_LOGGING\r
+\r
+#ifdef IBSP_LOGGING\r
+\r
+typedef struct DataLogger\r
+{\r
+       char                            *BufferStart;\r
+       size_t                          TotalSize;\r
+       char                            *NextPrint;\r
+       size_t                          ToatalPrinted;\r
+       BOOL                            ShutdownClosed;\r
+       HANDLE                          hMapFile;\r
+\r
+}DataLogger;\r
+\r
+\r
+VOID DataLogger_Init(\r
+                                       DataLogger                                      *pLoger,\r
+                                       char                                            *prefix,\r
+                                       struct sockaddr_in                      *addr1,\r
+                                       struct sockaddr_in                      *addr2 );\r
+\r
+\r
+VOID DataLogger_WriteData(\r
+                                       DataLogger                                      *pLoger,\r
+                                       long                                            Idx,\r
+                                       char                                            *Data,\r
+                                       DWORD                                           Len );\r
+\r
+VOID DataLogger_Shutdown(\r
+                                       DataLogger                                      *pLoger );\r
+\r
+#endif /* IBSP_LOGGING */\r
index e12a867..1c372a7 100644 (file)
@@ -143,6 +143,11 @@ _DllMain(
                        {\r
                                struct ibsp_socket_info *socket_info = NULL;\r
                                socket_info = PARENT_STRUCT(socket_item, struct ibsp_socket_info, item);\r
+\r
+#ifdef IBSP_LOGGING\r
+                               DataLogger_Shutdown(&socket_info->SendDataLogger);\r
+                               DataLogger_Shutdown(&socket_info->RecvDataLogger);\r
+#endif\r
                        }\r
 \r
                        cl_spinlock_release( &g_ibsp.socket_info_mutex );\r
@@ -275,6 +280,13 @@ accept_socket(
 \r
        new_socket_info->peer_addr = p_incoming->params.source;\r
 \r
+#ifdef IBSP_LOGGING\r
+       DataLogger_Init( &new_socket_info->SendDataLogger, "Send",\r
+               &new_socket_info->peer_addr, &new_socket_info->local_addr );\r
+       DataLogger_Init( &new_socket_info->RecvDataLogger, "Recv",\r
+               &new_socket_info->local_addr, &new_socket_info->peer_addr );\r
+#endif\r
+\r
        cl_spinlock_acquire( &new_socket_info->mutex );\r
        /* Update the state of the socket context */\r
        IBSP_CHANGE_SOCKET_STATE( new_socket_info, IBSP_CONNECTED );\r
@@ -785,6 +797,13 @@ IBSPConnect(
        /* Store the peer entity's address in socket context */\r
        socket_info->peer_addr = *addr;\r
 \r
+#ifdef IBSP_LOGGING\r
+       DataLogger_Init( &socket_info->SendDataLogger, "Send",\r
+               &socket_info->peer_addr, &socket_info->local_addr );\r
+       DataLogger_Init( &socket_info->RecvDataLogger, "Recv",\r
+               &socket_info->local_addr, &socket_info->peer_addr );\r
+#endif\r
+\r
        /* Update the socket state */\r
        IBSP_CHANGE_SOCKET_STATE( socket_info, IBSP_CONNECT );\r
 \r
@@ -1605,10 +1624,11 @@ IBSPRecv(
                         GetCurrentThreadId(), lpOverlapped,\r
                         g_ibsp.overlap_h0_count, g_ibsp.overlap_h1_count,\r
                         g_ibsp.overlap_h1_comp_count, g_ibsp.send_count, g_ibsp.recv_count));\r
-\r
-\r
 #endif\r
 \r
+#ifdef IBSP_LOGGING\r
+       wr->idx = socket_info->recv_log_idx++;\r
+#endif\r
 \r
        fzprint(("%s():%d:0x%x:0x%x: posting RECV socket=0x%p overlap=%p wr=0x%p\n",\r
                         __FUNCTION__, __LINE__, GetCurrentProcessId(), GetCurrentThreadId(), s,\r
@@ -1858,6 +1878,19 @@ IBSPSend(
        }\r
 #endif\r
 \r
+#ifdef IBSP_LOGGING\r
+       {\r
+               DWORD                                           i;\r
+\r
+               for( i=0; i < dwBufferCount; i++ )\r
+               {\r
+                       DataLogger_WriteData( &socket_info->SendDataLogger,\r
+                               socket_info->send_log_idx++, lpBuffers[i].buf,\r
+                               lpBuffers[i].len);\r
+               }\r
+       }\r
+#endif\r
+\r
        status = ib_post_send( socket_info->qp, &send_wr, NULL );\r
 \r
        if( status == IB_SUCCESS )\r
index 7936050..164d016 100644 (file)
@@ -109,6 +109,9 @@ struct _recv_wr
        struct _wr              wr;\r
        ib_recv_wr_t    recv;\r
        ib_local_ds_t   ds_array[QP_ATTRIB_RQ_SGE];\r
+#ifdef IBSP_LOGGING\r
+       LONG                    idx;\r
+#endif\r
 };\r
 \r
 \r
@@ -317,6 +320,13 @@ struct ibsp_socket_info
                DWORD identifier;               /* Unique identifier */\r
                DWORD dwProcessId;\r
        } duplicate;\r
+\r
+#ifdef IBSP_LOGGING\r
+       DataLogger              SendDataLogger;\r
+       DataLogger              RecvDataLogger;\r
+       long                    recv_log_idx;\r
+       long                    send_log_idx;\r
+#endif\r
 };\r
 \r
 \r