bes  Updated for version 3.17.0
BESStopWatch.cc
1 // BESStopWatch.cc
2 
3 // This file is part of bes, A C++ back-end server implementation framework
4 // for the OPeNDAP Data Access Protocol.
5 
6 // Copyright (c) 2004-2009 University Corporation for Atmospheric Research
7 // Author: Patrick West <pwest@ucar.edu> and Jose Garcia <jgarcia@ucar.edu>
8 //
9 // This library is free software; you can redistribute it and/or
10 // modify it under the terms of the GNU Lesser General Public
11 // License as published by the Free Software Foundation; either
12 // version 2.1 of the License, or (at your option) any later version.
13 //
14 // This library is distributed in the hope that it will be useful,
15 // but WITHOUT ANY WARRANTY; without even the implied warranty of
16 // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
17 // Lesser General Public License for more details.
18 //
19 // You should have received a copy of the GNU Lesser General Public
20 // License along with this library; if not, write to the Free Software
21 // Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
22 //
23 // You can contact University Corporation for Atmospheric Research at
24 // 3080 Center Green Drive, Boulder, CO 80301
25 
26 // (c) COPYRIGHT University Corporation for Atmospheric Research 2004-2005
27 // Please read the full copyright statement in the file COPYRIGHT_UCAR.
28 //
29 // Authors:
30 // ndp Nathan Potter <ndp@opendap.org>
31 // pwest Patrick West <pwest@ucar.edu>
32 // jgarcia Jose Garcia <jgarcia@ucar.edu>
33 
34 #include <cerrno>
35 #include <string>
36 #include <iostream>
37 #include <cstring>
38 
39 using std::string ;
40 using std::endl ;
41 
42 #include "BESStopWatch.h"
43 #include "BESDebug.h"
44 
45 namespace bes_timing {
46 BESStopWatch *elapsedTimeToReadStart=0;
47 BESStopWatch *elapsedTimeToTransmitStart=0;
48 }
49 
56 bool
57 BESStopWatch::start(string name)
58 {
59  return start(name, MISSING_LOG_PARAM) ;
60 }
61 
70 bool
71 BESStopWatch::start(string name, string reqID)
72 {
73  _timer_name = name;
74  _req_id = reqID;
75  // get timing for current usage
76  if( getrusage( RUSAGE_SELF, &_start_usage ) != 0 )
77  {
78  int myerrno = errno ;
79  char *c_err = strerror( myerrno ) ;
80  string err = "getrusage failed in start: " ;
81  err += (c_err != 0) ? c_err : "unknown error";
82 #if 0
83  if( c_err )
84  {
85  err += c_err ;
86  }
87  else
88  {
89  err += "unknown error" ;
90  }
91 #endif
92  if(BESDebug::GetStrm())
93  *(BESDebug::GetStrm()) << "[" << BESDebug::GetPidStr() << "]["<< _log_name << "][" << _req_id << "][ERROR][" << _timer_name << "][" << err << "]" << endl;
94  _started = false ;
95  }
96  else
97  {
98  _started = true ;
99  struct timeval &start = _start_usage.ru_utime ;
100  double starttime = start.tv_sec*1000.0 + start.tv_usec/1000.0;
101 
102  if(BESDebug::GetStrm())
103  *(BESDebug::GetStrm()) << "[" << BESDebug::GetPidStr() << "]["<< _log_name << "][" << _req_id << "][STARTED][" << starttime << "][ms]["<< _timer_name << "]" << endl;
104  }
105 
106  // either we started the stop watch, or failed to start it. Either way,
107  // no timings are available, so set stopped to false.
108  _stopped = false ;
109 
110 
111  return _started ;
112 }
113 
114 
123 {
124  // if we have started, then stop and update the log.
125  if( _started )
126  {
127  // get timing for current usage
128  if( getrusage( RUSAGE_SELF, &_stop_usage ) != 0 )
129  {
130  int myerrno = errno ;
131  char *c_err = strerror( myerrno ) ;
132  string err = "getrusage failed in stop: " ;
133  err += (c_err != 0) ? c_err : "unknown error";
134 #if 0
135  if( c_err )
136  {
137  err += c_err ;
138  }
139  else
140  {
141  err += "unknown error" ;
142  }
143 #endif
144  if(BESDebug::GetStrm())
145  *(BESDebug::GetStrm()) << "[" << BESDebug::GetPidStr() << "]["<< _log_name << "][" << _req_id << "][ERROR][" << _timer_name << "][" << err << "]" << endl;
146  _started = false ;
147  _stopped = false ;
148  }
149  else
150  {
151  // get the difference between the _start_usage and the
152  // _stop_usage and save the difference.
153  bool success = timeval_subtract() ;
154  if( !success )
155  {
156  if(BESDebug::GetStrm())
157  *(BESDebug::GetStrm()) << "[" << BESDebug::GetPidStr() << "]["<< _log_name << "][" << _req_id << "][ERROR][" << _timer_name << "][Failed to get timing.]" << endl;
158  _started = false ;
159  _stopped = false ;
160  }
161  else
162  {
163  _stopped = true ;
164 
165  struct timeval &stop = _stop_usage.ru_utime ;
166  double stoptime = stop.tv_sec*1000.0 + stop.tv_usec/1000.0;
167  double elapsed = _result.tv_sec*1000.0 + _result.tv_usec/1000.0;
168 
169  if(BESDebug::GetStrm())
170  *(BESDebug::GetStrm()) << "[" << BESDebug::GetPidStr() << "]["<< _log_name << "][" << _req_id << "][STOPPED][" << stoptime << "][ms][" << _timer_name << "][ELAPSED][" << elapsed << "][ms]" << endl;
171 
172  }
173 
174 
175  }
176  }
177 
178 }
179 
180 
181 #if 0
182 bool
183 BESStopWatch::stop()
184 {
185  // if we have started, the we can stop. Otherwise just fall through.
186  if( _started )
187  {
188  // get timer for current usage
189  if( getrusage( RUSAGE_SELF, &_stop_usage ) != 0 )
190  {
191  int myerrno = errno ;
192  char *c_err = strerror( myerrno ) ;
193  string err = "getrusage failed in stop: " ;
194  if( c_err )
195  {
196  err += c_err ;
197  }
198  else
199  {
200  err += "unknown error" ;
201  }
202  BESDEBUG( _log_name, err << endl ) ;
203  _started = false ;
204  _stopped = false ;
205  }
206  else
207  {
208  // get the difference between the _start_usage and the
209  // _stop_usage and save the difference.
210  bool success = timeval_subtract() ;
211  if( !success )
212  {
213  BESDEBUG( _log_name, "failed to get timing" << endl ) ;
214  _started = false ;
215  _stopped = false ;
216  }
217  else
218  {
219  _stopped = true ;
220  }
221  }
222  }
223  else
224  {
225  BESDEBUG( _log_name, "timing not started" << endl ) ;
226  }
227 
228  return _stopped ;
229 }
230 #endif
231 
232 
233 bool
234 BESStopWatch::timeval_subtract()
235 {
236  struct timeval &start = _start_usage.ru_utime ;
237  struct timeval &stop = _stop_usage.ru_utime ;
238 
239  /* Perform the carry for the later subtraction by updating y. */
240  if( stop.tv_usec < start.tv_usec )
241  {
242  int nsec = (start.tv_usec - stop.tv_usec) / 1000000 + 1 ;
243  start.tv_usec -= 1000000 * nsec ;
244  start.tv_sec += nsec ;
245  }
246  if( stop.tv_usec - start.tv_usec > 1000000 )
247  {
248  int nsec = (start.tv_usec - stop.tv_usec) / 1000000 ;
249  start.tv_usec += 1000000 * nsec ;
250  start.tv_sec -= nsec ;
251  }
252 
253  /* Compute the time remaining to wait.
254  tv_usec is certainly positive. */
255  _result.tv_sec = stop.tv_sec - start.tv_sec ;
256  _result.tv_usec = stop.tv_usec - start.tv_usec ;
257 
258  /* Return 1 if result is negative. */
259  return !(stop.tv_sec < start.tv_sec) ;
260 }
261 
268 void
269 BESStopWatch::dump( ostream &strm ) const
270 {
271  strm << BESIndent::LMarg << "BESStopWatch::dump - ("
272  << (void *)this << ")" << endl ;
273 }
274 
275 
276 
277 
278 
virtual ~BESStopWatch()
static string GetPidStr()
return the pid as a string
Definition: BESDebug.cc:139
virtual bool start(string name)
Definition: BESStopWatch.cc:57
static ostream * GetStrm()
return the debug stream
Definition: BESDebug.h:186
virtual void dump(ostream &strm) const
dumps information about this object