diff --git a/src/epics/util/feCodeGen.pl b/src/epics/util/feCodeGen.pl index 1e870eb1f0cda5e059c1d551562622df24ee8efd..662dbcdc949486ff0575ae11dcfd855f2fcc1345 100755 --- a/src/epics/util/feCodeGen.pl +++ b/src/epics/util/feCodeGen.pl @@ -1586,6 +1586,15 @@ print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_MAX_WAIT_HOLD_NS epicsOutput.ipcMaxWai print OUTH "\tint slowIpcInList;\n"; print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_SLOW_IN_LIST epicsOutput.slowIpcInList int ao 0\n"; +print OUTH "\tint ipcAvgSendTime_ns;\n"; +print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_AVG_SEND_TIME_NS epicsOutput.ipcAvgSendTime_ns int ao 0\n"; + +print OUTH "\tint ipcMaxSendTime_ns;\n"; +print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_MAX_SEND_TIME_NS epicsOutput.ipcMaxSendTime_ns int ao 0\n"; + +print OUTH "\tint ipcMaxSendTimeHold_ns;\n"; +print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_MAX_SEND_TIME_HOLD_NS epicsOutput.ipcMaxSendTimeHold_ns int ao 0\n"; + print OUTH "\tint IPC_TOTAL_SENDERS;\n"; print EPICS "OUTVARIABLE FEC\_$dcuId\_IPC_TOTAL_SENDERS epicsOutput.IPC_TOTAL_SENDERS int ao 0\n"; print OUTH "\tint IPC_TOTAL_RECEIVERS;\n"; diff --git a/src/epics/util/lib/IPCx.pm b/src/epics/util/lib/IPCx.pm index cbc331d61db69568edf9f7cbf83e0f3c66dccfc3..07061815a9dfee50e6f0f2dbb95e5d567077d2cf 100644 --- a/src/epics/util/lib/IPCx.pm +++ b/src/epics/util/lib/IPCx.pm @@ -836,7 +836,7 @@ my ($medmDir,$mdlName,$ifo,$dcuid,$medmTarget,$ipcxCnt1) = @_; ); # Calculate screen height based on number of IPC RCV signals - my $ind_ipc_ypos_start = 55; #This is the ypos start of the individual IPC table and column header + my $ind_ipc_ypos_start = 70; #This is the ypos start of the individual IPC table and column header my $dispH = $ind_ipc_ypos_start + 20; for(my $ii=0;$ii<$ipcxCnt1;$ii++) { @@ -865,6 +865,7 @@ my ($medmDir,$mdlName,$ifo,$dcuid,$medmTarget,$ipcxCnt1) = @_; $medmdata .= ("CDS::medmGen::medmGenText") -> ("310","3","100","15","IPC RCV STATUS",$ecolors{white}); # Add IPC Waiting Stats + $medmdata .= ("CDS::medmGen::medmGenText") -> (10, 30, 10, 15,"RX:",$ecolors{black}); $medmdata .= ("CDS::medmGen::medmGenText") -> (25, 30, 100, 15,"Late/s:",$ecolors{black}); $medmdata .= ("CDS::medmGen::medmGenTextMon") -> (110, 30, 50, 15, "$::ifo\:FEC-$::dcuId\_IPC_NUM_LATE",$ecolors{white},$ecolors{black}); @@ -877,6 +878,19 @@ my ($medmDir,$mdlName,$ifo,$dcuid,$medmTarget,$ipcxCnt1) = @_; $medmdata .= ("CDS::medmGen::medmGenText") -> (520, 30, 100, 15,"Slow IPC in List:",$ecolors{black}); $medmdata .= ("CDS::medmGen::medmGenTextMon") -> (630, 30, 50, 15, "$::ifo\:FEC-$::dcuId\_IPC_SLOW_IN_LIST",$ecolors{white},$ecolors{black}); + # Add IPC Send Timing Stats + $medmdata .= ("CDS::medmGen::medmGenText") -> (10, 50, 10, 15,"TX:",$ecolors{black}); + my $tx_ipc_start_indx = 60; + $medmdata .= ("CDS::medmGen::medmGenText") -> ($tx_ipc_start_indx, 50, 100, 15,"Avg Send Time (ns):",$ecolors{black}); + $medmdata .= ("CDS::medmGen::medmGenTextMon") -> ($tx_ipc_start_indx+115, 50, 50, 15, "$::ifo\:FEC-$::dcuId\_IPC_AVG_SEND_TIME_NS",$ecolors{white},$ecolors{black}); + + $medmdata .= ("CDS::medmGen::medmGenText") -> ($tx_ipc_start_indx+190, 50, 100, 15,"Max Send Time (ns):",$ecolors{black}); + $medmdata .= ("CDS::medmGen::medmGenTextMon") -> ($tx_ipc_start_indx+305, 50, 50, 15, "$::ifo\:FEC-$::dcuId\_IPC_MAX_SEND_TIME_NS",$ecolors{white},$ecolors{black}); + + $medmdata .= ("CDS::medmGen::medmGenText") -> ($tx_ipc_start_indx+375, 50, 100, 15,"Max Send Hold (ns):",$ecolors{black}); + $medmdata .= ("CDS::medmGen::medmGenTextMon") -> ($tx_ipc_start_indx+495, 50, 50, 15, "$::ifo\:FEC-$::dcuId\_IPC_MAX_SEND_TIME_HOLD_NS",$ecolors{white},$ecolors{black}); + + # Add the IPC column headings $medmdata .= ("CDS::medmGen::medmGenText") -> (80, $ind_ipc_ypos_start + 5, 100, 15,"SIGNAL NAME",$ecolors{black}); diff --git a/src/fe/commData3.c b/src/fe/commData3.c index d07fc479f91484b5ec98703b0092485d1301966a..5d52515711d36be99b7f314991399875d5bf817e 100644 --- a/src/fe/commData3.c +++ b/src/fe/commData3.c @@ -322,6 +322,9 @@ void commData3Send( int sendBlock; /// \param sendBlock Data block data is to be sent to int lastPcie = -1; int dolphinEnabled = 1; + LIGO_DUR_t send_timer; + + timer_start( &send_timer ); #ifdef RFM_DELAY // Need to write ahead one extra block @@ -459,6 +462,13 @@ void commData3Send( 16 ); } #endif + + LIGO_DUR_t total_time_ns = timer_end_ns( &send_timer ); + g_ipc_wait_time_stats.ipcTotalSendTime_ns += total_time_ns; + if( total_time_ns > g_ipc_wait_time_stats.ipcMaxSendTime_ns ) + g_ipc_wait_time_stats.ipcMaxSendTime_ns = total_time_ns; + + } // ************************************************************************************************* @@ -616,8 +626,50 @@ void commData3SetCycleStartTime(LIGO_DUR_t cycle_start_tsc) g_cycle_start_tsc = cycle_start_tsc; } +/* void commData3GetStats( CDS_IPC_STATS_t * stats_ptr) { memcpy((void*)stats_ptr, &g_ipc_wait_time_stats, sizeof(*stats_ptr)); +}*/ + + +void ipc_subsys_1Hz_stats_update( volatile CDS_EPICS* epics_ptr ) +{ + + //Calc Recv Stats + epics_ptr->epicsOutput.ipcNumWaitsInSec = g_ipc_wait_time_stats.numWaitsInSec; + epics_ptr->epicsOutput.ipcMaxWait_ns = g_ipc_wait_time_stats.ipcMaxWait_ns; + if( g_ipc_wait_time_stats.slowIpcListIndex != 0) + epics_ptr->epicsOutput.slowIpcInList = g_ipc_wait_time_stats.slowIpcListIndex; + if( g_ipc_wait_time_stats.ipcMaxWait_ns > epics_ptr->epicsOutput.ipcMaxWaitHold_ns) + epics_ptr->epicsOutput.ipcMaxWaitHold_ns = g_ipc_wait_time_stats.ipcMaxWait_ns; + + //Calc Send Stats + epics_ptr->epicsOutput.ipcMaxSendTime_ns = g_ipc_wait_time_stats.ipcMaxSendTime_ns; + epics_ptr->epicsOutput.ipcAvgSendTime_ns = + g_ipc_wait_time_stats.ipcTotalSendTime_ns / (MODEL_RATE_HZ / UNDERSAMPLE); + + if( g_ipc_wait_time_stats.ipcMaxSendTime_ns > epics_ptr->epicsOutput.ipcMaxSendTimeHold_ns) + { + epics_ptr->epicsOutput.ipcMaxSendTimeHold_ns = g_ipc_wait_time_stats.ipcMaxSendTime_ns; + } + + if( g_ipc_wait_time_stats.ipcMaxSendTime_ns > IPC_MAX_SEND_TIME_NS ) + { + RTSLOG_WARN("A commData3Send() (IPC) send call took %d ns, in the last second...\n", + g_ipc_wait_time_stats.ipcMaxSendTime_ns); + } + + //Clear stats for next second memset(&g_ipc_wait_time_stats, 0, sizeof(g_ipc_wait_time_stats)); + + + return; } + +void ipc_subsys_diag_reset( volatile CDS_EPICS* epics_ptr ) +{ + epics_ptr->epicsOutput.ipcMaxWaitHold_ns = 0; + epics_ptr->epicsOutput.slowIpcInList = 0; + epics_ptr->epicsOutput.ipcMaxSendTimeHold_ns = 0; +} \ No newline at end of file diff --git a/src/fe/controllerApp.c b/src/fe/controllerApp.c index 7c2a6bd07e3df38b0480b9185f09b5960818aff4..4a1e9a6d747da8a3b2a8532cab17a9dc3ae2a722 100644 --- a/src/fe/controllerApp.c +++ b/src/fe/controllerApp.c @@ -512,8 +512,7 @@ void fe_start_controller( void ) clear_fpu_exceptions(); clearFilterHistoryChecks(); feStatus &= ~FE_ERROR_FPU; - pLocalEpics->epicsOutput.ipcMaxWaitHold_ns = 0; - pLocalEpics->epicsOutput.slowIpcInList = 0; + ipc_subsys_diag_reset(pLocalEpics); } pLocalEpics->epicsOutput.diagWord = diagWord; } @@ -704,15 +703,7 @@ void fe_start_controller( void ) // if( cycleNum == HKP_IPC_STATS_UPDATES) { - CDS_IPC_STATS_t stats; - commData3GetStats( &stats ); - pLocalEpics->epicsOutput.ipcNumWaitsInSec = stats.numWaitsInSec; - pLocalEpics->epicsOutput.ipcMaxWait_ns = stats.ipcMaxWait_ns; - if( stats.slowIpcListIndex != 0) - pLocalEpics->epicsOutput.slowIpcInList = stats.slowIpcListIndex; - if( stats.ipcMaxWait_ns > pLocalEpics->epicsOutput.ipcMaxWaitHold_ns) - pLocalEpics->epicsOutput.ipcMaxWaitHold_ns = stats.ipcMaxWait_ns; - + ipc_subsys_1Hz_stats_update( pLocalEpics ); } diff --git a/src/fe/controllerIop.c b/src/fe/controllerIop.c index 13954c386e1564b423b4cf27effb190b01dc345c..57874ea99049f9f3036bcc1222946fd1f64b4595 100644 --- a/src/fe/controllerIop.c +++ b/src/fe/controllerIop.c @@ -1203,8 +1203,7 @@ void fe_start_controller( void ) clearFilterHistoryChecks(); feStatus &= ~FE_ERROR_FPU; dac_write_err_occured = 0; //Clear sticky DAC bit from missed sample - pLocalEpics->epicsOutput.ipcMaxWaitHold_ns = 0; - pLocalEpics->epicsOutput.slowIpcInList = 0; + ipc_subsys_diag_reset(pLocalEpics); } pLocalEpics->epicsOutput.diagWord = diagWord; } @@ -1304,15 +1303,7 @@ void fe_start_controller( void ) // if( hkp_cycle == HKP_IPC_STATS_UPDATES) { - CDS_IPC_STATS_t stats; - commData3GetStats( &stats ); - pLocalEpics->epicsOutput.ipcNumWaitsInSec = stats.numWaitsInSec; - pLocalEpics->epicsOutput.ipcMaxWait_ns = stats.ipcMaxWait_ns; - if( stats.slowIpcListIndex != 0) - pLocalEpics->epicsOutput.slowIpcInList = stats.slowIpcListIndex; - if( stats.ipcMaxWait_ns > pLocalEpics->epicsOutput.ipcMaxWaitHold_ns) - pLocalEpics->epicsOutput.ipcMaxWaitHold_ns = stats.ipcMaxWait_ns; - + ipc_subsys_1Hz_stats_update( pLocalEpics ); } #if !defined( RUN_WO_IO_MODULES ) && !defined( USE_DOLPHIN_TIMING ) diff --git a/src/include/commData3.h b/src/include/commData3.h index 3b9199001b8a05c544819f3ad8ff8ad61f1dc94e..a0b16427d4e325ba81f80f4fa801ccd8d8703300 100644 --- a/src/include/commData3.h +++ b/src/include/commData3.h @@ -20,6 +20,10 @@ #define IPC_BLOCKS 64 #define PCIE_SEG_SIZE 16 +/// If one or more IPC sends take longer that this value a warning +/// will be generated (at 1Hz) +#define IPC_MAX_SEND_TIME_NS 5000 + typedef struct TIMING_SIGNAL { unsigned long gps_time; @@ -77,10 +81,18 @@ typedef struct CDS_IPC_INFO typedef struct CDS_IPC_STATS_t { + //IPC Recv Stats int32_t numWaitsInSec; int32_t ipcMaxWait_ns; int32_t slowIpcListIndex; + //IPC Sending Stats + //int32_t ipcAvgSendTime_ns; + LIGO_DUR_t ipcTotalSendTime_ns; //Total time to send ipcs, for all cycles in second + int32_t ipcMaxSendTime_ns; + + + } CDS_IPC_STATS_t; /// Indicates data is to be sent @@ -109,6 +121,8 @@ typedef struct CDS_IPC_STATS_t extern "C" { #endif +typedef struct CDS_EPICS CDS_EPICS; + void commData3Init(int connects, int model_rate, int send_rate, CDS_IPC_INFO ipcInfo[] ); void commData3GetIpcNums(int totalIPCs, CDS_IPC_INFO ipcInfo[], int * numSenders, int * numReceiver); void commData3Send(int connects, CDS_IPC_INFO ipcInfo[], int timeSec, int cycle); @@ -119,6 +133,9 @@ void commData3SetCycleStartTime(LIGO_DUR_t cycle_start_tsc); int commData3GetInitStatus( void ); void commData3GetStats( CDS_IPC_STATS_t * stats_ptr); +void ipc_subsys_1Hz_stats_update( volatile CDS_EPICS* epics_ptr ); +void ipc_subsys_diag_reset( volatile CDS_EPICS* epics_ptr ); + #ifdef __cplusplus }