to give a warning in the log if a message takes too long to process

This commit is contained in:
Redmond Urbino 2010-05-07 05:29:59 +00:00
parent 8c56527a49
commit 0b344e9a2b
3 changed files with 57 additions and 2 deletions

View File

@ -406,3 +406,25 @@ INLINE bool CConnectionRepository::
get_verbose() const { get_verbose() const {
return _verbose; return _verbose;
} }
////////////////////////////////////////////////////////////////////
// Function: CConnectionRepository::set_time_warning
// Access: Published
// Description: Directly sets the time_warning field. When non zero, this
// describes every message going back and forth on the
// wire when the msg handling time is over it
////////////////////////////////////////////////////////////////////
INLINE void CConnectionRepository::
set_time_warning(float time_warning) {
_time_warning = time_warning;
}
////////////////////////////////////////////////////////////////////
// Function: CConnectionRepository::get_time_warning
// Access: Published
// Description: Returns the current setting of the time_warning field.
////////////////////////////////////////////////////////////////////
INLINE bool CConnectionRepository::
get_time_warning() const {
return _time_warning;
}

View File

@ -66,6 +66,7 @@ CConnectionRepository(bool has_owner_view, bool threaded_net) :
_handle_datagrams_internally(handle_datagrams_internally), _handle_datagrams_internally(handle_datagrams_internally),
_simulated_disconnect(false), _simulated_disconnect(false),
_verbose(distributed_cat.is_spam()), _verbose(distributed_cat.is_spam()),
_time_warning(0.0),
// _msg_channels(), // _msg_channels(),
_msg_sender(0), _msg_sender(0),
_msg_type(0), _msg_type(0),
@ -1072,7 +1073,7 @@ bool CConnectionRepository::network_based_reader_and_yielder(PyObject *PycallBac
{ {
ReMutexHolder holder(_lock); ReMutexHolder holder(_lock);
while(is_connected()) while(is_connected())
{ {
check_datagram_ai(PycallBackFunction); check_datagram_ai(PycallBackFunction);
if(is_connected()) if(is_connected())
_bdc.Flush(); _bdc.Flush();
@ -1091,7 +1092,8 @@ bool CConnectionRepository::check_datagram_ai(PyObject *PycallBackFunction)
ReMutexHolder holder(_lock); ReMutexHolder holder(_lock);
// these could be static .. not // these could be static .. not
PyObject *doId2do = NULL; PyObject *doId2do = NULL;
float startTime =0;
float endTime = 0;
// this seems weird...here // this seems weird...here
_bdc.Flush(); _bdc.Flush();
while (_bdc.GetMessage(_dg)) while (_bdc.GetMessage(_dg))
@ -1099,6 +1101,9 @@ bool CConnectionRepository::check_datagram_ai(PyObject *PycallBackFunction)
if (get_verbose()) if (get_verbose())
describe_message(nout, "RECV", _dg); describe_message(nout, "RECV", _dg);
if (_time_warning > 0)
startTime = ClockObject::get_global_clock()->get_real_time();
// Start breaking apart the datagram. // Start breaking apart the datagram.
_di.assign(_dg); _di.assign(_dg);
unsigned char wc_cnt = _di.get_uint8(); unsigned char wc_cnt = _di.get_uint8();
@ -1121,6 +1126,13 @@ bool CConnectionRepository::check_datagram_ai(PyObject *PycallBackFunction)
if (!handle_update_field_ai(doId2do)) if (!handle_update_field_ai(doId2do))
{ {
Py_XDECREF(doId2do); Py_XDECREF(doId2do);
if (_time_warning > 0) {
endTime = ClockObject::get_global_clock()->get_real_time();
if ( _time_warning < (endTime - startTime)) {
nout << "msg " << _msg_type <<" from " << _msg_sender << " took "<< (endTime-startTime) << "secs to process\n";
describe_message(nout, "RECV", _dg);
}
}
return false; return false;
} }
} }
@ -1130,11 +1142,28 @@ bool CConnectionRepository::check_datagram_ai(PyObject *PycallBackFunction)
if (PyErr_Occurred()) if (PyErr_Occurred())
{ {
Py_XDECREF(doId2do); Py_XDECREF(doId2do);
if (_time_warning > 0) {
endTime = ClockObject::get_global_clock()->get_real_time();
if ( _time_warning < (endTime - startTime)) {
nout << "msg " << _msg_type <<" from " << _msg_sender << " took "<< (endTime-startTime) << "secs to process\n";
describe_message(nout, "RECV", _dg);
}
}
return true; return true;
} }
} }
if (_time_warning > 0) {
endTime = ClockObject::get_global_clock()->get_real_time();
if ( _time_warning < (endTime - startTime)) {
nout << "msg " << _msg_type <<" from " << _msg_sender << " took "<< (endTime-startTime) << "secs to process\n";
describe_message(nout, "RECV", _dg);
}
}
} }
Py_XDECREF(doId2do); Py_XDECREF(doId2do);
return false; return false;
} }

View File

@ -163,6 +163,9 @@ PUBLISHED:
INLINE void set_verbose(bool verbose); INLINE void set_verbose(bool verbose);
INLINE bool get_verbose() const; INLINE bool get_verbose() const;
INLINE void set_time_warning(float time_warning);
INLINE bool get_time_warning() const;
private: private:
#ifdef HAVE_PYTHON #ifdef HAVE_PYTHON
#ifdef WANT_NATIVE_NET #ifdef WANT_NATIVE_NET
@ -211,6 +214,7 @@ private:
bool _simulated_disconnect; bool _simulated_disconnect;
bool _verbose; bool _verbose;
bool _in_quiet_zone; bool _in_quiet_zone;
float _time_warning;
Datagram _dg; Datagram _dg;
DatagramIterator _di; DatagramIterator _di;