fixed transaction log (bug#86)

git-svn-id: https://silmor.de/svn/softmagic/smoke/trunk@401 6e3c4bff-ac9f-4ac1-96c5-d2ea494d3e33

diff --git a/src/wbase/WInterface.h b/src/wbase/WInterface.h
index 100f9db..3cac7c4 100644 (file)
--- a/src/wbase/WInterface.h
+++ b/src/wbase/WInterface.h
@@ -56,12 +56,16 @@ class WInterface:public QObject
                
                /**log settings*/
                enum LogLevel {
+                       /**no logging*/
+                       LogNone=0,
                        /**minimal logging*/
-                       LogMinimal=0,
-                       /**log details on error*/
-                       LogOnError=1,
+                       LogMinimal=1,
+                       /**informational logging (more than minimal, not much yet)*/
+                       LogInfo=2,
+                       /**like LogInfo, but logs additional details on error*/
+                       LogOnError=0x12,
                        /**always log details*/
-                       LogDetailed=0xf
+                       LogDetailed=0xff
                };
                
                /**returns the current log level*/

diff --git a/src/wbase/WTransaction.cpp b/src/wbase/WTransaction.cpp
index c50556d..3023f24 100644 (file)
--- a/src/wbase/WTransaction.cpp
+++ b/src/wbase/WTransaction.cpp
@@ -27,6 +27,7 @@ WTransaction::WTransaction(QString ifc)
        m_stage=Uninitialized;
        m_httpid=-1;
        m_iface=ifc;
+       m_log=0;
 }
 WTransaction::WTransaction(const WTransaction&t)
        :WHelper()
@@ -36,6 +37,7 @@ WTransaction::WTransaction(const WTransaction&t)
        m_errtype=t.m_errtype;
        m_iface=t.m_iface;
        m_httpid=-1;
+       m_log=0;
 }
 
 WTransaction& WTransaction::operator=(const WTransaction&t)
@@ -67,12 +69,12 @@ QByteArray WTransaction::executeQuery(QString hreq,QByteArray data)
        //show the user we are waiting
        WaitCursor wc;
        //set up request
-       QString log;
        QEventLoop loop(this);
        connect(this,SIGNAL(webFinished()),&loop,SLOT(quit()));
        WInterface *iface=WInterface::instance(m_iface);
        if(!iface){
-               qDebug("Error: transaction cannot find interface.");
+               if(m_log)m_log->setError("cannot find interface.");
+               else qDebug("Error: transaction cannot find interface.");
                m_stage=Error;
                m_errtype="_iface";
                m_errstr=tr("interface not found");
@@ -85,12 +87,12 @@ QByteArray WTransaction::executeQuery(QString hreq,QByteArray data)
                if(url.scheme().toLower()=="http")port=80;
                else port=443;
        }
-       qDebug()<<QString("New HTTP Request %1 URL %2\n\tto host=%3 port=%4 scheme=%5")
+       if(m_log)m_log->setInfo(QString("New HTTP Request %1 URL %2\n\tto host=%3 port=%4 scheme=%5")
                .arg(hreq)
                .arg(url.toString())
                .arg(url.host())
                .arg(port)
-               .arg(url.scheme());
+               .arg(url.scheme()));
        QHttp::ConnectionMode conm;
        if(url.scheme().toLower()=="http")conm=QHttp::ConnectionModeHttp;
        else conm=QHttp::ConnectionModeHttps;
@@ -110,11 +112,11 @@ QByteArray WTransaction::executeQuery(QString hreq,QByteArray data)
        hrh.setValue("X-WobRequest",hreq);
        hrh.setContentLength(data.size());
        hrh.setContentType("application/x-webobject; charset=UTF-8");
-       WInterface::LogLevel loglvl=iface->logLevel();
        m_httpid=req.request(hrh,data);
-       if(loglvl>WInterface::LogMinimal)
-               log=QString("Request %3 with header:\n%1\n\nRequest Body:\n%2\n<---->\n").arg(hrh.toString()).arg(esc(data)).arg(m_httpid);
-       qDebug("started req %i",m_httpid);
+       if(m_log){
+               m_log->setRequ(hrh.toString(),esc(data),m_httpid);
+               m_log->setInfo(QString("HTTP ID %1").arg(m_httpid));
+       }
        
        /////////////////////////////////////////////////////////////////////
        //start loop
