HPCC-24946 Add jlog multiline logger methods

Signed-off-by: Jake Smith <jake.smith@lexisnexisrisk.com>

common/thorhelper/thorsoapcall.cpp

@@ -51,24 +51,6 @@ unsigned soapTraceLevel = 1;
 #define WSCBUFFERSIZE 0x10000
 #define MAXWSCTHREADS 50    //Max Web Service Call Threads
 
-void multiLog(const IContextLogger &logger, const char *format, ...) __attribute__((format(printf, 2, 3)));
-
-void multiLog(const IContextLogger &logger, const char *format, ...)
-{
-    va_list args;
-    va_start(args, format);
-    StringBuffer log;
-    log.limited_valist_appendf(1024*1024, format, args);
-    va_end(args);
-    StringArray loglines;
-    log.replace('\r', ' ');
-    loglines.appendList(log, "\n", false);
-    ForEachItemIn(idx, loglines)
-    {
-        logger.CTXLOG("%s", loglines.item(idx));
-    }
-}
-
 
 interface DECL_EXCEPTION IReceivedRoxieException : extends IException
 {
@@ -1645,7 +1627,7 @@ private:
         content = contentDecoded;
 
         if (soapTraceLevel > 6 || master->logXML)
-            multiLog(master->logctx, "Content decoded. Original %s %d", CONTENT_LENGTH, contentLength);
+            master->logctx.CTXLOG("Content decoded. Original " CONTENT_LENGTH " %d", contentLength);
 #else
             throw MakeStringException(-1, "_USE_ZLIB is required for Content-Encoding:%s", contentEncodingType);
 #endif
@@ -1691,9 +1673,9 @@ private:
         if (soapTraceLevel > 6 || master->logXML)
         {
             if (!contentEncoded)
-                multiLog(master->logctx, "%s: request(%s)", master->wscCallTypeText(), request.str());
+                master->logctx.mCTXLOG("%s: request(%s)", master->wscCallTypeText(), request.str());
             else
-                multiLog(master->logctx, "%s: request(%s), content encoded.", master->wscCallTypeText(), request.str());
+                master->logctx.mCTXLOG("%s: request(%s), content encoded.", master->wscCallTypeText(), request.str());
         }
     }
 
@@ -1709,7 +1691,7 @@ private:
         if (httpheaders && *httpheaders)
         {
             if (soapTraceLevel > 6 || master->logXML)
-                multiLog(master->logctx, "%s: Adding HTTP Headers(%s)",  master->wscCallTypeText(), httpheaders);
+                master->logctx.mCTXLOG("%s: Adding HTTP Headers(%s)",  master->wscCallTypeText(), httpheaders);
             request.append(httpheaders);
         }
 
@@ -1750,7 +1732,7 @@ private:
                 StringBuffer hdr(master->httpHeaderName.get());
                 hdr.append(": ").append(master->httpHeaderValue);
                 if (soapTraceLevel > 6 || master->logXML)
-                    multiLog(master->logctx, "SOAPCALL: Adding HTTP Header(%s)", hdr.str());
+                    master->logctx.mCTXLOG("SOAPCALL: Adding HTTP Header(%s)", hdr.str());
                 request.append(hdr.append("\r\n"));
             }
             if (!httpHeaderBlockContainsHeader(httpheaders, "Content-Type"))
@@ -1961,9 +1943,9 @@ private:
         if (checkContentDecoding(dbgheader, response, contentEncoding))
             decodeContent(contentEncoding.str(), response);
         if (soapTraceLevel > 6 || master->logXML)
-            multiLog(master->logctx, "%sCALL: LEN=%d %sresponse(%s%s)", master->wscType == STsoap ? "SOAP" : "HTTP",response.length(),chunked?"CHUNKED ":"", dbgheader.str(), response.str());
+            master->logctx.mCTXLOG("%sCALL: LEN=%d %sresponse(%s%s)", master->wscType == STsoap ? "SOAP" : "HTTP",response.length(),chunked?"CHUNKED ":"", dbgheader.str(), response.str());
         else if (soapTraceLevel > 8)
