Salome HOME
[EDF29150] : Add some dynamic traces + assign a more explicite name in perflog emc2p_1.6.0-rc1
authorAnthony Geay <anthony.geay@edf.fr>
Wed, 10 Jan 2024 16:14:06 +0000 (17:14 +0100)
committerAnthony Geay <anthony.geay@edf.fr>
Mon, 12 Feb 2024 12:27:25 +0000 (13:27 +0100)
src/bases/YacsTrace.cxx
src/bases/YacsTrace.hxx
src/engine/ForEachLoop.cxx
src/hmi/guiObservers.cxx
src/runtime/DistributedPythonNode.cxx
src/runtime/PythonNode.cxx
src/runtime/SalomeContainerTools.cxx
src/runtime/TypeConversions.cxx

index d6fc69ad17feb1d79926438020a2b16f731f0d8e..c734677785529baf8898dd99f279156f4052ef7b 100644 (file)
 #include "YacsTrace.hxx"
 #include <cstdlib>
 
+#include <chrono>
+#include <iomanip>
+#include <ctime>
+
 #ifdef WIN32
 #include <process.h>
 #define getpid _getpid
 #include <unistd.h>
 #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(&timestamp);
+  auto millis = std::chrono::duration_cast<std::chrono::milliseconds>(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()
index 37e13c91dbd763409159d175c8a94dd2357ee93b..922c358dd34e25aef24def30d4a5d05d918b0864 100644 (file)
@@ -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"
 #include <sstream>
 
 #ifdef _DEVDEBUG_
-#define DEBTRACE(msg) {std::cerr<<std::flush<<__FILE__<<" ["<<__LINE__<<"] : "<<msg<<std::endl<<std::flush;}
+#define DEBTRACE(msg) { std::cerr << std::flush << __FILE__ << " [" << __LINE__ << "] : " << msg << std::endl << std::flush; }
 #else
 #define DEBTRACE(msg)
 #endif
 
-namespace YACS{
-extern YACSBASES_EXPORT int traceLevel;
+namespace YACS
+{
+  extern YACSBASES_EXPORT int traceLevel;
+  void AppendTimeClock(std::ostream& os);
 }
 
 //! YACSTRACE macro for dynamic trace: print only if YACS_TRACELEVEL environment variable is set and level is less than  its value
-#define YACSTRACE(level,msg) {if(YACS::traceLevel >=level)std::cerr<<__FILE__<<" ["<<__LINE__<<"] : "<<msg<<std::endl;}
+#define YACSTRACE(level,msg) { if(YACS::traceLevel >=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
index c8bf514bb1942d05ec83a9fee87a3671118ccf15..846203500182f52ca33716c49d80d144137c7feb 100644 (file)
@@ -534,6 +534,7 @@ void ForEachLoopGen::exUpdateState()
 
       DEBTRACE("nbOfElts=" << nbOfElts);
       DEBTRACE("nbOfBr=" << nbOfBr);
+      INFO_YACSTRACE("nbOfBr (" << getName() << ") = " << nbOfBr);
 
       if(nbOfEltsToDo==0)
         {
index c62bce0ba148a8c2e52887b548fc037775608c25..3797b1c872b78d101d1710150c7152c6412d57c6 100644 (file)
@@ -3520,7 +3520,6 @@ SubjectDataPort::~SubjectDataPort()
   if (isDestructible())
     {
       Node* node = _dataPort->getNode();
-      YASSERT(node);
       ElementaryNode * father = dynamic_cast<ElementaryNode*>(node);
       if (father)
         {
index 8e4b7b27ca73823aa610a0aa7df9aad1913a5710..f8bc5361abbb693852911d625a793038f228a03e 100644 (file)
@@ -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<InputPort *>::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<OutputPort *>::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: "<<salexc->details.lineNumber);
+              GURU_YACSTRACE("SALOME_Exception: "<< salexc->details.sourceFile);
+              GURU_YACSTRACE("SALOME_Exception: "<<salexc->details.lineNumber);
               _errorDetails=salexc->details.text;
               throw Exception("Execution problem: Salome Exception occurred" + getErrorDetails() );
             }
index d5101f6e234716b7048293eb42ab59389900c047..6b9f14a7001f96cb09adb1242fc20b724cea484c 100644 (file)
@@ -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
index ca7ee3055b9ae09f4fd1b9de2b1c283840cec420..4a2a4427b07bead9abc25ce545badc0668e7822f 100644 (file)
@@ -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<std::string>& 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<std::string>& 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<std::string>& 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<std::string>& 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<std::string>& 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<std::string>& 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<std::string>& 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<Container> 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="<<itm->first<<" envvalue="<< itm->second);
+      DEBUG_YACSTRACE("envname="<<itm->first<<" envvalue="<< itm->second);
       env[item].key= CORBA::string_dup(itm->first.c_str());
       env[item].value <<= itm->second.c_str();
     }
index 7c5620023dafcc2a008e231647f8b1d2915df1c8..972c540f6830a0419c6292ba67a0b84120ca6026 100644 (file)
@@ -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<length;i++)
             {
               PyObject *item=PySequence_ITEM(o,i);
+              GURU_YACSTRACE("convertToYacsSequence : analyze if proxy");
               bool somthingToDo = YACS::ENGINE::PythonEntry::IsProxy(item);
               if( somthingToDo )
               {
+                GURU_YACSTRACE("convertToYacsSequence : it s proxy -> 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)