# HG changeset patch # User Nina Engelhardt # Date 1312298172 -7200 # Node ID 659299627e70087ef065f6c0728dcd6f9cb8d645 # Parent 3bc3b89630c79e72fb5feb7286e6eb652f585780 counters done diff -r 3bc3b89630c7 -r 659299627e70 CoreLoop.c --- a/CoreLoop.c Tue Jul 26 15:36:24 2011 +0200 +++ b/CoreLoop.c Tue Aug 02 17:16:12 2011 +0200 @@ -35,7 +35,7 @@ { ThdParams *coreLoopThdParams; int thisCoresIdx; - VirtProcr *currPr; + VirtProcr *currPr = NULL; VMSQueueStruc *readyToAnimateQ; cpu_set_t coreMask; //has 1 in bit positions of allowed cores int errorCode; @@ -84,7 +84,17 @@ while(1){ - + #ifdef MEAS__PERF_COUNTERS + //end work + + if(currPr!=NULL){ + int lastRecordIdx = currPr->counter_history_array_info->numInArray -1; + CounterRecord* lastRecord = currPr->counter_history[lastRecordIdx]; + //lastRecord->work_core = thisCoresIdx; + saveCyclesAndInstrs(thisCoresIdx,lastRecord->suspend_cycles,lastRecord->suspend_instrs); + } + + #endif //Get virtual processor from queue //The Q must be a global, static volatile var, so not kept in reg, // which forces reloading the pointer after each jmp to this point @@ -151,38 +161,15 @@ } - #ifdef MEAS__PERF_COUNTER + #ifdef MEAS__PERF_COUNTERS //start work int lastRecordIdx = currPr->counter_history_array_info->numInArray -1; CounterRecord* lastRecord = currPr->counter_history[lastRecordIdx]; - lastRecord->work_core = thisCoresIdx; - int cycles_fd = _VMSMasterEnv->cycles_counter_fd[thisCoresIdx]; - int instrs_fd = _VMSMasterEnv->instrs_counter_fd[thisCoresIdx]; - int nread; - - nread = read(cycles_fd,&(lastRecord->start_work_cycles),sizeof(lastRecord->start_work_cycles)); - if(nread<0){ - lastRecord->start_work_cycles = 0; - } - - nread = read(instrs_fd,&(lastRecord->start_work_instrs),sizeof(lastRecord->start_work_instrs)); - if(nread<0){ - lastRecord->start_work_instrs = 0; - } + lastRecord->work_core = thisCoresIdx; + saveCyclesAndInstrs(thisCoresIdx,lastRecord->start_work_cycles,lastRecord->start_work_instrs); #endif switchToVP(currPr); //The VPs return in here - #ifdef MEAS__PERF_COUNTER - //end work - nread = read(cycles_fd,&(lastRecord->start_work_cycles),sizeof(lastRecord->start_work_cycles)); - if(nread<0){ - lastRecord->start_work_cycles = 0; - } - nread = read(instrs_fd,&(lastRecord->start_work_instrs),sizeof(lastRecord->start_work_instrs)); - if(nread<0){ - lastRecord->start_work_instrs = 0; - } - #endif flushRegisters(); }//CoreLoop } diff -r 3bc3b89630c7 -r 659299627e70 Counters/Counters.c --- a/Counters/Counters.c Tue Jul 26 15:36:24 2011 +0200 +++ b/Counters/Counters.c Tue Aug 02 17:16:12 2011 +0200 @@ -2,13 +2,13 @@ void print_record(CounterRecord* record){ - printf("=== Loop Stats: ==="); - printf("Constraints check done:\t%ld cycles, %ld instrs [Core %d]\n",record->sc_done_cycles,record->sc_done_instrs,record->req_core); - printf("Ready Queue entered at:\t%ld cycles, %ld instrs [Core %d]\n",record->enter_readyQ_cycles,record->enter_readyQ_instrs,record->req_core); - printf("Assigner started:\t%ld cycles, %ld instrs [Core %d]\n",record->start_assign_cycles,record->start_assign_instrs,record->assigning_core); - printf("Assigner ended:\t%ld cycles, %ld instrs [Core %d]\n",record->end_assign_cycles,record->end_assign_instrs,record->assigning_core); - printf("Work+comm started:\t%ld cycles, %ld instrs [Core %d]\n",record->start_work_cycles,record->start_work_instrs,record->work_core); - printf("Work+comm ended:\t%ld cycles, %ld instrs [Core %d]\n",record->suspend_cycles,record->suspend_instrs,record->work_core); - printf("Request read:\t%ld cycles, %ld instrs [Core %d]\n",record->req_cycles,record->req_instrs,record->req_core); + printf("=== Loop Stats (VP %d): ===\n",record->vp_id); + printf("Constraints check done:\t%lu cycles, %lu instrs [Core %d]\n",record->sc_done_cycles,record->sc_done_instrs,record->req_core); + printf("Time in ready queue:\tblocked at %u, unblocked at %u\n",record->blocked_timestamp,record->unblocked_timestamp); + printf("Assigner started:\t%lu cycles, %lu instrs [Core %d]\n",record->start_assign_cycles,record->start_assign_instrs,record->assigning_core); + printf("Assigner ended: \t%lu cycles, %lu instrs [Core %d]\n",record->end_assign_cycles,record->end_assign_instrs,record->assigning_core); + printf("Work+comm started:\t%lu cycles, %lu instrs [Core %d]\n",record->start_work_cycles,record->start_work_instrs,record->work_core); + printf("Work+comm ended:\t%lu cycles, %lu instrs [Core %d]\n",record->suspend_cycles,record->suspend_instrs,record->work_core); + printf("Status request read:\t%lu cycles, %lu instrs [Core %d]\n",record->req_cycles,record->req_instrs,record->req_core); } diff -r 3bc3b89630c7 -r 659299627e70 Counters/Counters.h --- a/Counters/Counters.h Tue Jul 26 15:36:24 2011 +0200 +++ b/Counters/Counters.h Tue Aug 02 17:16:12 2011 +0200 @@ -15,12 +15,15 @@ int work_core; int assigning_core; int req_core; + int vp_id; + uint32 blocked_timestamp; + uint32 unblocked_timestamp; uint64 req_cycles; uint64 req_instrs; uint64 sc_done_cycles; uint64 sc_done_instrs; - uint64 enter_readyQ_cycles; - uint64 enter_readyQ_instrs; +// uint64 enter_readyQ_cycles; +// uint64 enter_readyQ_instrs; uint64 start_assign_cycles; uint64 start_assign_instrs; uint64 end_assign_cycles; diff -r 3bc3b89630c7 -r 659299627e70 MasterLoop.c --- a/MasterLoop.c Tue Jul 26 15:36:24 2011 +0200 +++ b/MasterLoop.c Tue Aug 02 17:16:12 2011 +0200 @@ -147,29 +147,18 @@ int32 startStamp1, endStamp1; saveLowTimeStampCountInto( startStamp1 ); #endif - #ifdef MEAS__PERF_COUNTER + #ifdef MEAS__PERF_COUNTERS int lastRecordIdx = currSlot->procrAssignedToSlot->counter_history_array_info->numInArray -1; CounterRecord* lastRecord = currSlot->procrAssignedToSlot->counter_history[lastRecordIdx]; lastRecord->req_core = thisCoresIdx; - int cycles_fd = masterEnv->cycles_counter_fd[thisCoresIdx]; - int instrs_fd = masterEnv->instrs_counter_fd[thisCoresIdx]; - int nread; - - nread = read(cycles_fd,&(lastRecord->req_cycles),sizeof(lastRecord->req_cycles)); - if(nread<0){ - lastRecord->req_cycles = 0; - } - - nread = read(instrs_fd,&(lastRecord->req_instrs),sizeof(lastRecord->req_instrs)); - if(nread<0){ - lastRecord->req_instrs = 0; - } + saveCyclesAndInstrs(thisCoresIdx,lastRecord->req_cycles,lastRecord->req_instrs); //End of task, start of next task //print counters from last run print_record(lastRecord); - //create new entry in record array here + //create new entry in record array CounterRecord* newRecord = VMS__malloc(sizeof(CounterRecord)); newRecord->req_core = thisCoresIdx; + newRecord->vp_id = currSlot->procrAssignedToSlot->procrID; addToDynArray( (void*) newRecord, currSlot->procrAssignedToSlot->counter_history_array_info); lastRecord = newRecord; #endif @@ -183,65 +172,38 @@ addIntervalToHist( startStamp1, endStamp1, _VMSMasterEnv->reqHdlrHighTimeHist ); #endif - #ifdef MEAS__PERF_COUNTER - - nread = read(cycles_fd,&(lastRecord->sc_done_cycles),sizeof(lastRecord->sc_done_cycles)); - if(nread<0){ - lastRecord->sc_done_cycles = 0; - } - nread = read(instrs_fd,&(lastRecord->sc_done_instrs),sizeof(lastRecord->sc_done_instrs)); - if(nread<0){ - lastRecord->sc_done_instrs = 0; - } + #ifdef MEAS__PERF_COUNTERS + //done with constraints check + saveCyclesAndInstrs(thisCoresIdx,lastRecord->sc_done_cycles,lastRecord->sc_done_instrs); + saveLowTimeStampCountInto(lastRecord->blocked_timestamp); #endif //============================================================ } if( currSlot->needsProcrAssigned ) { //give slot a new virt procr - #ifdef MEAS__PERF_COUNTER + #ifdef MEAS__PERF_COUNTERS //start assigner - int cycles_fd = masterEnv->cycles_counter_fd[thisCoresIdx]; - int instrs_fd = masterEnv->instrs_counter_fd[thisCoresIdx]; uint64 tmp_cycles; uint64 tmp_instrs; - int nread=0; - - nread = read(cycles_fd,&tmp_cycles,sizeof(uint64)); - if(nread<0){ - tmp_cycles = 0; - } - - nread = read(instrs_fd,&tmp_instrs,sizeof(uint64)); - if(nread<0){ - tmp_instrs = 0; - } + saveCyclesAndInstrs(thisCoresIdx,tmp_cycles,tmp_instrs); #endif schedVirtPr = (*slaveScheduler)( semanticEnv, thisCoresIdx ); - #ifdef MEAS__PERF_COUNTER + + if( schedVirtPr != NULL ) + { currSlot->procrAssignedToSlot = schedVirtPr; + schedVirtPr->schedSlot = currSlot; + currSlot->needsProcrAssigned = FALSE; + numSlotsFilled += 1; + #ifdef MEAS__PERF_COUNTERS //end assigner int lastRecordIdx = currSlot->procrAssignedToSlot->counter_history_array_info->numInArray -1; CounterRecord* lastRecord = currSlot->procrAssignedToSlot->counter_history[lastRecordIdx]; lastRecord->assigning_core = thisCoresIdx; lastRecord->start_assign_cycles = tmp_cycles; lastRecord->start_assign_instrs = tmp_instrs; - - nread = read(cycles_fd,&(lastRecord->end_assign_cycles),sizeof(lastRecord->end_assign_cycles)); - if(nread<0){ - lastRecord->end_assign_cycles = 0; - } - - nread = read(instrs_fd,&(lastRecord->end_assign_instrs),sizeof(lastRecord->end_assign_instrs)); - if(nread<0){ - lastRecord->end_assign_instrs = 0; - } + saveCyclesAndInstrs(thisCoresIdx,lastRecord->end_assign_cycles,lastRecord->end_assign_instrs); #endif - if( schedVirtPr != NULL ) - { currSlot->procrAssignedToSlot = schedVirtPr; - schedVirtPr->schedSlot = currSlot; - currSlot->needsProcrAssigned = FALSE; - numSlotsFilled += 1; - writeVMSQ( schedVirtPr, readyToAnimateQ ); } } diff -r 3bc3b89630c7 -r 659299627e70 ProcrContext.c --- a/ProcrContext.c Tue Jul 26 15:36:24 2011 +0200 +++ b/ProcrContext.c Tue Aug 02 17:16:12 2011 +0200 @@ -59,7 +59,12 @@ //newPr->createPtInSecs = timeStamp.tv_sec +(timeStamp.tv_usec/1000000.0) - // _VMSMasterEnv->createPtInSecs; #endif - + #ifdef MEAS__PERF_COUNTERS + newPr->counter_history = VMS__malloc(10*sizeof(void*)); + newPr->counter_history_array_info = makePrivDynArrayInfoFrom(&(newPr->counter_history),10); + CounterRecord* newRecord = VMS__malloc(sizeof(CounterRecord)); + addToDynArray( (void*) newRecord, newPr->counter_history_array_info); + #endif //======================================================================== return newPr; diff -r 3bc3b89630c7 -r 659299627e70 VMS.c --- a/VMS.c Tue Jul 26 15:36:24 2011 +0200 +++ b/VMS.c Tue Aug 02 17:16:12 2011 +0200 @@ -16,9 +16,14 @@ #include "Queue_impl/BlockingQueue.h" #include "Histogram/Histogram.h" +#include +#include +#include #include -#include -#include +#include +#include +#include + #define thdAttrs NULL @@ -181,12 +186,14 @@ MakeTheMeasHists(); - #ifdef MEAS__PERF_COUNTER + #ifdef MEAS__PERF_COUNTERS printf("Creating HW counters..."); struct perf_event_attr hw_event; + memset(&hw_event,0,sizeof(hw_event)); hw_event.type = PERF_TYPE_HARDWARE; - hw_event.size = sizeof(struct perf_event_attr); + hw_event.size = sizeof(hw_event); hw_event.disabled = 1; + hw_event.freq = 0; hw_event.inherit = 1; /* children inherit it */ hw_event.pinned = 1; /* must always be on PMU */ hw_event.exclusive = 0; /* only group on PMU */ @@ -197,24 +204,36 @@ hw_event.mmap = 0; /* include mmap data */ hw_event.comm = 0; /* include comm data */ + for( coreIdx = 0; coreIdx < NUM_CORES; coreIdx++ ) { - hw_event.config = PERF_COUNT_HW_CPU_CYCLES; //cycles + hw_event.config = 0x0000000000000000; //cycles _VMSMasterEnv->cycles_counter_fd[coreIdx] = syscall(__NR_perf_event_open, &hw_event, 0,//pid_t pid, - coreIdx,//int cpu, + -1,//int cpu, -1,//int group_fd, 0//unsigned long flags ); - hw_event.config = PERF_COUNT_HW_INSTRUCTIONS; //instrs + if (_VMSMasterEnv->cycles_counter_fd[coreIdx]<0){ + fprintf(stderr,"On core %d: ",coreIdx); + perror("Failed to open cycles counter"); + } + hw_event.config = 0x0000000000000001; //instrs _VMSMasterEnv->instrs_counter_fd[coreIdx] = syscall(__NR_perf_event_open, &hw_event, 0,//pid_t pid, - coreIdx,//int cpu, + -1,//int cpu, -1,//int group_fd, 0//unsigned long flags ); + if (_VMSMasterEnv->instrs_counter_fd[coreIdx]<0){ + fprintf(stderr,"On core %d: ",coreIdx); + perror("Failed to open instrs counter"); + } } prctl(PR_TASK_PERF_EVENTS_ENABLE); + uint64 tmpc,tmpi; + saveCyclesAndInstrs(0,tmpc,tmpi); + printf("Start: cycles = %lu, instrs = %lu\n",tmpc,tmpi); #endif //======================================================================== @@ -419,7 +438,8 @@ * to the plugin. */ void -VMS__send_create_procr_req( void *semReqData, VirtProcr *reqstingPr ) +VMS__send_create_procr_req( void *semReqData, VirtProcr *reqstingPr ) __attribute__ ((noinline)) + { VMSReqst req; req.reqType = createReq; @@ -453,7 +473,7 @@ * pears -- making that suspend the last thing in the virt procr's trace. */ void -VMS__send_dissipate_req( VirtProcr *procrToDissipate ) +VMS__send_dissipate_req( VirtProcr *procrToDissipate ) __attribute__ ((noinline)) { VMSReqst req; req.reqType = dissipate; @@ -512,8 +532,8 @@ * to plugin *Then it does suspend, to cause request to be sent. */ -inline void -VMS__send_sem_request( void *semReqData, VirtProcr *callingPr ) +/*inline*/ void +VMS__send_sem_request( void *semReqData, VirtProcr *callingPr ) __attribute__ ((noinline)) { VMSReqst req; req.reqType = semantic; @@ -525,8 +545,9 @@ } -inline void -VMS__send_VMSSem_request( void *semReqData, VirtProcr *callingPr ) +/*inline*/ void +VMS__send_VMSSem_request( void *semReqData, VirtProcr *callingPr ) __attribute__ ((noinline)) + { VMSReqst req; req.reqType = VMSSemantic; @@ -678,7 +699,18 @@ shutDownPr = VMS__create_procr( &endOSThreadFn, NULL ); writeVMSQ( shutDownPr, _VMSMasterEnv->readyToAnimateQs[coreIdx] ); } - +#ifdef MEAS__PERF_COUNTERS + uint64 tmpc,tmpi; + saveCyclesAndInstrs(0,tmpc,tmpi); + printf("End: cycles = %lu, instrs = %lu\n",tmpc,tmpi); + prctl(PR_TASK_PERF_EVENTS_DISABLE); +/* + for( coreIdx=0; coreIdx < NUM_CORES; coreIdx++ ){ + close(_VMSMasterEnv->cycles_counter_fd[coreIdx]); + close(_VMSMasterEnv->instrs_counter_fd[coreIdx]); + } +*/ +#endif } @@ -718,8 +750,8 @@ //SchedSlot ***allSchedSlots; //ptr to array of ptrs //Before getting rid of everything, print out any measurements made - forAllInDynArrayDo( _VMSMasterEnv->measHistsInfo, (DynArrayFnPtr)&printHist ); - forAllInDynArrayDo( _VMSMasterEnv->measHistsInfo, (DynArrayFnPtr)&saveHistToFile); + //forAllInDynArrayDo( _VMSMasterEnv->measHistsInfo, (DynArrayFnPtr)&printHist ); + //forAllInDynArrayDo( _VMSMasterEnv->measHistsInfo, (DynArrayFnPtr)&saveHistToFile); //forAllInDynArrayDo( _VMSMasterEnv->measHistsInfo, &freeHistExt ); #ifdef MEAS__TIME_PLUGIN printHist( _VMSMasterEnv->reqHdlrLowTimeHist ); diff -r 3bc3b89630c7 -r 659299627e70 VMS.h --- a/VMS.h Tue Jul 26 15:36:24 2011 +0200 +++ b/VMS.h Tue Aug 02 17:16:12 2011 +0200 @@ -45,11 +45,11 @@ //Comment or un- the substitute half to turn on/off types of debug message #define DEBUG( bool, msg) \ -// if( bool){ printf(msg); fflush(stdin);} + if( bool){ printf(msg); fflush(stdin);} #define DEBUG1( bool, msg, param) \ -// if(bool){printf(msg, param); fflush(stdin);} + if(bool){printf(msg, param); fflush(stdin);} #define DEBUG2( bool, msg, p1, p2) \ -// if(bool) {printf(msg, p1, p2); fflush(stdin);} + if(bool) {printf(msg, p1, p2); fflush(stdin);} #define ERROR(msg) printf(msg); #define ERROR1(msg, param) printf(msg, param); @@ -64,14 +64,14 @@ // rollover of low portion into high portion. //#define MEAS__TIME_STAMP_SUSP //#define MEAS__TIME_MASTER -#define MEAS__TIME_PLUGIN -#define MEAS__TIME_MALLOC +//#define MEAS__TIME_PLUGIN +//#define MEAS__TIME_MALLOC //#define MEAS__TIME_MASTER_LOCK -#define MEAS__NUM_TIMES_TO_RUN 100000 +//#define MEAS__NUM_TIMES_TO_RUN 100000 //For code that calculates normalization-offset between TSC counts of // different cores. -#define NUM_TSC_ROUND_TRIPS 10 +//#define NUM_TSC_ROUND_TRIPS 10 #define MEAS__PERF_COUNTERS @@ -415,6 +415,24 @@ _VMSMasterEnv->measHists[idx] = \ makeFixedBinHist( numBins, startVal, binWidth, name ); +#define saveCyclesAndInstrs(core,cycles,instrs) do{ \ + int cycles_fd = _VMSMasterEnv->cycles_counter_fd[core]; \ + int instrs_fd = _VMSMasterEnv->instrs_counter_fd[core]; \ + int nread; \ + \ + nread = read(cycles_fd,&(cycles),sizeof(cycles)); \ + if(nread<0){ \ + perror("Error reading cycles counter"); \ + cycles = 0; \ + } \ + \ + nread = read(instrs_fd,&(instrs),sizeof(instrs)); \ + if(nread<0){ \ + perror("Error reading cycles counter"); \ + instrs = 0; \ + } \ +} while (0) + #define MEAS__SUB_CREATE /*turn on/off subtraction of create from plugin*/