-            multiLog(master->logctx, "%sCALL: LEN=%d %sresponse(%s)", master->wscType == STsoap ? "SOAP" : "HTTP",response.length(),chunked?"CHUNKED ":"", response.str()); // not sure this is that useful but...
+            master->logctx.mCTXLOG("%sCALL: LEN=%d %sresponse(%s)", master->wscType == STsoap ? "SOAP" : "HTTP",response.length(),chunked?"CHUNKED ":"", response.str()); // not sure this is that useful but...
         return rval;
     }
 
@@ -2254,7 +2236,7 @@ public:
                 checkRoxieAbortMonitor(master->roxieAbortMonitor);
                 socket->write(request.str(), request.length());
                 if (soapTraceLevel > 4)
-                    multiLog(master->logctx, "%sCALL: sent request (%s) to %s:%d", master->wscType == STsoap ? "SOAP" : "HTTP",master->service.str(), url.host.str(), url.port);
+                    master->logctx.CTXLOG("%sCALL: sent request (%s) to %s:%d", master->wscType == STsoap ? "SOAP" : "HTTP",master->service.str(), url.host.str(), url.port);
                 checkTimeLimitExceeded(&remainingMS);
                 checkRoxieAbortMonitor(master->roxieAbortMonitor);
 
@@ -2263,7 +2245,7 @@ public:
                 keepAlive = keepAlive && keepAlive2;
 
                 if (soapTraceLevel > 4)
-                    multiLog(master->logctx, "%sCALL: received response (%s) from %s:%d", master->wscType == STsoap ? "SOAP" : "HTTP",master->service.str(), url.host.str(), url.port);
+                    master->logctx.CTXLOG("%sCALL: received response (%s) from %s:%d", master->wscType == STsoap ? "SOAP" : "HTTP",master->service.str(), url.host.str(), url.port);
 
                 if (rval != 200)
                 {

dali/base/dadfs.cpp

@@ -10103,12 +10103,12 @@ void initClusterAndStoragePlaneGroups(bool force, IPropertyTree *oldEnvironment,
     StringBuffer response;
     init.constructGroups(force, response, oldEnvironment);
     if (response.length())
-        PROGLOG("DFS group initialization : %s", response.str()); // should this be a syslog?
+        MLOG("DFS group initialization : %s", response.str()); // should this be a syslog?
 
     response.clear();
     init.constructStorageGroups(false, response);
     if (response.length())
-        PROGLOG("StoragePlane group initialization : %s", response.str()); // should this be a syslog?
+        MLOG("StoragePlane group initialization : %s", response.str()); // should this be a syslog?
 }
 
 bool resetClusterGroup(const char *clusterName, const char *type, bool spares, StringBuffer &response, unsigned timems)

dali/sasha/sacoalescer.cpp

@@ -86,7 +86,7 @@ void coalesceDatastore(bool force)
             iStoreHelper->getCurrentStoreFilename(storeFilename);
             StringBuffer memStr;
             getSystemTraceInfo(memStr.clear());
-            PROGLOG("COALESCE: %s", memStr.str());
+            MLOG("COALESCE: %s", memStr.str());
             Owned<IPropertyTree> _root;
             OwnedIFile storeIFile = createIFile(storeFilename.str());
             if (storeIFile->exists())
@@ -108,7 +108,7 @@ void coalesceDatastore(bool force)
             }
             IPropertyTree *root = _root.get();
             getSystemTraceInfo(memStr.clear());
-            PROGLOG("COALESCE: %s", memStr.str());
+            MLOG("COALESCE: %s", memStr.str());
 
             PROGLOG("COALESCER: coalesce started");
             if (baseEdition != iStoreHelper->queryCurrentEdition())
@@ -149,12 +149,12 @@ void coalesceDatastore(bool force)
             else
             {
                 getSystemTraceInfo(memStr.clear());
-                PROGLOG("COALESCE: %s", memStr.str());
+                MLOG("COALESCE: %s", memStr.str());
                 PROGLOG("Clearing old store...");
                 _root.clear();
                 PROGLOG("old store cleared");
                 getSystemTraceInfo(memStr.clear());
-                PROGLOG("COALESCE: %s", memStr.str());
+                MLOG("COALESCE: %s", memStr.str());
             }
             break;
         }

