src/myrlog.cpp

Go to the documentation of this file.
00001 //
00002 // C++ Implementation: myrlog
00003 //
00004 // Description:
00005 //
00006 //
00007 // Author: Roman Geus <geus@maxwell>, (C) 2004
00008 //
00009 // Copyright: See COPYING file that comes with this distribution
00010 //
00011 //
00012 
00013 #include <unistd.h>
00014 #if defined(__QK_USER__)
00015 #    include <catamount/catmalloc.h>
00016 #    include <catamount/data.h>
00017 #    include <papi.h>
00018 #endif
00019 #include <sys/times.h>
00020 #include <time.h>
00021 #include <fstream>
00022 #include <iterator>
00023 #include <sstream>
00024 #include "Epetra_Comm.h"
00025 #include "Epetra_Map.h"
00026 #include "Epetra_CrsMatrix.h"
00027 #include "rlog/RLogChannel.h"
00028 #include "myrlog.h"
00029 
00030 using namespace std;
00031 using namespace rlog;
00032 
00033 namespace rlog {
00034 
00035 std::string bytes2str(unsigned long long size) {
00036     char suffix;
00037     if (size < 10000)
00038         suffix = 'b';
00039     else {
00040         size /= 1024;
00041         if (size < 10000)
00042             suffix = 'k';
00043         else {
00044             size /= 1024;
00045             suffix = 'm';
00046         }
00047     }
00048     std::ostringstream buf;
00049     buf << size << suffix;
00050     return buf.str();
00051 }
00052 
00053 MyStdioNode::MyStdioNode(string prefix, int _fdOut)
00054     : StdioNode(_fdOut, true), prefix_(prefix)
00055 {
00056     // override: always use color
00057     colorize = true;
00058 }
00059 
00060 MyStdioNode::~MyStdioNode()
00061 {
00062 }
00063 
00064 void
00065 MyStdioNode::publish( const RLogData &data )
00066 {
00067     const char kNormalColor[] = "\033[0m";
00068     const char kRedColor[]    = "\033[31m";
00069     const char kGreenColor[]  = "\033[32m";
00070     const char kYellowColor[] = "\033[33m";    
00071 //    const char kBlueColor[] = "\033[34m";
00072 //    const char kPurpleColor[] = "\033[35m";    
00073     const char kMagentaColor[] = "\033[36m";    
00074     char timeStamp[32];
00075     time_t errTime = data.time;
00076     tm currentTime;
00077 
00078 #ifdef HAVE_LOCALTIME_R
00079     localtime_r( &errTime, &currentTime );
00080 #else
00081     currentTime = *localtime( &errTime );
00082 #endif
00083 
00084     const char *color = NULL;
00085     if(colorize)
00086     {
00087         sprintf(timeStamp, "%s%02i:%02i:%02i%s %s%s ",
00088                 kGreenColor,
00089                 currentTime.tm_hour,
00090                 currentTime.tm_min,
00091                 currentTime.tm_sec,
00092                 kMagentaColor,
00093                 prefix_.c_str(),
00094                 kNormalColor);
00095 
00096         string channel = data.publisher->channel->name();
00097         LogLevel level = data.publisher->channel->logLevel();
00098 
00099         switch(level)
00100         {
00101         case Log_Critical:
00102         case Log_Error:
00103             color = kRedColor;
00104             break;
00105         case Log_Warning:
00106             color = kYellowColor;
00107             break;
00108         case Log_Notice:
00109         case Log_Info:
00110         case Log_Debug:
00111         case Log_Undef:
00112             break;
00113         }
00114     } else
00115     {
00116         sprintf(timeStamp, "%02i:%02i:%02i %s ",
00117                 currentTime.tm_hour,
00118                 currentTime.tm_min,
00119                 currentTime.tm_sec,
00120                 prefix_.c_str());
00121     }
00122 
00123     ostringstream ss;
00124 
00125     ss << timeStamp;
00126     //ss << '[' << data.publisher->channel->name << "] ";
00127     //ss << "(" << data.publisher->fileName << ':'
00128     //    << data.publisher->lineNum << ") ";
00129 
00130     if(color)
00131         ss << color;
00132 
00133     ss << data.msg;
00134 
00135     if(color)
00136         ss << kNormalColor;
00137 
00138     ss << '\n';
00139 
00140     string out = ss.str();
00141     write( fdOut, out.c_str(), out.length() );
00142 }
00143 
00144 } // namespace rlog
00145 
00151 string get_log_file_name(string prefix) {
00152     char buf_time[128];
00153     char buf_pid[128];
00154 
00155     // get local time
00156     time_t tim = time(NULL);
00157 
00158     // convert to tm structure
00159     struct tm* ts = localtime(&tim);
00160 
00161     // format time
00162     int info = strftime(buf_time, sizeof(buf_time), "%Y%m%d-%H%M%S", ts);
00163     rAssert(info > 0);
00164 
00165     // format id
00166     unsigned int pid;
00167 #if defined(__QK_USER__)
00168     pid = _my_yod_cmd_pid;
00169 #else
00170     pid = getpid();
00171 #endif
00172     info = snprintf(buf_pid, sizeof(buf_pid), "-%d", pid);
00173     rAssert(0 <= info && info < static_cast<int>(sizeof(buf_pid)));
00174 
00175     // return file name
00176     return prefix + buf_time + buf_pid + ".log";
00177 }
00178 
00179 #if defined(__QK_USER__)
00180 
00181 size_t get_mem_footprint() {
00182   size_t fragments;
00183   unsigned long total_free;
00184   unsigned long largest_free;
00185   unsigned long total_used;
00186 
00187   int info =  heap_info(&fragments,
00188                         &total_free,
00189                         &largest_free,
00190                         &total_used);
00191   assert(info == 0);
00192   return total_used;
00193 }
00194 
00195 #else
00196 
00197 #  if defined(USE_SBRK)
00198 
00199 size_t get_mem_footprint() {
00200     // extract memory footprint sbrk
00201     static size_t base = 0;
00202     size_t p = reinterpret_cast<size_t>(sbrk(0));
00203     // if called for the 1st time, set base
00204     if (base == 0)
00205         base = p;
00206     return p - base;
00207 }
00208 // call function to make sure base gets initialised
00209 namespace {
00210     size_t dummy = get_mem_footprint();
00211 }
00212 
00213 #  else
00214 
00215 size_t get_mem_footprint() {
00216     // extract memory footprint from /proc/$PID/status
00217     pid_t pid = getpid();
00218     ostringstream buf;
00219     buf << "/proc/" << pid << "/status";
00220     ifstream istr(buf.str().c_str());
00221     istream_iterator<string> ifile(istr);
00222     istream_iterator<string> eos;
00223     for (; ifile != eos && *ifile != "VmSize:"; ++ ifile)
00224         ;
00225     rAssert(ifile != eos);
00226     ++ ifile;
00227     istringstream buf2(*ifile);
00228     ++ ifile;
00229     rAssert(*ifile == "kB");
00230     size_t size;
00231     buf2 >> size;
00232     return 1024 * size;
00233 }
00234 
00235 #  endif
00236 
00237 #endif
00238 
00239 void log_mem_footprint(const Epetra_Comm& comm, string msg) {
00240     size_t local_size = get_mem_footprint();
00241     double local_size_d = static_cast<double>(local_size);
00242     double sum_size_d, max_size_d, min_size_d;
00243     comm.SumAll(&local_size_d, &sum_size_d, 1);
00244     comm.MaxAll(&local_size_d, &max_size_d, 1);
00245     comm.MinAll(&local_size_d, &min_size_d, 1);
00246     if (msg != "")
00247         msg = " (" + msg + ")";
00248     rDebug("Memory footprint%s: sum=%s, min=%s, max=%s",
00249            msg.c_str(),
00250            rlog::bytes2str(static_cast<unsigned long long>(sum_size_d)).c_str(),
00251            rlog::bytes2str(static_cast<unsigned long long>(min_size_d)).c_str(),
00252            rlog::bytes2str(static_cast<unsigned long long>(max_size_d)).c_str());
00253 }
00254 
00255 void log_command_line_args(int argc, char* argv[], rlog::RLogChannel* channel) {
00256     if (channel == 0)
00257         channel = RLOG_CHANNEL("debug");
00258 
00259     ostringstream buf;
00260     buf << argv[0] << " started with arguments";
00261     for (int i = 1; i < argc; ++ i) {
00262         buf << " \"" << argv[i] << "\"";
00263     }
00264     rLog(channel, "%s", buf.str().c_str());
00265 }
00266 
00267 size_t get_matrix_mem_footprint(const Epetra_CrsMatrix& A) {
00268     /* Memory consumption calculated according to mail by Mike Heroux:
00269 
00270        N=Global dimension
00271        NNZ=Global Nonzero count
00272        Nghost=Total number of redundant values needed for parallel execution
00273        Nrhs=Number of RHS.
00274 
00275        4*(N+NNZ)    - Array of pointer for Column Indices and NNZ total integer space.
00276 
00277        4*(2*N)      - Two integer arrays to manage insertion of matrix entries.
00278 
00279        4*(N+2*NNZ)  - Array of pointers for values and NNZ total doubles.
00280 
00281        4*N          - RowMap
00282        4*(N+Nghost) - ColMap
00283 
00284        8**Nrhs*(N+Nghost) - Import MultiVector (zero if on a single processor).
00285     */
00286     size_t local_size = 0;
00287     // col and val
00288     local_size += A.NumMyNonzeros() * (sizeof(int) + sizeof(double));
00289     // ptrs to indices in row and nof_per_row and alloc_per_row
00290     local_size += A.NumMyRows() * (sizeof(int*) + 2*sizeof(int));
00291     // ptrs to values in row
00292     local_size += A.NumMyRows() * sizeof(double*);
00293     // row map
00294     local_size += A.NumMyRows() * sizeof(int);
00295     // col map
00296     local_size += A.NumMyCols() * sizeof(int);
00297     // import vectors (assume nrhs == 1)
00298     if (A.Comm().NumProc() > 1)
00299         local_size += A.NumMyCols() * sizeof(double);
00300     return local_size;
00301 }
00302 
00311 static void get_local_nnz(const Epetra_CrsMatrix& A, int* nnz_diag, int* nnz_offdiag) {
00312     *nnz_diag = 0;
00313     *nnz_offdiag = 0;
00314     for (int i_row = 0; i_row < A.NumMyRows(); ++ i_row) {
00315         int num_entries;
00316         double* val;
00317         int* col;
00318         A.ExtractMyRowView(i_row, num_entries, val, col);        
00319         for (int k = 0; k < num_entries; ++ k) {
00320             if (A.DomainMap().MyGID(A.ColMap().GID(col[k]))) {
00321                 *nnz_diag += 1;
00322             } else {
00323                 *nnz_offdiag += 1;
00324             }
00325         }
00326     }
00327 }
00328 
00329 void log_matrix_stats(string matrix_name, const Epetra_CrsMatrix* A) {
00330     size_t local_size = get_matrix_mem_footprint(*A);
00331     double local_size_d = static_cast<double>(local_size);
00332     double sum_size_d, max_size_d;
00333     A->Comm().SumAll(&local_size_d, &sum_size_d, 1);
00334     A->Comm().MaxAll(&local_size_d, &max_size_d, 1);
00335     int nnz, local_nnz_diag, local_nnz_offdiag;
00336     nnz = A->NumGlobalNonzeros();
00337     get_local_nnz(*A, &local_nnz_diag, &local_nnz_offdiag);
00338     double local_nnz_diag_d = static_cast<double>(local_nnz_diag);
00339     double sum_nnz_diag_d;
00340     A->Comm().SumAll(&local_nnz_diag_d, &sum_nnz_diag_d, 1);
00341     rInfo("%s: nrows=%d, ncols=%d, nnz=%d, p_nnz_diag=%.1f%%, mem(sum)=%s, mem(max)=%s",
00342           matrix_name.c_str(),
00343           A->NumGlobalRows(),
00344           A->NumGlobalCols(),
00345           nnz,
00346           nnz == 0 ? 0.0 : 100.0*sum_nnz_diag_d/static_cast<double>(nnz),
00347           rlog::bytes2str(static_cast<unsigned long long>(sum_size_d)).c_str(),
00348           rlog::bytes2str(static_cast<unsigned long long>(max_size_d)).c_str());
00349 }
00350 
00351 #if defined(__QK_USER__)
00352 
00356 clock_t times(struct tms *buf) {
00357     float rt, pt, ipc;
00358     long_long ins;
00359     int info;
00360 
00361     info = PAPI_ipc(&rt, &pt, &ins, &ipc);
00362     if (info != PAPI_OK)
00363         return -1;
00364 
00365     // Set user time to PAPI process time
00366     buf->tms_utime = (clock_t)(unsigned long long)(pt * CLK_TCK);
00367     // Set system time and child times to zero
00368     buf->tms_stime = 0;
00369     buf->tms_cutime = 0;
00370     buf->tms_cstime = 0;
00371 
00372     // Return wallclock time (overflow may happen here!)
00373     return (clock_t)(unsigned long long)(rt * CLK_TCK);
00374 }
00375 
00376 #endif

Generated on Fri Oct 26 13:35:12 2007 for FEMAXX (Finite Element Maxwell Eigensolver) by  doxygen 1.4.7