From 09fb6e9f1ba8592612c669b6e83e4af51c18bf65 Mon Sep 17 00:00:00 2001 From: Anthony Geay Date: Wed, 10 Jan 2024 17:14:06 +0100 Subject: [PATCH] [EDF29150] : Add some dynamic traces + assign a more explicite name in perflog --- src/bases/YacsTrace.cxx | 20 +++++++++++++-- src/bases/YacsTrace.hxx | 31 ++++++++++++++++------- src/engine/ForEachLoop.cxx | 1 + src/hmi/guiObservers.cxx | 1 - src/runtime/DistributedPythonNode.cxx | 36 +++++++++++++-------------- src/runtime/PythonNode.cxx | 9 +++++-- src/runtime/SalomeContainerTools.cxx | 23 +++++++++-------- src/runtime/TypeConversions.cxx | 9 ++++++- 8 files changed, 86 insertions(+), 44 deletions(-) diff --git a/src/bases/YacsTrace.cxx b/src/bases/YacsTrace.cxx index d6fc69ad1..c73467778 100644 --- a/src/bases/YacsTrace.cxx +++ b/src/bases/YacsTrace.cxx @@ -22,6 +22,10 @@ #include "YacsTrace.hxx" #include +#include +#include +#include + #ifdef WIN32 #include #define getpid _getpid @@ -29,8 +33,20 @@ #include #endif -namespace YACS{ - int traceLevel=0; +namespace YACS { + int traceLevel = 0; +} + +void YACS::AppendTimeClock(std::ostream& os) +{ + auto now = std::chrono::system_clock::now(); + auto duration = now.time_since_epoch(); + auto timestamp = std::chrono::system_clock::to_time_t(now); + std::tm *local_time = std::localtime(×tamp); + auto millis = std::chrono::duration_cast(duration).count(); + os << std::setfill('0') << std::setw(2) << local_time->tm_hour << ":" + << std::setw(2) << local_time->tm_min << ":" + << std::setw(2) << local_time->tm_sec << "." << std::setw(3) << millis % 1000 << " - "; } void AttachDebugger() diff --git a/src/bases/YacsTrace.hxx b/src/bases/YacsTrace.hxx index 37e13c91d..922c358dd 100644 --- a/src/bases/YacsTrace.hxx +++ b/src/bases/YacsTrace.hxx @@ -17,8 +17,7 @@ // See http://www.salome-platform.org/ or email : webmaster.salome@opencascade.com // -#ifndef __YACSTRACE_HXX__ -#define __YACSTRACE_HXX__ +#pragma once #include "YACSBasesExport.hxx" #include "Exception.hxx" @@ -27,22 +26,36 @@ #include #ifdef _DEVDEBUG_ -#define DEBTRACE(msg) {std::cerr<=level)std::cerr<<__FILE__<<" ["<<__LINE__<<"] : "<=level) \ + { \ + AppendTimeClock(std::cerr); \ + std::cerr << __FILE__ << " [" << __LINE__ << "] : " << msg << std::endl; \ + } } + +#define ERROR_YACSTRACE(msg) YACSTRACE(0,msg) + +#define WARNING_YACSTRACE(msg) YACSTRACE(1,msg) + +#define INFO_YACSTRACE(msg) YACSTRACE(2,msg) + +#define DEBUG_YACSTRACE(msg) YACSTRACE(7,msg) + +#define GURU_YACSTRACE(msg) YACSTRACE(99,msg) //! YASSERT macro is always defined, used like assert, but throw a YACS::Exception instead of abort -#define YASSERT(val) {if(!(val)){std::stringstream mess; mess<<__FILE__<<" ["<<__LINE__<<"] : assertion "<<#val<<" failed"; throw YACS::Exception(mess.str());}} +#define YASSERT(val) { if( !(val) ) { std::ostringstream mess; mess << __FILE__ << " [" <<__LINE__<< "] : assertion " << #val << " failed"; throw YACS::Exception(mess.str()); } } void AttachDebugger(); - -#endif diff --git a/src/engine/ForEachLoop.cxx b/src/engine/ForEachLoop.cxx index c8bf514bb..846203500 100644 --- a/src/engine/ForEachLoop.cxx +++ b/src/engine/ForEachLoop.cxx @@ -534,6 +534,7 @@ void ForEachLoopGen::exUpdateState() DEBTRACE("nbOfElts=" << nbOfElts); DEBTRACE("nbOfBr=" << nbOfBr); + INFO_YACSTRACE("nbOfBr (" << getName() << ") = " << nbOfBr); if(nbOfEltsToDo==0) { diff --git a/src/hmi/guiObservers.cxx b/src/hmi/guiObservers.cxx index c62bce0ba..3797b1c87 100644 --- a/src/hmi/guiObservers.cxx +++ b/src/hmi/guiObservers.cxx @@ -3520,7 +3520,6 @@ SubjectDataPort::~SubjectDataPort() if (isDestructible()) { Node* node = _dataPort->getNode(); - YASSERT(node); ElementaryNode * father = dynamic_cast(node); if (father) { diff --git a/src/runtime/DistributedPythonNode.cxx b/src/runtime/DistributedPythonNode.cxx index 8e4b7b27c..f8bc5361a 100644 --- a/src/runtime/DistributedPythonNode.cxx +++ b/src/runtime/DistributedPythonNode.cxx @@ -154,13 +154,13 @@ void DistributedPythonNode::load() throw Exception("In DistributedPythonNode the ref in NULL ! "); - DEBTRACE( "---------------End PyfuncSerNode::load function---------------" ); + DEBUG_YACSTRACE( "---------------End PyfuncSerNode::load function---------------" ); } } void DistributedPythonNode::execute() { - YACSTRACE(1,"+++++++++++++++++ DistributedPythonNode::execute: " << getName() << " " << getFname() << " +++++++++++++++++" ); + GURU_YACSTRACE("+++++++++++++++++ DistributedPythonNode::execute: " << getName() << " " << getFname() << " +++++++++++++++++" ); ////// PyObject* ob; if(!_pyfuncSer) @@ -170,7 +170,7 @@ void DistributedPythonNode::execute() { AutoGIL agil; - DEBTRACE( "---------------DistributedPythonNode::inputs---------------" ); + GURU_YACSTRACE( "---------------DistributedPythonNode::inputs---------------" ); args = PyTuple_New(getNumberOfInputPorts()) ; int pos=0; for(list::iterator iter2 = _setOfInputPort.begin(); iter2 != _setOfInputPort.end(); iter2++,pos++) @@ -191,7 +191,7 @@ void DistributedPythonNode::execute() Py_DECREF(serializationInput); } //serializationInputCorba[serializationInputC.length()]='\0'; - DEBTRACE( "-----------------DistributedPythonNode starting remote python invocation-----------------" ); + DEBUG_YACSTRACE( "-----------------DistributedPythonNode starting remote python invocation-----------------" ); Engines::pickledArgs *resultCorba; try { @@ -203,7 +203,7 @@ void DistributedPythonNode::execute() _errorDetails=msg; throw Exception(msg); } - DEBTRACE( "-----------------DistributedPythonNode end of remote python invocation-----------------" ); + DEBUG_YACSTRACE( "-----------------DistributedPythonNode end of remote python invocation-----------------" ); // delete serializationInputCorba; char *resultCorbaC=new char[resultCorba->length()+1]; @@ -220,7 +220,7 @@ void DistributedPythonNode::execute() delete [] resultCorbaC; PyTuple_SetItem(args,0,resultPython); PyObject *finalResult=PyObject_CallObject(_pyfuncUnser,args); - DEBTRACE( "-----------------DistributedPythonNode::outputs-----------------" ); + GURU_YACSTRACE( "-----------------DistributedPythonNode::outputs-----------------" ); if(finalResult == NULL) { std::stringstream msg; @@ -248,12 +248,12 @@ void DistributedPythonNode::execute() for(list::iterator iter = _setOfOutputPort.begin(); iter != _setOfOutputPort.end(); iter++, pos++) { OutputPyPort *p=(OutputPyPort *)*iter; - DEBTRACE( "port name: " << p->getName() ); - DEBTRACE( "port kind: " << p->typeName() ); - DEBTRACE( "port pos : " << pos ); + GURU_YACSTRACE( "port name: " << p->getName() ); + GURU_YACSTRACE( "port kind: " << p->typeName() ); + GURU_YACSTRACE( "port pos : " << pos ); if(PyTuple_Check(finalResult))ob=PyTuple_GetItem(finalResult,pos) ; else ob=finalResult; - DEBTRACE( "ob refcnt: " << ob->ob_refcnt ); + GURU_YACSTRACE( "ob refcnt: " << ob->ob_refcnt ); p->put(ob); } } @@ -264,7 +264,7 @@ void DistributedPythonNode::execute() throw; } } - DEBTRACE( "++++++++++++++ End DistributedPythonNode::execute: " << getName() << " ++++++++++++++++++++" ); + GURU_YACSTRACE( "++++++++++++++ End DistributedPythonNode::execute: " << getName() << " ++++++++++++++++++++" ); } std::string DistributedPythonNode::getEffectiveKindOfServer() const @@ -296,16 +296,16 @@ void DistributedPythonNode::dealException(CORBA::Exception *exc, const char *met { if( exc ) { - DEBTRACE( "An exception was thrown!" ); - DEBTRACE( "The raised exception is of Type:" << exc->_name() ); + GURU_YACSTRACE( "An exception was thrown!" ); + GURU_YACSTRACE( "The raised exception is of Type:" << exc->_name() ); CORBA::SystemException* sysexc; sysexc=CORBA::SystemException::_downcast(exc); if(sysexc != NULL) { // It's a SystemException - DEBTRACE( "minor code: " << sysexc->minor() ); - DEBTRACE( "completion code: " << sysexc->completed() ); + GURU_YACSTRACE( "minor code: " << sysexc->minor() ); + GURU_YACSTRACE( "completion code: " << sysexc->completed() ); std::string text="Execution problem: "; std::string excname=sysexc->_name(); if(excname == "BAD_OPERATION") @@ -330,7 +330,7 @@ void DistributedPythonNode::dealException(CORBA::Exception *exc, const char *met } else { - DEBTRACE(sysexc->NP_minorString() ); + GURU_YACSTRACE(sysexc->NP_minorString() ); text=text+"System Exception "+ excname; } _errorDetails=text; @@ -347,8 +347,8 @@ void DistributedPythonNode::dealException(CORBA::Exception *exc, const char *met const SALOME::SALOME_Exception* salexc; if(anyExcept >>= salexc) { - DEBTRACE("SALOME_Exception: "<< salexc->details.sourceFile); - DEBTRACE("SALOME_Exception: "<details.lineNumber); + GURU_YACSTRACE("SALOME_Exception: "<< salexc->details.sourceFile); + GURU_YACSTRACE("SALOME_Exception: "<details.lineNumber); _errorDetails=salexc->details.text; throw Exception("Execution problem: Salome Exception occurred" + getErrorDetails() ); } diff --git a/src/runtime/PythonNode.cxx b/src/runtime/PythonNode.cxx index d5101f6e2..6b9f14a70 100644 --- a/src/runtime/PythonNode.cxx +++ b/src/runtime/PythonNode.cxx @@ -578,10 +578,12 @@ void PythonNode::executeRemote() { //pass outargsname and dict serialized SALOME::SenderByte_var serializationInputRef = serializationInputCorba->_this(); + DEBUG_YACSTRACE("Before execute first of " << getId()); _pynode->executeFirst(serializationInputRef); //serializationInput and serializationInputCorba are no more needed for server. Release it. serializationInput.set(nullptr); resultCorba.reset( _pynode->executeSecond(myseq) ); + DEBUG_YACSTRACE("After execute second of " << getId()); } catch( const SALOME::SALOME_Exception& ex ) { @@ -677,6 +679,7 @@ void PythonNode::executeRemote() for(iter = _setOfOutputPort.begin(); iter != _setOfOutputPort.end(); ++iter) { OutputPyPort *p=(OutputPyPort *)*iter; + DEBUG_YACSTRACE("Start of dealing with output " << p->getName() << " of "<< getId()); DEBTRACE( "port name: " << p->getName() ); DEBTRACE( "port kind: " << p->edGetType()->kind() ); DEBTRACE( "port pos : " << pos ); @@ -698,7 +701,9 @@ void PythonNode::executeRemote() throw YACS::ENGINE::ConversionException(msg.str()); } UnlinkOnDestructorIfProxy(ob); + DEBUG_YACSTRACE("Assign PyObj output " << p->getName() << " of "<< getId()); p->put( ob ); + DEBUG_YACSTRACE("End of assign PyObj output " << p->getName() << " of "<< getId()); } pos++; } @@ -717,7 +722,7 @@ void PythonNode::executeRemote() freeKernelPynode(); bool dummy; Engines::Container_var cont(GetContainerObj(this,dummy)); - cont->removePyScriptNode(getName().c_str()); + cont->removePyScriptNode(getId().c_str()); } DEBTRACE( "++++++++++++++ ENDOF PyNode::executeRemote: " << getName() << " ++++++++++++++++++++" ); } @@ -945,7 +950,7 @@ std::string PythonNode::pythonEntryName()const if(isUsingPythonCache()) return "DEFAULT_NAME_FOR_UNIQUE_PYTHON_NODE_ENTRY"; else - return getName(); + return getId(); } bool PythonNode::isUsingPythonCache()const diff --git a/src/runtime/SalomeContainerTools.cxx b/src/runtime/SalomeContainerTools.cxx index ca7ee3055..4a2a4427b 100644 --- a/src/runtime/SalomeContainerTools.cxx +++ b/src/runtime/SalomeContainerTools.cxx @@ -22,6 +22,7 @@ #include "SALOME_NamingService_Wrapper.hxx" #include "SALOME_ResourcesManager.hxx" #include "SALOME_ContainerManager.hxx" + #include "Container.hxx" #include "AutoLocker.hxx" @@ -70,7 +71,7 @@ std::string SalomeContainerTools::getProperty(const std::string& name) const void SalomeContainerTools::setProperty(const std::string& name, const std::string& value) { - //DEBTRACE("SalomeContainer::setProperty : " << name << " ; " << value); + //DEBUG_YACSTRACE("SalomeContainer::setProperty : " << name << " ; " << value); // Container Part if (name == "container_name") _params.container_name = CORBA::string_dup(value.c_str()); @@ -334,7 +335,7 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, bool isEmptyName; std::string str(sct.getNotNullContainerName(cont,askingNode,isEmptyName)); - DEBTRACE("SalomeContainer::start " << str <<";"<< sct.getHostName() ); + DEBUG_YACSTRACE("SalomeContainer::start " << str <<";"<< sct.getHostName() ); // Finalize parameters with components found in the container @@ -370,7 +371,7 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, myparams.mode="get"; try { - DEBTRACE("GiveContainer " << str << " mode " << myparams.mode); + DEBUG_YACSTRACE("GiveContainer " << str << " mode " << myparams.mode); trueCont=contManager->GiveContainer(myparams); } catch( const SALOME::SALOME_Exception& ex ) @@ -378,7 +379,7 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, std::string msg="SalomeContainer::start : no existing container : "; msg += '\n'; msg += ex.details.text.in(); - DEBTRACE( msg ); + DEBUG_YACSTRACE( msg ); } catch(...) { @@ -387,13 +388,13 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, if(!CORBA::is_nil(trueCont)) { shutdownLevel=3; - DEBTRACE( "container found: " << str << " " << shutdownLevel ); + DEBUG_YACSTRACE( "container found: " << str << " " << shutdownLevel ); } else { shutdownLevel=2; myparams.mode="start"; - DEBTRACE( "container not found: " << str << " " << shutdownLevel); + DEBUG_YACSTRACE( "container not found: " << str << " " << shutdownLevel); } } @@ -404,7 +405,7 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, { // --- GiveContainer is used in batch mode to retreive launched containers, // and is equivalent to StartContainer when not in batch. - DEBTRACE("GiveContainer " << str << " mode " << myparams.mode); + DEBUG_YACSTRACE("GiveContainer " << str << " mode " << myparams.mode); trueCont=contManager->GiveContainer(myparams); } catch( const SALOME::SALOME_Exception& ex ) @@ -417,7 +418,7 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, catch(CORBA::COMM_FAILURE&) { //std::cerr << "SalomeContainer::start : CORBA Comm failure detected. Make another try!" << std::endl; - DEBTRACE("SalomeContainer::start :" << str << " :CORBA Comm failure detected. Make another try!"); + DEBUG_YACSTRACE("SalomeContainer::start :" << str << " :CORBA Comm failure detected. Make another try!"); nbTries++; if(nbTries > 5) throw Exception("SalomeContainer::start : Unable to launch container in Salome : CORBA Comm failure detected"); @@ -436,12 +437,12 @@ void SalomeContainerToolsBase::Start(const std::vector& compoNames, CORBA::String_var containerName(trueCont->name()),hostName(trueCont->getHostName()); //std::cerr << "SalomeContainer launched : " << containerName << " " << hostName << " " << trueCont->getPID() << std::endl; - DEBTRACE("SalomeContainer launched : " << containerName << " " << hostName << " " << trueCont->getPID() ); + DEBUG_YACSTRACE("SalomeContainer launched : NS entry : " << containerName << " PID : " << trueCont->getPID() ); } CORBA::Object_ptr SalomeContainerToolsBase::LoadComponent(SalomeContainerHelper *launchModeType, Container *cont, Task *askingNode) { - DEBTRACE("SalomeContainer::loadComponent "); + DEBUG_YACSTRACE("SalomeContainer::loadComponent "); const ComponentInstance *inst(askingNode?askingNode->getComponent():0); { YACS::BASES::AutoLocker alck(cont);//To be sure @@ -486,7 +487,7 @@ CORBA::Object_ptr SalomeContainerToolsBase::CreateComponentInstance(Container *c int item=0; for(itm = properties.begin(); itm != properties.end(); ++itm, item++) { - DEBTRACE("envname="<first<<" envvalue="<< itm->second); + DEBUG_YACSTRACE("envname="<first<<" envvalue="<< itm->second); env[item].key= CORBA::string_dup(itm->first.c_str()); env[item].value <<= itm->second.c_str(); } diff --git a/src/runtime/TypeConversions.cxx b/src/runtime/TypeConversions.cxx index 7c5620023..972c540f6 100644 --- a/src/runtime/TypeConversions.cxx +++ b/src/runtime/TypeConversions.cxx @@ -861,15 +861,18 @@ namespace YACS throw YACS::ENGINE::ConversionException(msg.str()); } int length=PySequence_Size(o); - DEBTRACE("length: " << length ); + GURU_YACSTRACE("convertToYacsSequence : length = " << length); v.resize(length); for(int i=0;i unlink"); YACS::ENGINE::PythonEntry::UnlinkOnDestructorIfProxy(item); + GURU_YACSTRACE("convertToYacsSequence : it s proxy -> incrRef"); YACS::ENGINE::PythonEntry::IfProxyDoSomething(item,"incrRef"); } #ifdef _DEVDEBUG_ @@ -994,13 +997,17 @@ namespace YACS { //It's a python pickled object, unpickled it PyObject* mod=PyImport_ImportModule("pickle"); + GURU_YACSTRACE("convertFromYacsObjref : unpickling..."); PyObject *ob=PyObject_CallMethod(mod,(char *)"loads",(char *)"y#",o.c_str(),o.length()); + GURU_YACSTRACE("convertFromYacsObjref : unpickling done..."); DEBTRACE(PyObject_Repr(ob)); Py_DECREF(mod); + GURU_YACSTRACE("convertFromYacsObjref : Analyze if it's a proxy"); bool somthingToDo = YACS::ENGINE::PythonEntry::IsProxy(ob); if( somthingToDo ) { // no incrRef here because the incrRef has been done before dumps that construct o. + GURU_YACSTRACE("convertFromYacsObjref : It's a proxy -> activate on deletion"); YACS::ENGINE::PythonEntry::UnlinkOnDestructorIfProxy(ob); } if(ob==NULL) -- 2.39.2