Repository: trafodion Updated Branches: refs/heads/master 9d88d0810 -> 86c2284f6
[TRAFODION-2927] Refactor and improve UPDATE STATISTICS logging Project: http://git-wip-us.apache.org/repos/asf/trafodion/repo Commit: http://git-wip-us.apache.org/repos/asf/trafodion/commit/f473c0cd Tree: http://git-wip-us.apache.org/repos/asf/trafodion/tree/f473c0cd Diff: http://git-wip-us.apache.org/repos/asf/trafodion/diff/f473c0cd Branch: refs/heads/master Commit: f473c0cd5a1d895dd8a40d2ce2ec24c12a5b076d Parents: 47713b9 Author: Dave Birdsall <[email protected]> Authored: Thu Feb 1 00:37:49 2018 +0000 Committer: Dave Birdsall <[email protected]> Committed: Thu Feb 1 00:37:49 2018 +0000 ---------------------------------------------------------------------- core/sqf/commonLogger/CommonLogger.cpp | 8 +- core/sqf/commonLogger/CommonLogger.h | 8 +- core/sql/qmscommon/QRLogger.cpp | 97 ++++++++-- core/sql/qmscommon/QRLogger.h | 18 +- core/sql/regress/compGeneral/EXPECTED023 | 54 +++--- core/sql/regress/compGeneral/TEST023 | 4 + core/sql/sqlcomp/DefaultConstants.h | 1 + core/sql/sqlcomp/nadefaults.cpp | 4 + core/sql/ustat/hs_globals.cpp | 30 +-- core/sql/ustat/hs_lex.ll | 4 + core/sql/ustat/hs_log.cpp | 261 ++++++++++++++------------ core/sql/ustat/hs_log.h | 25 ++- core/sql/ustat/hs_update.cpp | 11 +- core/sql/ustat/hs_yacc.y | 17 +- 14 files changed, 336 insertions(+), 206 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sqf/commonLogger/CommonLogger.cpp ---------------------------------------------------------------------- diff --git a/core/sqf/commonLogger/CommonLogger.cpp b/core/sqf/commonLogger/CommonLogger.cpp index b49623a..68e1eab 100644 --- a/core/sqf/commonLogger/CommonLogger.cpp +++ b/core/sqf/commonLogger/CommonLogger.cpp @@ -114,7 +114,7 @@ CommonLogger& CommonLogger::instance() // This method should be used when the work of producing the logging text // is expensive, such as a join graph or an extensive dump. // ************************************************************************** -bool CommonLogger::isCategoryInDebug(std::string &cat) +bool CommonLogger::isCategoryInDebug(const std::string &cat) { bool result = false; log4cxx::LoggerPtr myLogger(log4cxx::Logger::getLogger(cat)); @@ -133,7 +133,7 @@ bool CommonLogger::isCategoryInDebug(std::string &cat) // ************************************************************************** // The generic message logging method for any message type and length. // ************************************************************************** -void CommonLogger::log1(std::string &cat, +void CommonLogger::log1(const std::string &cat, logLevel level, const char* cmsg, unsigned int eventId) @@ -177,7 +177,7 @@ void CommonLogger::log1(std::string &cat, } } -char* CommonLogger::buildMsgBuffer(std::string &cat, +char* CommonLogger::buildMsgBuffer(const std::string &cat, logLevel level, const char* logMsgTemplate, va_list args) @@ -249,7 +249,7 @@ char* CommonLogger::buildMsgBuffer(std::string &cat, // ************************************************************************** // The generic message logging method for any message type and length. // ************************************************************************** -void CommonLogger::log(std::string &cat, +void CommonLogger::log(const std::string &cat, logLevel level, const char* logMsgTemplate...) { http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sqf/commonLogger/CommonLogger.h ---------------------------------------------------------------------- diff --git a/core/sqf/commonLogger/CommonLogger.h b/core/sqf/commonLogger/CommonLogger.h index 75ca87d..dadec8d 100644 --- a/core/sqf/commonLogger/CommonLogger.h +++ b/core/sqf/commonLogger/CommonLogger.h @@ -104,12 +104,12 @@ public: * message template. */ - static void log1(std::string &cat, + static void log1(const std::string &cat, logLevel level, const char* cmsg, unsigned int eventId = 0); - static void log(std::string &cat, + static void log(const std::string &cat, logLevel level, const char* logMsgTemplate ...); @@ -120,11 +120,11 @@ public: * @param cat The name of the category to check. * @return TRUE if DEBUG messages are logged. */ - static bool isCategoryInDebug(std::string &cat); + static bool isCategoryInDebug(const std::string &cat); protected: - static char* buildMsgBuffer(std::string &cat, + static char* buildMsgBuffer(const std::string &cat, logLevel level, const char* logMsgTemplate, va_list args); http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/qmscommon/QRLogger.cpp ---------------------------------------------------------------------- diff --git a/core/sql/qmscommon/QRLogger.cpp b/core/sql/qmscommon/QRLogger.cpp index f4fb75d..b300c23 100644 --- a/core/sql/qmscommon/QRLogger.cpp +++ b/core/sql/qmscommon/QRLogger.cpp @@ -21,6 +21,7 @@ // @@@ END COPYRIGHT @@@ // ********************************************************************** +#include <log4cxx/fileappender.h> #include <log4cxx/rollingfileappender.h> #include <log4cxx/patternlayout.h> #include <log4cxx/propertyconfigurator.h> @@ -54,6 +55,7 @@ std::string CAT_SQL_SSMP = "SQL.SSMP"; std::string CAT_SQL_SSCP = "SQL.SSCP"; std::string CAT_SQL_UDR = "SQL.UDR"; std::string CAT_SQL_PRIVMGR = "SQL.PRIVMGR"; +std::string CAT_SQL_USTAT = "SQL.USTAT"; // hdfs std::string CAT_SQL_HDFS_JNI_TOP = "SQL.HDFS.JniTop"; std::string CAT_SQL_HDFS_SEQ_FILE_READER = "SQL.HDFS.SeqFileReader"; @@ -213,15 +215,6 @@ NABoolean QRLogger::initLog4cxx(const char* configFileName) return FALSE; } -// ************************************************************************** -// ************************************************************************** -void QRLogger::initCategory(std::string &cat, log4cxx::LevelPtr defaultPriority) -{ - log4cxx::LoggerPtr myLogger(log4cxx::Logger::getLogger(cat)); - myLogger->addAppender(fileAppender_); - myLogger->setLevel(defaultPriority); -} - std::string &QRLogger::getMyDefaultCat() { @@ -504,7 +497,7 @@ CommonTracer::~CommonTracer() } } -void QRLogger::log(std::string &cat, +void QRLogger::log(const std::string &cat, logLevel level, int sqlCode, const char *queryId, @@ -556,7 +549,7 @@ void QRLogger::log(std::string &cat, va_end(args); } -void QRLogger::log(std::string &cat, +void QRLogger::log(const std::string &cat, logLevel level, const char *logMsgTemplate...) { @@ -608,3 +601,85 @@ NABoolean QRLogger::initLog4cxx(ExecutableModule module) } +NABoolean QRLogger::startLogFile(const std::string &cat, const char * logFileName) +{ + NABoolean retcode = TRUE; // assume success + try + { + log4cxx::LoggerPtr logger(Logger::getLogger(cat)); + logger->setAdditivity(false); // make this logger non-additive + log4cxx::PatternLayout * layout = new PatternLayout("%m%n"); // want just the message text + log4cxx::LogString fileName(logFileName); + log4cxx::FileAppenderPtr fap(new FileAppender(layout,fileName,false /* no append */)); + + logger->addAppender(fap); + } + catch (...) + { + retcode = FALSE; + } + + return retcode; +} + +NABoolean QRLogger::stopLogFile(const std::string &cat) +{ + NABoolean retcode = TRUE; // assume success + try + { + log4cxx::LoggerPtr logger(Logger::getLogger(cat)); + logger->removeAllAppenders(); + } + catch (...) + { + retcode = FALSE; + } + + return retcode; +} + +NABoolean QRLogger::getRootLogDirectory(const std::string &cat, std::string &out) +{ + NABoolean retcode = TRUE; // assume success + + out.clear(); + + // strip off all but the first qualifier of the category name + + size_t firstDot = cat.find_first_of('.'); + std::string firstQualifier; + if (firstDot == std::string::npos) + firstQualifier = cat; // no dot, use the whole thing + else + firstQualifier = cat.substr(0,firstDot); + + try + { + log4cxx::LoggerPtr logger(Logger::getLogger(firstQualifier)); + log4cxx::AppenderList appenderList = logger->getAllAppenders(); + for (size_t i = 0; i < appenderList.size(); i++) + { + log4cxx::AppenderPtr appender = appenderList[i]; + log4cxx::LogString appenderName = appender->getName(); + log4cxx::Appender * appenderP = appender; + log4cxx::FileAppender * fileAppender = dynamic_cast<FileAppender *>(appenderP); + if (fileAppender) + { + log4cxx::LogString logFileName = fileAppender->getFile(); + out = logFileName.data(); + size_t lastSlash = out.find_last_of('/'); + if (lastSlash != std::string::npos) + out = out.substr(0,lastSlash); + return TRUE; + } + } + } + catch (...) + { + retcode = FALSE; + } + + return retcode; +} + + http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/qmscommon/QRLogger.h ---------------------------------------------------------------------- diff --git a/core/sql/qmscommon/QRLogger.h b/core/sql/qmscommon/QRLogger.h index 5cabac4..93fdc86 100644 --- a/core/sql/qmscommon/QRLogger.h +++ b/core/sql/qmscommon/QRLogger.h @@ -60,6 +60,7 @@ extern std::string CAT_SQL_COMP; extern std::string CAT_SQL_ESP; extern std::string CAT_SQL_SSCP; extern std::string CAT_SQL_PRIVMGR; +extern std::string CAT_SQL_USTAT; // HDFS extern std::string CAT_SQL_HDFS_JNI_TOP; @@ -211,10 +212,10 @@ public: const char* getMyProcessInfo(); // overrides the method in CommonLogger so process information can be added - static void log(std::string &cat, + static void log(const std::string &cat, logLevel level, const char* logMsgTemplate ...); - static void log(std::string &cat, + static void log(const std::string &cat, logLevel level, int sqlCode, const char* queryId, @@ -262,9 +263,15 @@ public: static NABoolean initLog4cxx(ExecutableModule module); -protected: + // Methods for use by components that wish to manage logs for their + // own debugging purposes. The log layout includes just the text + // the component generates and not the usual log header text. - void initCategory(std::string &cat, log4cxx::LevelPtr defaultPriority); + static NABoolean startLogFile(const std::string &cat, const char * logFileName); + + static NABoolean stopLogFile(const std::string &cat); + + static NABoolean getRootLogDirectory(const std::string &cat, std::string &out); private: /** @@ -280,9 +287,6 @@ private: private: - /** The appender. */ - log4cxx::Appender *fileAppender_; - /** Is this QMS, QMM, QMP or MXCMP? */ ExecutableModule module_; http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/regress/compGeneral/EXPECTED023 ---------------------------------------------------------------------- diff --git a/core/sql/regress/compGeneral/EXPECTED023 b/core/sql/regress/compGeneral/EXPECTED023 index 03beacb..8a46e13 100644 --- a/core/sql/regress/compGeneral/EXPECTED023 +++ b/core/sql/regress/compGeneral/EXPECTED023 @@ -1,3 +1,9 @@ +>> +>>-- keep ULOGs whenever there are severe errors +>>update statistics log system; + +--- SQL operation complete. +>> >>-- create the database used for the tests >> >>create schema compgeneral_test023; @@ -125,7 +131,7 @@ STEST_EMPTY OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280032_959042 M +STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441663_444545 M --- 1 row(s) selected. >>-- should see one row @@ -141,7 +147,7 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280032_959042 +TRAF_SAMPLE_07158060726899021395_1517441663_444545 --- SQL operation complete. >> -- should be stest, stest_empty, stestc, sb_* tables + a sample table @@ -165,7 +171,7 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280079_749188 +TRAF_SAMPLE_07158060726899021395_1517441711_141471 --- SQL operation complete. >> -- should be stest, stest_empty, stestc, sb_* tables + a different sample >> table @@ -175,7 +181,7 @@ TRAF_SAMPLE_05715215834648412060_1513280079_749188 OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280079_749188 M +STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441711_141471 M --- 1 row(s) selected. >>-- should see one row @@ -222,7 +228,7 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280122_597819 +TRAF_SAMPLE_07158060726899021395_1517441748_979037 --- SQL operation complete. >> -- should be stest, stest_empty, stestc, sb_* tables + another sample table @@ -232,7 +238,7 @@ TRAF_SAMPLE_05715215834648412060_1513280122_597819 OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280122_597819 I +STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441748_979037 I --- 1 row(s) selected. >>-- should see one row @@ -256,7 +262,7 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 --- SQL operation complete. >> -- should be stest, stest_empty, stestc, sb_* tables + another sample table @@ -266,7 +272,7 @@ TRAF_SAMPLE_05715215834648412060_1513280167_871663 OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280167_871663 I +STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441802_045572 I --- 1 row(s) selected. >>-- should see one row @@ -327,7 +333,7 @@ STEST OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280167_871663 I c1 >= 100000 +STEST TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441802_045572 I c1 >= 100000 --- 1 row(s) selected. >> @@ -384,8 +390,8 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 -TRAF_SAMPLE_05715215834648413689_1513280221_712692 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 +TRAF_SAMPLE_07158060726899023220_1517441862_582002 --- SQL operation complete. >> @@ -394,7 +400,7 @@ TRAF_SAMPLE_05715215834648413689_1513280221_712692 OBJECT_NAME SAMPLE_NAME REASON LAST_WHERE_PREDICATE ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- -STESTC TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648413689_1513280221_712692 I c1 >= 'naaaa' +STESTC TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899023220_1517441862_582002 I c1 >= 'naaaa' --- 1 row(s) selected. >> @@ -419,8 +425,8 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 -TRAF_SAMPLE_05715215834648413689_1513280221_712692 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 +TRAF_SAMPLE_07158060726899023220_1517441862_582002 --- SQL operation complete. >> -- should be the same as previous "get tables" @@ -447,8 +453,8 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 -TRAF_SAMPLE_05715215834648413689_1513280221_712692 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 +TRAF_SAMPLE_07158060726899023220_1517441862_582002 --- SQL operation complete. >> -- should be the same as previous "get tables" @@ -476,8 +482,8 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 -TRAF_SAMPLE_05715215834648413689_1513280221_712692 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 +TRAF_SAMPLE_07158060726899023220_1517441862_582002 --- SQL operation complete. >> -- should be the same as previous "get tables" @@ -488,8 +494,8 @@ TRAF_SAMPLE_05715215834648413689_1513280221_712692 *** ERROR[9219] Incremental UPDATE STATISTICS: An operation failed, possibly due to an invalid WHERE clause. *** ERROR[15001] A syntax error occurred at or before: -DELETE WITH NO ROLLBACK FROM TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215 -834648412060_1513280167_871663 WHERE 1; +DELETE WITH NO ROLLBACK FROM TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060 +726899021395_1517441802_045572 WHERE 1; ^ (119 characters from start of SQL statement) *** ERROR[8822] The statement was not prepared. @@ -507,8 +513,8 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 -TRAF_SAMPLE_05715215834648413689_1513280221_712692 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 +TRAF_SAMPLE_07158060726899023220_1517441862_582002 --- SQL operation complete. >> -- should be the same as previous "get tables" @@ -518,7 +524,7 @@ TRAF_SAMPLE_05715215834648413689_1513280221_712692 *** ERROR[9219] Incremental UPDATE STATISTICS: An operation failed, possibly due to an invalid WHERE clause. -*** ERROR[4001] Column BADCOL is not found. Tables in scope: TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_05715215834648412060_1513280167_871663. Default schema: TRAFODION.SCH. +*** ERROR[4001] Column BADCOL is not found. Tables in scope: TRAFODION.COMPGENERAL_TEST023.TRAF_SAMPLE_07158060726899021395_1517441802_045572. Default schema: TRAFODION.SCH. *** ERROR[8822] The statement was not prepared. @@ -559,7 +565,7 @@ SB_PERSISTENT_SAMPLES STEST STESTC STEST_EMPTY -TRAF_SAMPLE_05715215834648412060_1513280167_871663 +TRAF_SAMPLE_07158060726899021395_1517441802_045572 --- SQL operation complete. >> -- should be the same as previous "get tables" except only one sample table http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/regress/compGeneral/TEST023 ---------------------------------------------------------------------- diff --git a/core/sql/regress/compGeneral/TEST023 b/core/sql/regress/compGeneral/TEST023 index 1a81ebb..c55eeec 100755 --- a/core/sql/regress/compGeneral/TEST023 +++ b/core/sql/regress/compGeneral/TEST023 @@ -31,6 +31,10 @@ drop schema compgeneral_test023 cascade; ?section create_db log LOG023 clear; + +-- keep ULOGs whenever there are severe errors +update statistics log system; + -- create the database used for the tests create schema compgeneral_test023; http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/sqlcomp/DefaultConstants.h ---------------------------------------------------------------------- diff --git a/core/sql/sqlcomp/DefaultConstants.h b/core/sql/sqlcomp/DefaultConstants.h index b7e4d0d..a3809f5 100644 --- a/core/sql/sqlcomp/DefaultConstants.h +++ b/core/sql/sqlcomp/DefaultConstants.h @@ -507,6 +507,7 @@ enum DefaultConstants USTAT_ADD_SALTED_KEY_PREFIXES_FOR_MC, // Generate MCs for primary key prefixes as well as full key of // salted table when ON EVERY KEY or ON EVERY COLUMN is specified. USTAT_ATTEMPT_ESP_PARALLELISM, // use parallel plans for reading columns to form histograms + USTAT_AUTOMATIC_LOGGING, // If ON, gives same semantics as UPDATE STATISTICS LOG SYSTEM USTAT_COMPACT_VARCHARS, // For internal sort, store only the actual # chars used in each value USTAT_DELETE_NO_ROLLBACK, // If ON, use DELETE WITH NO ROLLBACK in incremental stats when updating sample table USTAT_ESTIMATE_HBASE_ROW_COUNT, // If ON, estimate row count of HBase table instead of count(*), subject http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/sqlcomp/nadefaults.cpp ---------------------------------------------------------------------- diff --git a/core/sql/sqlcomp/nadefaults.cpp b/core/sql/sqlcomp/nadefaults.cpp index ea2d8d4..bd948a9 100644 --- a/core/sql/sqlcomp/nadefaults.cpp +++ b/core/sql/sqlcomp/nadefaults.cpp @@ -3046,6 +3046,10 @@ XDDkwd__(SUBQUERY_UNNESTING, "ON"), DDkwd__(USTAT_ADD_SALTED_KEY_PREFIXES_FOR_MC, "ON"), // When ON, generate MCs for primary key prefixes as well as full key // of salted table when ON EVERY KEY or ON EVERY COLUMN is specified. DDkwd__(USTAT_ATTEMPT_ESP_PARALLELISM, "ON"), // for reading column values + DDkwd__(USTAT_AUTOMATIC_LOGGING, "OFF"), // OFF gives same semantics as + // UPDATE STATISTICS LOG OFF, while + // ON gives same semantics as + // UPDATE STATISTICS LOG SYSTEM DDui___(USTAT_AUTOMATION_INTERVAL, "0"), DDkwd__(USTAT_AUTO_EMPTYHIST_TWO_TRANS, "OFF"), // When ON empty hist insert will be 2 trans. DDkwd__(USTAT_AUTO_FOR_VOLATILE_TABLES, "OFF"), // Toggle for vol tbl histogram usage http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_globals.cpp ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_globals.cpp b/core/sql/ustat/hs_globals.cpp index bb764b2..c183b01 100644 --- a/core/sql/ustat/hs_globals.cpp +++ b/core/sql/ustat/hs_globals.cpp @@ -3847,34 +3847,8 @@ void HSGlobalsClass::startJitLogging(const char* checkPointName, Int64 elapsedSe { HSLogMan *LM = HSLogMan::Instance(); - - - - // Construct logfile name incorporating process id and node number. Note that - // the 2nd parameter of processhandle_decompose is named cpu but is actually - // the node number for Seaquest (the 4th param, named nodenumber, is the cluster - // number). - Int32 nodeNum; - Int32 pin; - SB_Phandle_Type procHandle; - XPROCESSHANDLE_GETMINE_(&procHandle); - XPROCESSHANDLE_DECOMPOSE_(&procHandle, &nodeNum, &pin); - - NAString filePath; - char* sqroot = getenv("TRAF_HOME"); - if (sqroot) - { - filePath = sqroot; - filePath.append("/logs/"); - } - - const size_t MAX_FILENAME_SIZE = 50; - char fileName[MAX_FILENAME_SIZE]; - sprintf(fileName, "ULOG.%d.%d.txt", nodeNum, pin); - filePath.append(fileName); - - // Turn logging on using the filepath we just created. - LM->StartLog(TRUE, filePath.data()); + // Turn logging on + LM->StartLog(TRUE); jitLogOn = TRUE; // Write introductory information to log; name of table and columns being http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_lex.ll ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_lex.ll b/core/sql/ustat/hs_lex.ll index 89cd265..43634bb 100644 --- a/core/sql/ustat/hs_lex.ll +++ b/core/sql/ustat/hs_lex.ll @@ -315,6 +315,10 @@ CMNT_START "/*" return(NO); } +[Ss][Yy][Ss][Tt][Ee][Mm] { + return(SYSTEM); + } + {R_IDENTIFIER} { yylval->stringval = new(STMTHEAP) NAString(STMTHEAP); *yylval->stringval = yytext; http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_log.cpp ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_log.cpp b/core/sql/ustat/hs_log.cpp index 988b7c2..4519a82 100644 --- a/core/sql/ustat/hs_log.cpp +++ b/core/sql/ustat/hs_log.cpp @@ -58,6 +58,8 @@ #include "NAClusterInfo.h" +#include "QRLogger.h" + #define ULOG_PATH_WARN 2244 // ----------------------------------------------------------------------- @@ -166,6 +168,28 @@ void HSFuncMergeDiags( Lng32 sqlcode } +// ----------------------------------------------------------------------- +// Clean up log as determined by the current log settings +void HSCleanUpLog() +{ + HSLogMan *LM = HSLogMan::Instance(); + if (LM->GetLogSetting() == HSLogMan::SYSTEM) + { + NABoolean internalError = CmpCommon::diags()->contains(-UERR_INTERNAL_ERROR); + NABoolean dropError = CmpCommon::diags()->contains(-UERR_UNABLE_TO_DROP_OBJECT); + NABoolean descError = CmpCommon::diags()->contains(-UERR_UNABLE_TO_DESCRIBE_COLUMN_NAMES); + NABoolean createError = CmpCommon::diags()->contains(-UERR_UNABLE_TO_CREATE_OBJECT); + NABoolean internalError1 = CmpCommon::diags()->contains(-UERR_GENERIC_ERROR); + NABoolean bwError = CmpCommon::diags()->contains(-UERR_UNEXPECTED_BACKWARDS_DATA); + + if (internalError || dropError || descError || createError || + internalError1 || bwError) + LM->StopLog(); // stop logging but keep the log + else + LM->StopAndDeleteLog(); // stop logging and throw the log away + } +} + // ----------------------------------------------------------------------- // Log the location of error. @@ -249,11 +273,13 @@ void HSFuncLogError(Lng32 error, char *filename, Lng32 lineno) /*****************************************************************************/ THREAD_P HSLogMan* HSLogMan::instance_ = 0; HSLogMan::HSLogMan() -: currentTimingEvent_(-1), logNeeded_(FALSE) +: logSetting_(OFF), currentTimingEvent_(-1), logNeeded_(FALSE) { memset(startTime_, 0, MAX_TIMING_EVENTS*sizeof(Int64)); logFile_ = new (CTXTHEAP) NAString(); prevTime_.tv_sec = prevTime_.tv_usec = 0; + if (CmpCommon::getDefault(USTAT_AUTOMATIC_LOGGING) == DF_ON) + logSetting_ = SYSTEM; } /***********************************************/ @@ -281,95 +307,51 @@ void HSLogMan::Log(const char *data) { if (logNeeded_) { - ofstream fileout(logFile_->data(), ios::app); time_t currentTime = time(0); struct tm currentTimeExploded; localtime_r(¤tTime,¤tTimeExploded); char localTime[100]; // way more space than needed strftime(localTime,sizeof(localTime),"%c",¤tTimeExploded); - fileout << "[" << localTime << "] " << data << endl; + + NAString temp; + temp = "["; + temp += localTime; + temp += "] "; + temp += data; + // Note: LL_FATAL always logs. The format we use doesn't include + // the severity, so "FATAL" doesn't actually show up in ULOG data + QRLogger::log1(CAT_SQL_USTAT, LL_FATAL, temp.data()); // use log1 to avoid cpu, process etc. prefix } } -// ----------------------------------------------------------------------- -// Check whether the dir containing ULOG file exists, -// making sure ULOG can be created in it later. -// ----------------------------------------------------------------------- -NABoolean HSLogMan::ContainDirExist(const char* path) -{ - CMPASSERT(strlen(path)>0); - struct stat sb; - NAString containDir = path; - Int32 pos = containDir.last('/'); - if(-1 == pos) - return TRUE; - containDir = containDir.remove(pos); - Int32 rVal = stat(containDir.data(), &sb); - - NABoolean dirExist = rVal != -1 && S_ISDIR(sb.st_mode); - - if(!dirExist) - { - char buf[256]; - snprintf(buf, sizeof(buf), "Directory %s does not exist", containDir.data()); - *CmpCommon::diags() << DgSqlCode(ULOG_PATH_WARN) << DgString0(buf); - } - //contain dir exist but not accessible - if(dirExist&& - (!((sb.st_mode & S_IRWXU)&S_IXUSR) - ||!((sb.st_mode & S_IRWXU)&S_IRUSR) - ||!((sb.st_mode & S_IRWXU)&S_IWUSR))) - { - char buf[256]; - snprintf(buf, sizeof(buf), "Directory %s Permission denied", containDir.data()); - *CmpCommon::diags() << DgSqlCode(ULOG_PATH_WARN) << DgString0(buf); - //return FALSE so we don't start logging - dirExist = FALSE; - } - - return dirExist; -} - -// ----------------------------------------------------------------------- -// @param: path(OUT), return changed real path on success. -// @param: cqd_valud(IN), filename set by CQD USTAT_LOG ... -// In situation of cluster: -// prefix $TAR_DOWNLOAD_ROOT to value of USTAT_LOG to form a safe log path, -// and change file name to filename.<tdm_arkcmp>.<NodeId>.<Hostname>.<pid>.log, -// e.g. USTAT_LOG="ULOG", real path will be $TAR_DOWNLOAD_ROOT/ULOG.<tdm_arkcmp>.<NodeId>.<Hostname>.<pid>.log. -// For cqd_value, an absolute path is not allowd, and will return FALSE. -// ----------------------------------------------------------------------- -NABoolean HSLogMan::GetLogFile(NAString & path, const char* cqd_value) +// +// METHOD: SetLogSetting() +// PURPOSE: Change the current logging state +// INPUT: logSetting - Indicates the new logging state +// +void HSLogMan::SetLogSetting(LogSetting logSetting) { - CMPASSERT(strlen(cqd_value) > 0); - if('/' == cqd_value[0]) - {//Absolute path is not allowed on cluster. - *CmpCommon::diags() << DgSqlCode(ULOG_PATH_WARN) << DgString0("Absolute path is not allowed on cluster."); - return FALSE; - } - else if( getenv("TAR_DOWNLOAD_ROOT") ) - {// relative path - const size_t HOSTNAME_SIZE = 64; - char hostname[HOSTNAME_SIZE]; - Int32 nodeNum; - Int32 pin; - SB_Phandle_Type procHandle; - XPROCESSHANDLE_GETMINE_(&procHandle); - XPROCESSHANDLE_DECOMPOSE_(&procHandle, &nodeNum, &pin); - gethostname(hostname, sizeof(hostname)); - path = NAString(getenv("TAR_DOWNLOAD_ROOT")) + "/" + NAString(cqd_value) - + "." + "tdm_arkcmp" - + "." + LongToNAString((Lng32)nodeNum) - + "." + hostname - + "." + LongToNAString((Lng32)pin) - +".log"; - } - else - {//Environment variable $TAR_DOWNLOAD_ROOT not set - *CmpCommon::diags() << DgSqlCode(ULOG_PATH_WARN) << DgString0("Environment variable $TAR_DOWNLOAD_ROOT is not set on cluster."); - return FALSE; + switch (logSetting) + { + case ON: + StartLog(); + break; + case SYSTEM: + if (logSetting_ == ON) // if logging was ON + StopLog(); // stop existing log so it doesn't get deleted + StartLog(); + break; + case OFF: + if (logSetting_ == SYSTEM) // if logging was SYSTEM + StopAndDeleteLog(); // stop and delete log + else + StopLog(); + break; + default: + break; // should not occur; just ignore } - return TRUE; + + logSetting_ = logSetting; } /***********************************************/ @@ -389,44 +371,64 @@ NABoolean HSLogMan::GetLogFile(NAString & path, const char* cqd_value) /* until either StartLog() or */ /* ClearLog() methods are called. */ /***********************************************/ -void HSLogMan::StartLog(NABoolean needExplain, const char* logFileName) +void HSLogMan::StartLog(NABoolean needExplain) { - // The GENERATE_EXPLAIN cqd captures explain data pertaining to dynamic - // queries. Ordinarily we want it on, but for just-in-time logging triggered - // by an error, we don't need it, and can't set it because HSFuncExecQuery - // clears the diagnostics area, which causes the error to be lost. - explainOn_ = needExplain; - if (!needExplain || - HSFuncExecQuery("CONTROL QUERY DEFAULT GENERATE_EXPLAIN 'ON'") == 0) + if (!logNeeded_) // if logging isn't already on { - CollIndex activeNodes = gpClusterInfo->numOfSMPs(); - if (logFileName) - { - *logFile_ = logFileName; - currentTimingEvent_ = -1; - startTime_[0] = 0; /* reset timer */ - logNeeded_ = TRUE; - } - else if(activeNodes > 2) - {//we consider we are running on cluster - //if gpClusterInfo->numOfSMPs() > 2 - NABoolean ret = FALSE; - if(GetLogFile(*logFile_, ActiveSchemaDB()->getDefaults().getValue(USTAT_LOG))) - ret = ContainDirExist(logFile_->data()); - - if(ret) - logNeeded_ = TRUE; - - currentTimingEvent_ = -1; - startTime_[0] = 0; /* reset timer */ - } + // Construct logfile name incorporating process id and node number. Note that + // the 2nd parameter of processhandle_decompose is named cpu but is actually + // the node number for Seaquest (the 4th param, named nodenumber, is the cluster + // number). + Int32 nodeNum; + Int32 pin; + SB_Phandle_Type procHandle; + XPROCESSHANDLE_GETMINE_(&procHandle); + XPROCESSHANDLE_DECOMPOSE_(&procHandle, &nodeNum, &pin); + long currentTime = (long)time(0); + + const size_t MAX_FILENAME_SIZE = 50; + char qualifiers[MAX_FILENAME_SIZE]; + sprintf(qualifiers, ".%d.%d.%ld.txt", nodeNum, pin, currentTime); + + std::string logFileName; + QRLogger::getRootLogDirectory(CAT_SQL_USTAT, logFileName /* out */); + if (logFileName.size() > 0) + logFileName += '/'; + + const char * ustatLog = ActiveSchemaDB()->getDefaults().getValue(USTAT_LOG); + const char * fileNameStem = ustatLog + strlen(ustatLog); + if (ustatLog == fileNameStem) + fileNameStem = "ULOG"; // CQD USTAT_LOG is the empty string else - { - *logFile_ = ActiveSchemaDB()->getDefaults().getValue(USTAT_LOG); - currentTimingEvent_ = -1; - startTime_[0] = 0; /* reset timer */ - logNeeded_ = TRUE; - } + { + // strip off any directory path name; we will always use the logs directory + // as configured via QRLogger + while ((fileNameStem > ustatLog) && (*(fileNameStem - 1) != '/')) + fileNameStem--; + } + + logFileName += fileNameStem; + logFileName += qualifiers; + + NABoolean logStarted = QRLogger::startLogFile(CAT_SQL_USTAT,logFileName.c_str()); + if (logStarted) + { + *logFile_ = logFileName.c_str(); + currentTimingEvent_ = -1; + startTime_[0] = 0; /* reset timer */ + logNeeded_ = TRUE; + + // The GENERATE_EXPLAIN cqd captures explain data pertaining to dynamic + // queries. Ordinarily we want it on, but for just-in-time logging triggered + // by an error, we don't need it, and can't set it because HSFuncExecQuery + // clears the diagnostics area, which causes the error to be lost. + explainOn_ = needExplain; + if (needExplain) + { + if (HSFuncExecQuery("CONTROL QUERY DEFAULT GENERATE_EXPLAIN 'ON'") != 0) + explainOn_ = FALSE; // couldn't turn it on (shouldn't happen) + } + } } } @@ -442,6 +444,21 @@ void HSLogMan::StopLog() if (explainOn_) HSFuncExecQuery("CONTROL QUERY DEFAULT GENERATE_EXPLAIN RESET"); logNeeded_ = FALSE; + + NABoolean logStopped = QRLogger::stopLogFile(CAT_SQL_USTAT); + } + +/***********************************************/ +/* METHOD: StopAndDeleteLog() */ +/* PURPOSE: Stop capturing log information */ +/* and then delete the log file */ +/* INPUT: none */ +/***********************************************/ +void HSLogMan::StopAndDeleteLog() + { + StopLog(); + unlink(logFile_->data()); + logFile_->clear(); } /***********************************************/ @@ -456,12 +473,14 @@ void HSLogMan::StopLog() /***********************************************/ void HSLogMan::ClearLog() { - //*logFile_ = ActiveSchemaDB()->getDefaults().getValue(USTAT_LOG); - struct stat sb; - if(0==stat(logFile_->data(), &sb))//if log exists, empty it. - ofstream fileout(logFile_->data(), ios::out); - currentTimingEvent_ = -1; - startTime_[0] = 0; /* reset timer */ + if (logFile_->length() > 0) + { + struct stat sb; + if(0==stat(logFile_->data(), &sb))//if log exists, empty it. + ofstream fileout(logFile_->data(), ios::out); + currentTimingEvent_ = -1; + startTime_[0] = 0; /* reset timer */ + } } /***********************************************/ http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_log.h ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_log.h b/core/sql/ustat/hs_log.h index 305ce75..4b0ce69 100644 --- a/core/sql/ustat/hs_log.h +++ b/core/sql/ustat/hs_log.h @@ -53,6 +53,10 @@ void HSFuncMergeDiags( Lng32 sqlcode , Lng32 fsError = 0 ); +// Clean up logs as determined by log settings; assumes that it +// is called after diagnostics have been merged into CmpCommon::diags() +void HSCleanUpLog(); + // ----------------------------------------------------------------------- // Class to catch and summarize diagnostic info at procedure return. // @@ -215,6 +219,7 @@ void HSFuncLogError(Lng32 error, char *filename, Lng32 lineno); if (retcode) { \ HSFuncLogError(retcode, (char *)HS_FILE, (Lng32)__LINE__); \ HSFilterError(retcode); \ + HSCleanUpLog(); \ HSClearCLIDiagnostics(); \ return retcode; \ } \ @@ -233,9 +238,9 @@ class HSLogMan static HSLogMan* Instance(); inline NABoolean LogNeeded() const {return logNeeded_;} void Log(const char *data); /* data string to write to log */ - void StartLog(NABoolean needExplain = TRUE, /* start the log */ - const char* logFileName = NULL); /* allow override of default */ + void StartLog(NABoolean needExplain = TRUE); /* start the log */ void StopLog(); /* stop the log */ + void StopAndDeleteLog(); /* stop the log and delete it */ void ClearLog(); /* erase the log file */ void StartTimer(const char *title = ""); /* start time-watch */ void StopTimer(); /* stop time-watch */ @@ -245,11 +250,23 @@ class HSLogMan /* formmatting messages */ NAString* logFileName() { return logFile_; }; - NABoolean ContainDirExist(const char* path); - NABoolean GetLogFile(NAString & logFile, const char* cqc_value); + + enum LogSetting + { + ON, // log all activity continuously in one log until explicitly + // turned off + OFF, // do not log any activity + SYSTEM // log each UPDATE STATS command in a separate log; keep log + // only if interesting errors occur + }; + + LogSetting GetLogSetting() const { return logSetting_; } + void SetLogSetting(LogSetting logSetting); + protected: HSLogMan(); /* ensure only 1 instance of class */ private: + LogSetting logSetting_; NABoolean logNeeded_; /* T: logging is needed */ NAString *logFile_; /* log filename */ http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_update.cpp ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_update.cpp b/core/sql/ustat/hs_update.cpp index 2e33abf..ca946df 100644 --- a/core/sql/ustat/hs_update.cpp +++ b/core/sql/ustat/hs_update.cpp @@ -170,6 +170,8 @@ Lng32 UpdateStats(char *input, NABoolean requestedByCompiler) sortBuffer2 = NULL; HSLogMan *LM = HSLogMan::Instance(); + if (LM->GetLogSetting() == HSLogMan::SYSTEM) + LM->StartLog(); // start a log automatically for each UPDATE STATS command ComDiagsArea *ptrDiags = CmpCommon::diags(); if (!ptrDiags) @@ -329,7 +331,10 @@ Lng32 UpdateStats(char *input, NABoolean requestedByCompiler) /* MODIFY HISTOGRAMS. */ /*==============================*/ if (hs_globals_obj.optFlags & LOG_OPT) /* log option requested */ - return 0; + { + HSCleanUpLog(); + return 0; + } /*==============================*/ /* VERIFY THAT THE REQUESTOR */ @@ -410,6 +415,7 @@ Lng32 UpdateStats(char *input, NABoolean requestedByCompiler) hs_globals_obj.optFlags & REMOVE_SAMPLE_OPT) /* delete sample requested*/ { retcode = managePersistentSamples(); + HSCleanUpLog(); HSClearCLIDiagnostics(); return retcode; } @@ -421,6 +427,7 @@ Lng32 UpdateStats(char *input, NABoolean requestedByCompiler) if (hs_globals_obj.optFlags & VIEWONLY_OPT) { + HSCleanUpLog(); return 0; } @@ -539,6 +546,8 @@ Lng32 UpdateStats(char *input, NABoolean requestedByCompiler) LM->StopTimer(); + HSCleanUpLog(); + return retcode; } http://git-wip-us.apache.org/repos/asf/trafodion/blob/f473c0cd/core/sql/ustat/hs_yacc.y ---------------------------------------------------------------------- diff --git a/core/sql/ustat/hs_yacc.y b/core/sql/ustat/hs_yacc.y index cfdaa56..bb7a8f0 100644 --- a/core/sql/ustat/hs_yacc.y +++ b/core/sql/ustat/hs_yacc.y @@ -89,6 +89,7 @@ extern int yylex(YYSTYPE * lvalp, void* scanner); %token TOK_SET ROWCOUNT SAMPLE ROWS RANDOM PERIODIC TOK_PERCENT CLUSTERS BLOCKS OF %token EXISTING COLUMNS NECESSARY CREATE REMOVE ALL WITH SKEWED VALUES %token INCREMENTAL WHERE WHERE_CONDITION PERSISTENT NO +%token SYSTEM %% /* @@ -105,13 +106,19 @@ statement : UPDATE STATISTICS { hs_globals_y->isUpdatestatsStmt = TRUE; } FOR | UPDATE STATISTICS LOG ON { HSLogMan *LM = HSLogMan::Instance(); - LM->StartLog(); + LM->SetLogSetting(HSLogMan::ON); hs_globals_y->optFlags |= LOG_OPT; } | UPDATE STATISTICS LOG TOK_OFF { HSLogMan *LM = HSLogMan::Instance(); - LM->StopLog(); + LM->SetLogSetting(HSLogMan::OFF); + hs_globals_y->optFlags |= LOG_OPT; + } + | UPDATE STATISTICS LOG SYSTEM + { + HSLogMan *LM = HSLogMan::Instance(); + LM->SetLogSetting(HSLogMan::SYSTEM); hs_globals_y->optFlags |= LOG_OPT; } | UPDATE STATISTICS LOG CLEAR @@ -323,6 +330,12 @@ identifier : REGULAR_IDENTIFIER *buf = "STATISTICS"; $$ = buf; } + | SYSTEM + { + NAString *buf = new(STMTHEAP) NAString(STMTHEAP); + *buf = "SYSTEM"; + $$ = buf; + } | TOK_PERCENT { NAString *buf = new(STMTHEAP) NAString(STMTHEAP);