system/jlib/jdebug.cpp

@@ -2894,11 +2894,13 @@ public:
                 udpStats.reportUdpInfo(0);
             }
             if(traceMode&&str.length()) {
-                LOG(MCdebugInfo, unknownJob, "SYS: %s", str.str());
+                MLOG(MCdebugInfo, unknownJob, "SYS: %s", str.str());
 #ifndef _WIN32
-                if (traceMode&PerfMonExtended) {
+                if (traceMode&PerfMonExtended)
+                {
                     if (extstats.getLine(str.clear()))
-                        LOG(MCdebugInfo, unknownJob, "%s", str.str());
+                        MLOG(MCdebugInfo, "%s", str.str());
+
                     {
                         CriticalBlock block(sect);
                         extstats.printKLog(hook);
@@ -3315,7 +3317,7 @@ void PrintMemoryReport(bool full)
 {
     StringBuffer s;
     getSystemTraceInfo(s,PerfMonProcMem);
-    PROGLOG("%s",s.str());
+    MLOG("%s",s.str());
 }
 
 #else
@@ -3356,7 +3358,7 @@ void PrintMemoryReport(bool full)
         try {
             StringBuffer s;
             getSystemTraceInfo(s,PerfMonProcMem);
-            PROGLOG("%s",s.str());
+            MLOG("%s",s.str());
             PROGLOG("===============================================================");
         }
         catch (IException *e) {

system/jlib/jlog.cpp

@@ -1289,6 +1289,16 @@ void LogMsgComponentReporter::report(const LogMsg & msg)
     queryLogMsgManager()->report(msg);
 }
 
+void LogMsgComponentReporter::mreport_direct(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg)
+{
+    queryLogMsgManager()->mreport_direct(component, cat, job, msg);
+}
+
+void LogMsgComponentReporter::mreport_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args)
+{
+    queryLogMsgManager()->mreport_va(component, cat, job, format, args);
+}
+
 // LogMsgPrepender
 
 void LogMsgPrepender::report(const LogMsgCategory & cat, const char * format, ...)
@@ -1598,6 +1608,55 @@ void CLogMsgManager::report_va(const LogMsgCategory & cat, LogMsgCode code, cons
     pushMsg(new LogMsg(cat, getNextID(), unknownJob, code, format, args, 0, port, session));
 }
 
+void CLogMsgManager::mreport_direct(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg)
+{
+    if(rejectsCategory(cat)) return;
+    const char *cursor = msg;
+    const char *lineStart = cursor;
+    while (true)
+    {
+        switch (*cursor)
+        {
+            case '\0':
+                pushMsg(new LogMsg(cat, getNextID(), job, NoLogMsgCode, (int)(cursor-lineStart), lineStart, compo, port, session));
+                return;
+            case '\r':
+                // NB: \r or \r\n translated into newline
+                pushMsg(new LogMsg(cat, getNextID(), job, NoLogMsgCode, (int)(cursor-lineStart), lineStart, compo, port, session));
+                if ('\n' == *(cursor+1))
+                    cursor++;
+                lineStart = cursor+1;
+                break;
+            case '\n':
+                pushMsg(new LogMsg(cat, getNextID(), job, NoLogMsgCode, (int)(cursor-lineStart), lineStart, compo, port, session));
+                lineStart = cursor+1;
+                break;
+        }
+        ++cursor;
+    }
+}
+
+void CLogMsgManager::mreport_direct(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg)
+{
+    mreport_direct(0, cat, job, msg);
+}
+
+void CLogMsgManager::mreport_va(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args)
+{
+    if(rejectsCategory(cat)) return;
+    StringBuffer log;
+    log.limited_valist_appendf(1024*1024, format, args);
+    mreport_direct(compo, cat, job, log);
+}
+
+void CLogMsgManager::mreport_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args)
+{
+    if(rejectsCategory(cat)) return;
+    StringBuffer log;
+    log.limited_valist_appendf(1024*1024, format, args);
+    mreport_direct(cat, job, log);
+}
+
 void CLogMsgManager::report(const LogMsgCategory & cat, const IException * exception, const char * prefix)
 {
     if(rejectsCategory(cat)) return;
@@ -2725,6 +2784,39 @@ void IContextLogger::CTXLOG(const char *format, ...) const
     va_end(args);
 }
 
+void IContextLogger::mCTXLOG(const char *format, ...) const
+{
+    va_list args;
+    va_start(args, format);
+    StringBuffer log;
+    log.limited_valist_appendf(1024*1024, format, args);
+    va_end(args);
+
+    const char *cursor = log;
+    const char *lineStart = cursor;
+    while (true)
+    {
+        switch (*cursor)
+        {
+            case '\0':
+                CTXLOG("%.*s", (int)(cursor-lineStart), lineStart);
+                return;
+            case '\r':
+                // NB: \r or \r\n translated into newline
+                CTXLOG("%.*s", (int)(cursor-lineStart), lineStart);
+                if ('\n' == *(cursor+1))
+                    cursor++;
+                lineStart = cursor+1;
+                break;
+            case '\n':
+                CTXLOG("%.*s", (int)(cursor-lineStart), lineStart);
+                lineStart = cursor+1;
+                break;
+        }
+        ++cursor;
+    }
+}
+
 void IContextLogger::logOperatorException(IException *E, const char *file, unsigned line, const char *format, ...) const
 {
     va_list args;

system/jlib/jlog.hpp

@@ -559,6 +559,7 @@ class jlib_decl LogMsg : public CInterface
 public:
     LogMsg() : category(), sysInfo(), jobInfo(), remoteFlag(false) {}
     LogMsg(const LogMsgCategory & _cat, LogMsgId _id, const LogMsgJobInfo & _jobInfo, LogMsgCode _code, const char * _text, unsigned _compo, unsigned port, LogMsgSessionId session) : category(_cat), sysInfo(_id, port, session), jobInfo(_jobInfo), msgCode(_code), component(_compo), remoteFlag(false) { text.append(_text); }
+    LogMsg(const LogMsgCategory & _cat, LogMsgId _id, const LogMsgJobInfo & _jobInfo, LogMsgCode _code, size32_t sz, const char * _text, unsigned _compo, unsigned port, LogMsgSessionId session) : category(_cat), sysInfo(_id, port, session), jobInfo(_jobInfo), msgCode(_code), component(_compo), remoteFlag(false) { text.append(sz, _text); }
     LogMsg(const LogMsgCategory & _cat, LogMsgId _id, const LogMsgJobInfo & _jobInfo, LogMsgCode _code, const char * format, va_list args,
            unsigned _compo, unsigned port, LogMsgSessionId session)  __attribute__((format(printf,6, 0)))
     : category(_cat), sysInfo(_id, port, session), jobInfo(_jobInfo), msgCode(_code), component(_compo), remoteFlag(false) { text.valist_appendf(format, args); }
@@ -702,6 +703,10 @@ interface jlib_decl ILogMsgManager : public ILogMsgListener
     virtual void              report(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code , const char * format, ...) __attribute__((format(printf, 6, 7))) = 0;
     virtual void              report_va(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code , const char * format, va_list args) = 0;
     virtual void              report(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const IException * e, const char * prefix = NULL) = 0;
+    virtual void              mreport_direct(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg) = 0;
+    virtual void              mreport_direct(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg) = 0;
+    virtual void              mreport_va(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args) = 0;
+    virtual void              mreport_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args) = 0;
     virtual void              report(const LogMsg & msg) const = 0;
     virtual LogMsgId          getNextID() = 0;
     virtual bool              rejectsCategory(const LogMsgCategory & cat) const = 0;
@@ -727,6 +732,8 @@ public:
     void                  report_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, LogMsgCode code, const char * format, va_list args);
     void                  report(const LogMsgCategory & cat, const LogMsgJobInfo & job, const IException * e, const char * prefix = NULL);
     void                  report(const LogMsg & msg);
+    void                  mreport_direct(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg);
+    void                  mreport_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args);
 private:
     unsigned                  component;
 };