@@ -130,39 +132,29 @@ QByteArray WTransaction::executeQuery(QString hreq,QByteArray data)
                //it did not finish yet, caught a timeout.
                req.abort();
                m_errstr=tr("Web Request timed out.");
-               qDebug("Request %i timed out.",m_httpid);
-               if(loglvl&WInterface::LogOnError)
-                       qDebug()<<log;
+               if(m_log)m_log->setError(QString("Request %1 timed out.").arg(m_httpid));
                return QByteArray();
        }else
        //finished with low-level error?
        if(m_stage==Error){
                m_errstr="HTTP Error: "+req.errorString();
-               log+=QString("Request %2 finished with HTTP level error: %1").arg(m_errstr).arg(m_httpid);
-               if(loglvl&WInterface::LogOnError)
-                       qDebug()<<log;
+               if(m_log)m_log->setError(QString("Request %2 finished with HTTP level error: %1").arg(m_errstr).arg(m_httpid));
                return QByteArray();
        }
+       //get data
        QHttpResponseHeader rsph=req.lastResponse();
        m_wobstatus=rsph.value("X-WobResponse-Status");
        m_wobstatus=m_wobstatus.replace("\"","").trimmed().toLower();
+       QByteArray rspdata=req.readAll();
+       if(m_log)m_log->setResp(rsph.toString(),esc(rspdata),m_httpid);
        //check for high level error
        if(rsph.statusCode()!=200){
                m_errstr=tr("HTTP Error, return code %1 %2") .arg(rsph.statusCode()).arg(rsph.reasonPhrase());
                m_errtype="_HTTP";
                m_stage=Error;
-               log+=QString("Request %2 finished with HTTP level error: %1").arg(m_errstr).arg(m_httpid);
-               if(loglvl&WInterface::LogOnError)
-                       qDebug()<<log;
+               if(m_log)m_log->setError(QString("Request %2 finished with HTTP level error: %1").arg(m_errstr).arg(m_httpid));
                return QByteArray();
        }
-       //get data
-       QByteArray rspdata=req.readAll();
-       //log
-       if(loglvl==WInterface::LogDetailed){
-               log+=QString ("----->\nHTTP Response %3 Headers:\n%1\nHTTP Response %3 Body:\n%2\n<------------------").arg(rsph.toString()).arg(esc(rspdata)).arg(m_httpid);
-               qDebug()<<log;
-       }
        if(m_stage!=Error)m_stage=Success;
        //remaining high level errors are handled by the generated code
        return rspdata;