@@ -1060,6 +1067,36 @@ inline void PROGLOG(const char * format, ...)
     va_end(args);
 }
 
+inline void MLOG(const LogMsgCategory & cat, const char * msg)
+{
+    LOGMSGREPORTER->mreport_direct(cat, unknownJob, msg);
+}
+
+inline void MLOG(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, ...)
+{
+    va_list args;
+    va_start(args, format);
+    LOGMSGREPORTER->mreport_va(cat, job, format, args);
+    va_end(args);
+}
+
+inline void MLOG(const LogMsgCategory & cat, const char * format, ...)
+{
+    va_list args;
+    va_start(args, format);
+    LOGMSGREPORTER->mreport_va(cat, unknownJob, format, args);
+    va_end(args);
+}
+
+inline void MLOG(const char * format, ...) __attribute__((format(printf, 1, 2)));
+inline void MLOG(const char * format, ...)
+{
+    va_list args;
+    va_start(args, format);
+    LOGMSGREPORTER->mreport_va(MCuserProgress, unknownJob, format, args);
+    va_end(args);
+}
+
 inline void DBGLOG(LogMsgCode code, char const * format, ...) __attribute__((format(printf, 2, 3)));
 inline void DBGLOG(LogMsgCode code, char const * format, ...)
 {
@@ -1219,6 +1256,7 @@ extern jlib_decl void AuditSystemAccess(const char *userid, bool success, char c
 interface jlib_decl IContextLogger : extends IInterface
 {
     void CTXLOG(const char *format, ...) const  __attribute__((format(printf, 2, 3)));
+    void mCTXLOG(const char *format, ...) const  __attribute__((format(printf, 2, 3)));
     virtual void CTXLOGva(const char *format, va_list args) const __attribute__((format(printf,2,0))) = 0;
     void logOperatorException(IException *E, const char *file, unsigned line, const char *format, ...) const  __attribute__((format(printf, 5, 6)));
     virtual void logOperatorExceptionVA(IException *E, const char *file, unsigned line, const char *format, va_list args) const __attribute__((format(printf,5,0))) = 0;

system/jlib/jlog.ipp

@@ -757,6 +757,10 @@ public:
     bool                      flushQueue(unsigned timeout) { if(processor) return processor->flush(timeout); else return true; }
     void                      report(const LogMsgCategory & cat, const char * format, ...) __attribute__((format(printf,3,4)));
     void                      report_va(const LogMsgCategory & cat, const char * format, va_list args) __attribute__((format(printf,3,0)));
+    void                      mreport_direct(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg);
+    void                      mreport_direct(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * msg);
+    void                      mreport_va(unsigned compo, const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args);
+    void                      mreport_va(const LogMsgCategory & cat, const LogMsgJobInfo & job, const char * format, va_list args) __attribute__((format(printf,4,0)));
     void                      report(const LogMsgCategory & cat, LogMsgCode code, const char * format, ...) __attribute__((format(printf,4,5)));
     void                      report_va(const LogMsgCategory & cat, LogMsgCode code, const char * format, va_list args) __attribute__((format(printf,4,0)));
     void                      report(const LogMsgCategory & cat, const IException * e, const char * prefix = NULL);

thorlcr/graph/thgraph.cpp

@@ -1376,7 +1376,7 @@ void CGraphBase::executeSubGraph(size32_t parentExtractSz, const byte *parentExt
             {
                 StringBuffer s;
                 toXML(&queryXGMML(), s, 2);
-                LOG(MCthorDetailedDebugInfo, thorJob, "Running graph [%s] : %s", isGlobal()?"global":"local", s.str());
+                MLOG(MCthorDetailedDebugInfo, thorJob, "Running graph [%s] : %s", isGlobal()?"global":"local", s.str());
             }
         }
         if (localResults)

thorlcr/graph/thgraphslave.cpp

@@ -1750,7 +1750,7 @@ void CJobSlave::reportGraphEnd(graph_id gid)
         getSocketStatistics(stats);
         StringBuffer s;
         getSocketStatisticsString(stats,s);
-        LOG(MCthorDetailedDebugInfo, thorJob, "Graph[%" GIDPF "u] - Socket statistics : %s\n", gid, s.str());
+        MLOG(MCthorDetailedDebugInfo, thorJob, "Graph[%" GIDPF "u] - Socket statistics : %s\n", gid, s.str());
     }
     resetSocketStatistics();
 }