@@ -171,7 +163,7 @@ QByteArray WTransaction::executeQuery(QString hreq,QByteArray data)
 void WTransaction::webTimeout()
 {
        if(m_httpid<0)return;
-       qDebug("web timeout");
+//     qDebug("web timeout");
        m_stage=Error;
        m_errtype="_timeout";
        emit webFinished();
@@ -180,7 +172,7 @@ void WTransaction::webTimeout()
 void WTransaction::webReady(int i,bool e)
 {
        if(i!=m_httpid)return;
-       qDebug("finished req %i",i);
+       if(m_log)m_log->setInfo(QString("finished request %1").arg(i));
        if(e){
                m_stage=Error;
                m_errtype="_web";
@@ -192,3 +184,70 @@ QString WTransaction::errorString()const
 {
        return QCoreApplication::translate("php::",m_errstr.toUtf8(),0,QCoreApplication::UnicodeUTF8);
 }
+
+
+WTransaction::WTLog::WTLog(WTransaction*p,const QString&s)
+{
+       parent=p;
+       parent->m_log=this;
+       trn=s;
+       WInterface*in=WInterface::instance(p->m_iface);
+       if(in)lvl=in->logLevel();
+       else lvl=WInterface::LogOnError;
+       if(lvl>WInterface::LogNone)
+               qDebug("Running transaction %s",s.toAscii().data());
+}
+
+WTransaction::WTLog::~WTLog()
+{
+       parent->m_log=0;
+}
+
+void WTransaction::WTLog::setRequ(const QString&h,const QString&d,int i)
+{
+       if(lvl<=WInterface::LogInfo)return;
+       QByteArray r="RequestID="+QString::number(i).toAscii()
+        +"\n--Header--\n"+h.trimmed().toAscii()
+        +"\n--Body--\n"+d.trimmed().toAscii()+"\n--End--";
+       if(lvl==WInterface::LogDetailed)
+               qDebug("Transaction %s request: %s",trn.toAscii().data(),r.data());
+       else
+       if(lvl==WInterface::LogOnError)
+               req=r;
+}
+
+void WTransaction::WTLog::setResp(const QString&h,const QString&d,int i)
+{
+       if(lvl<=WInterface::LogInfo)return;
+       QByteArray r="RequestID="+QString::number(i).toAscii()
+        +"\n--Header--\n"+h.trimmed().toAscii()
+        +"\n--Body--\n"+d.trimmed().toAscii()+"\n--End--";
+       if(lvl==WInterface::LogDetailed)
+               qDebug("Transaction %s response: %s",trn.toAscii().data(),r.data());
+       else
+       if(lvl==WInterface::LogOnError)
+               rsp=r;
+}
+
+void WTransaction::WTLog::setInfo(const QString&s)
+{
+       if(lvl>=WInterface::LogInfo)
+               qDebug("Transaction %s info: %s",trn.toAscii().data(),s.toAscii().data());
+}
+
+void WTransaction::WTLog::setError(const QString&s)
+{
+       //bail out if no logging
+       if(lvl<WInterface::LogMinimal)return;
+       //only for LogOnError, these have been stored, replay them:
+       if(req.size()>0){
+               qDebug("Transaction %s on error, request was: %s",trn.toAscii().data(),req.data());
+               req=QByteArray();
+       }
+       if(rsp.size()>0){
+               qDebug("Transaction %s on error, response was: %s",trn.toAscii().data(),rsp.data());
+               rsp=QByteArray();
+       }
+       //show actual error
+       qDebug("Transaction %s Error: %s",trn.toAscii().data(),s.toAscii().data());
+}
\ No newline at end of file

diff --git a/src/wbase/WTransaction.h b/src/wbase/WTransaction.h
index 74b0afc..907ae7c 100644 (file)
--- a/src/wbase/WTransaction.h
+++ b/src/wbase/WTransaction.h
@@ -55,6 +55,22 @@ class WTransaction:public WHelper
                
                /**internal: execute a query on the web, used by subclasses*/
                QByteArray executeQuery(QString,QByteArray);
+               
+               /**internal logger class*/
+               class WTLog{
+                       public:
+                               WTLog(WTransaction*,const QString&);
+                               ~WTLog();
+                               void setRequ(const QString&,const QString&,int);
+                               void setResp(const QString&,const QString&,int);
+                               void setError(const QString&);
+                               void setInfo(const QString&);
+                       private:
+                               QByteArray req,rsp;
+                               QString trn;
+                               WTransaction*parent;
+                               int lvl;
+               };
        private slots:
                /**internal: triggers when the transaction times out*/
                void webTimeout();
@@ -64,9 +80,11 @@ class WTransaction:public WHelper
                /**this signal is raised when the transaction finished executing*/
                void webFinished();
        protected:
+               friend class WTransaction::WTLog;
                Stage m_stage;
                QString m_errtype,m_errstr,m_iface,m_wobstatus;
                int m_httpid;
+               WTLog*m_log;
 };
 
 #endif

diff --git a/woc/qtout.cpp b/woc/qtout.cpp
index eac47af..beb2e85 100644 (file)
--- a/woc/qtout.cpp
+++ b/woc/qtout.cpp
@@ -568,10 +568,11 @@ void WocQtClientOut::newTransaction(const WocTransaction&trn)
        
        //query method implemented
        scd+="void "+cn+"::netquery()\n{\n";
+       scd+="\tWTLog log(this,\""+trn.name()+"\");\n";
        scd+="\tQDomDocument doc;QDomElement root=doc.createElement(\"WobRequest\");\n";
        scd+="\tQDomElement tmp;\n";
        scd+="\tWInterface *iface=WInterface::instance(m_iface);\n";
-       scd+="\tif(iface==0){m_errtype=\"_iface\";m_errstr=\"interface not found\";m_stage=Error;return;}\n";
+       scd+="\tif(iface==0){m_errtype=\"_iface\";m_errstr=\"interface not found\";m_stage=Error;log.setError(m_errstr);return;}\n";
        //encode input
        scd+=trnInput(trn);
        scd+="\tdoc.appendChild(root);\n";
@@ -671,15 +672,15 @@ QString WocQtClientOut::trnOutput(const WocTransaction&trn)
        code+="\tdoc=QDomDocument();\n";
        code+="\tQString emsg;int eln,ecl;\n";
        code+="\tif(!doc.setContent(rba,&emsg,&eln,&ecl)){\n";
-       code+="\t\tm_stage=Error;m_errtype=\"_iface\";m_errstr=QString(QCoreApplication::translate(\"WobTransaction\",\"XML result parser error line %1 col %2: %3\")).arg(eln).arg(ecl).arg(emsg);\n\t\treturn;\n\t}\n";
+       code+="\t\tm_stage=Error;m_errtype=\"_iface\";m_errstr=QString(QCoreApplication::translate(\"WobTransaction\",\"XML result parser error line %1 col %2: %3\")).arg(eln).arg(ecl).arg(emsg);\n\t\tlog.setError(m_errstr);\n\t\treturn;\n\t}\n";
        code+="\troot=doc.documentElement();\n";
        //decide where to go, error handling
        code+="\tif(m_wobstatus!=\"ok\"){\n\t\tm_stage=Error;m_errtype=\"_server\";m_errstr=\"unknown server error\";\n";
        code+="\t\tQList<QDomElement> nl=elementsByTagName(root,\"Error\");\n";
-       code+="\t\tif(nl.size()==0)return;\n";
+       code+="\t\tif(nl.size()==0){\n\t\t\tlog.setError(m_errstr);\n\t\t\treturn;\n\t\t}\n";
        code+="\t\ttmp=nl.at(0).toElement();\n";
        code+="\t\tm_errtype=tmp.attribute(\"type\",\"_server\");\n";
-       code+="\t\tm_errstr=tmp.text();\n\t\treturn;\n\t}\n";
+       code+="\t\tm_errstr=tmp.text();\n\t\tlog.setError(m_errstr);\n\t\treturn;\n\t}\n";
        code+="\tQList<QDomElement> nl;\n";
        //parse parameters
        for(int i=0;i<sl.size();i++){
@@ -694,7 +695,7 @@ QString WocQtClientOut::trnOutput(const WocTransaction&trn)
                        if(trn.isListType(t)){
                                code+="\tfor(int i=0;i<nl.size();i++){\n";
                                if(trn.isObjectType(t)){
-                                       code+="\t\ttry{out_"+sl[i]+".append("+qtobjtype(trn,sl[i],Out)+"(nl.at(i).toElement()));}catch(WException e){m_stage=Error;m_errtype=e.component();m_errstr=e.error();}\n";
+                                       code+="\t\ttry{out_"+sl[i]+".append("+qtobjtype(trn,sl[i],Out)+"(nl.at(i).toElement()));}catch(WException e){m_stage=Error;m_errtype=e.component();m_errstr=e.error();log.setError(m_errstr);}\n";
                                }else if(trn.isIntType(t)){
                                        code+="\t\tout_"+sl[i]+".append(nl.at(i).toElement().text().toInt());\n";
                                }else if(trn.isBoolType(t)){
@@ -708,7 +709,7 @@ QString WocQtClientOut::trnOutput(const WocTransaction&trn)
                        }else{
                                code+="\tif(nl.size()>0){\n";
                                if(trn.isObjectType(t)){
-                                       code+="\t\ttry{out_"+sl[i]+"="+qtobjtype(trn,sl[i],Out)+"(nl.at(0).toElement());}catch(WException e){m_stage=Error;m_errtype=e.component();m_errstr=e.error();}\n";
+                                       code+="\t\ttry{out_"+sl[i]+"="+qtobjtype(trn,sl[i],Out)+"(nl.at(0).toElement());}catch(WException e){m_stage=Error;m_errtype=e.component();m_errstr=e.error();log.setError(m_errstr);}\n";
                                }else if(trn.isBlobType(t)){
                                        code+="\t\tout_"+sl[i]+"=QByteArray::fromBase64(nl.at(0).toElement().text().toAscii());\n";
                                }else{//can only be string