From 24ddd96235e0a3d817055b957493e24caefb39d3 Mon Sep 17 00:00:00 2001 From: morningman Date: Wed, 5 Jun 2024 23:41:52 +0800 Subject: [PATCH 1/3] 1 --- be/CMakeLists.txt | 3 ++ be/src/common/config.cpp | 2 + be/src/common/config.h | 5 +++ be/src/common/logconfig.cpp | 40 +++++++++++++++-- bin/start_be.sh | 72 ++++++++++++++++++------------- regression-test/framework/pom.xml | 2 +- 6 files changed, 90 insertions(+), 34 deletions(-) diff --git a/be/CMakeLists.txt b/be/CMakeLists.txt index fafaff15fe164c..929483d08b27fb 100644 --- a/be/CMakeLists.txt +++ b/be/CMakeLists.txt @@ -66,6 +66,9 @@ else() add_definitions(-DBOOST_STACKTRACE_USE_NOOP) endif() +# enable glog custom prefix +add_definitions(-DGLOG_CUSTOM_PREFIX_SUPPORT) + # Options option(GLIBC_COMPATIBILITY "Enable compatibility with older glibc libraries." ON) option(USE_LIBCPP "Use libc++" OFF) diff --git a/be/src/common/config.cpp b/be/src/common/config.cpp index e754917e016f8f..432fcc3648b3fa 100644 --- a/be/src/common/config.cpp +++ b/be/src/common/config.cpp @@ -1292,6 +1292,8 @@ DEFINE_Bool(enable_jvm_monitor, "false"); // Skip loading stale rowset meta when initializing `TabletMeta` from protobuf DEFINE_mBool(skip_loading_stale_rowset_meta, "false"); +DEFINE_Bool(enable_file_logger, "true"); + // clang-format off #ifdef BE_TEST // test s3 diff --git a/be/src/common/config.h b/be/src/common/config.h index b1a825a462bdee..ad37b2b22382f6 100644 --- a/be/src/common/config.h +++ b/be/src/common/config.h @@ -1369,6 +1369,11 @@ DECLARE_Bool(enable_jvm_monitor); // Skip loading stale rowset meta when initializing `TabletMeta` from protobuf DECLARE_mBool(skip_loading_stale_rowset_meta); +// Whether to use file to record log. When starting BE with --console, +// all logs will be written to both standard output and file. +// Disable this option will no longer use file to record log. +// Only works when starting BE with --console. +DECLARE_Bool(enable_file_logger); #ifdef BE_TEST // test s3 diff --git a/be/src/common/logconfig.cpp b/be/src/common/logconfig.cpp index bf408272776984..597f6ca6c9ad87 100644 --- a/be/src/common/logconfig.cpp +++ b/be/src/common/logconfig.cpp @@ -21,6 +21,7 @@ #include #include #include +#include #include #include #include @@ -48,6 +49,28 @@ static bool iequals(const std::string& a, const std::string& b) { return true; } +void custom_prefix(std::ostream &s, const google::LogMessageInfo &l, void*) { + // Add prefix "RuntimeLogger ". + s << "RuntimeLogger "; + // Same as in fe.log + // The following is same as default log format. eg: + // I20240605 15:25:15.677153 1763151 wal_manager.cpp:481] msg... + s << l.severity[0] + << std::setw(4) << 1900 + l.time.year() + << std::setw(2) << 1 + l.time.month() + << std::setw(2) << l.time.day() + << ' ' + << std::setw(2) << l.time.hour() << ':' + << std::setw(2) << l.time.min() << ':' + << std::setw(2) << l.time.sec() << "." + << std::setw(6) << l.time.usec() + << ' ' + << std::setfill(' ') << std::setw(5) + << l.thread_id << std::setfill('0') + << ' ' + << l.filename << ':' << l.line_number << "]"; +} + bool init_glog(const char* basename) { std::lock_guard logging_lock(logging_mutex); @@ -55,8 +78,14 @@ bool init_glog(const char* basename) { return true; } - if (getenv("DORIS_LOG_TO_STDERR") != nullptr) { - FLAGS_alsologtostderr = true; + bool log_to_console = (getenv("DORIS_LOG_TO_STDERR") != nullptr); + std::cout << "xxx log_to_console: " << log_to_console << std::endl; + if (log_to_console) { + if (config::enable_file_logger) { + FLAGS_alsologtostderr = true; + } else { + FLAGS_logtostderr = true; + } } // don't log to stderr except fatal level @@ -144,7 +173,12 @@ bool init_glog(const char* basename) { } } - google::InitGoogleLogging(basename); + if (log_to_console) { + // Only add prefix if log output to stderr + google::InitGoogleLogging(basename, &custom_prefix); + } else { + google::InitGoogleLogging(basename); + } logging_initialized = true; diff --git a/bin/start_be.sh b/bin/start_be.sh index 7d3b5c5679ebac..fc75a5775d4ace 100755 --- a/bin/start_be.sh +++ b/bin/start_be.sh @@ -81,17 +81,41 @@ PID_DIR="$( )" export PID_DIR +# read from be.conf +while read -r line; do + envline="$(echo "${line}" | + sed 's/[[:blank:]]*=[[:blank:]]*/=/g' | + sed 's/^[[:blank:]]*//g' | + grep -E "^[[:upper:]]([[:upper:]]|_|[[:digit:]])*=" || + true)" + envline="$(eval "echo ${envline}")" + if [[ "${envline}" == *"="* ]]; then + eval 'export "${envline}"' + fi +done <"${DORIS_HOME}/conf/be.conf" + +STDOUT_LOGGER="${LOG_DIR}/be.out" +log() { + # same datetime format as in fe.log: 2024-06-03 14:54:41,478 + cur_date=$(date +"%Y-%m-%d %H:%M:%S,$(date +%3N)") + if [[ "${RUN_CONSOLE}" -eq 1 ]]; then + echo "StdoutLogger ${cur_date} $1" + else + echo "StdoutLogger ${cur_date} $1" >>"${STDOUT_LOGGER}" + fi +} + jdk_version() { local java_cmd="${1}" local result local IFS=$'\n' if ! command -v "${java_cmd}" >/dev/null; then - echo "ERROR: invalid java_cmd ${java_cmd}" >>"${LOG_DIR}/be.out" + echo "ERROR: invalid java_cmd ${java_cmd}" >> "${STDOUT_LOGGER}" result=no_java return 1 else - echo "INFO: java_cmd ${java_cmd}" >>"${LOG_DIR}/be.out" + echo "INFO: java_cmd ${java_cmd}" >> "${STDOUT_LOGGER}" local version # remove \r for Cygwin version="$("${java_cmd}" -Xms32M -Xmx32M -version 2>&1 | tr '\r' '\n' | grep version | awk '{print $3}')" @@ -101,7 +125,7 @@ jdk_version() { else result="$(echo "${version}" | awk -F '.' '{print $1}')" fi - echo "INFO: jdk_version ${result}" >>"${LOG_DIR}/be.out" + echo "INFO: jdk_version ${result}" >> "${STDOUT_LOGGER}" fi echo "${result}" return 0 @@ -145,19 +169,19 @@ fi if [[ "$(uname -s)" != 'Darwin' ]]; then MAX_MAP_COUNT="$(cat /proc/sys/vm/max_map_count)" if [[ "${MAX_MAP_COUNT}" -lt 2000000 ]]; then - echo "Set kernel parameter 'vm.max_map_count' to a value greater than 2000000, example: 'sysctl -w vm.max_map_count=2000000'" + log "Set kernel parameter 'vm.max_map_count' to a value greater than 2000000, example: 'sysctl -w vm.max_map_count=2000000'" exit 1 fi if [[ "$(swapon -s | wc -l)" -gt 1 ]]; then - echo "Disable swap memory before starting be" + log "Disable swap memory before starting be" exit 1 fi fi MAX_FILE_COUNT="$(ulimit -n)" if [[ "${MAX_FILE_COUNT}" -lt 60000 ]]; then - echo "Set max number of open file descriptors to a value greater than 60000, example: 'ulimit -n 60000'" + log "Set max number of open file descriptors to a value greater than 60000, example: 'ulimit -n 60000'" exit 1 fi @@ -218,7 +242,7 @@ export CLASSPATH="${DORIS_HOME}/conf/:${DORIS_CLASSPATH}:${CLASSPATH}" # DORIS_CLASSPATH is for self-managed jni export DORIS_CLASSPATH="-Djava.class.path=${DORIS_CLASSPATH}" -#echo ${DORIS_CLASSPATH} +# log ${DORIS_CLASSPATH} export LD_LIBRARY_PATH="${DORIS_HOME}/lib/hadoop_hdfs/native:${LD_LIBRARY_PATH}" @@ -228,18 +252,6 @@ export ODBCSYSINI="${DORIS_HOME}/conf" # support utf8 for oracle database export NLS_LANG='AMERICAN_AMERICA.AL32UTF8' -while read -r line; do - envline="$(echo "${line}" | - sed 's/[[:blank:]]*=[[:blank:]]*/=/g' | - sed 's/^[[:blank:]]*//g' | - grep -E "^[[:upper:]]([[:upper:]]|_|[[:digit:]])*=" || - true)" - envline="$(eval "echo ${envline}")" - if [[ "${envline}" == *"="* ]]; then - eval 'export "${envline}"' - fi -done <"${DORIS_HOME}/conf/be.conf" - if [[ -e "${DORIS_HOME}/bin/palo_env.sh" ]]; then # shellcheck disable=1091 source "${DORIS_HOME}/bin/palo_env.sh" @@ -248,16 +260,16 @@ fi export PPROF_TMPDIR="${LOG_DIR}" if [[ -z "${JAVA_HOME}" ]]; then - echo "The JAVA_HOME environment variable is not set correctly" - echo "This environment variable is required to run this program" - echo "Note: JAVA_HOME should point to a JDK and not a JRE" - echo "You can set JAVA_HOME in the be.conf configuration file" + log "The JAVA_HOME environment variable is not set correctly" + log "This environment variable is required to run this program" + log "Note: JAVA_HOME should point to a JDK and not a JRE" + log "You can set JAVA_HOME in the be.conf configuration file" exit 1 fi for var in http_proxy HTTP_PROXY https_proxy HTTPS_PROXY; do if [[ -n ${!var} ]]; then - echo "env '${var}' = '${!var}', need unset it using 'unset ${var}'" + log "env '${var}' = '${!var}', need unset it using 'unset ${var}'" exit 1 fi done @@ -278,7 +290,7 @@ if [[ -f "${pidfile}" ]]; then fi chmod 550 "${DORIS_HOME}/lib/doris_be" -echo "Start time: $(date)" >>"${LOG_DIR}/be.out" +log "Start time: $(date)" if [[ ! -f '/bin/limit3' ]]; then LIMIT='' @@ -329,7 +341,7 @@ set_tcmalloc_heap_limit() { fi if [[ "${mem_limit_mb}" -gt "${total_mem_mb}" ]]; then - echo "mem_limit is larger than the total memory of the server. ${mem_limit_mb} > ${total_mem_mb}" + log "mem_limit is larger than the total memory of the server. ${mem_limit_mb} > ${total_mem_mb}" return 1 fi export TCMALLOC_HEAP_LIMIT_MB=${mem_limit_mb} @@ -358,7 +370,7 @@ if [[ "${java_version}" -eq 17 ]]; then fi final_java_opt="${JAVA_OPTS_FOR_JDK_17}" else - echo "ERROR: The jdk_version is ${java_version}, it must be 17." >>"${LOG_DIR}/be.out" + log "ERROR: The jdk_version is ${java_version}, it must be 17." >>"${LOG_DIR}/be.out" exit 1 fi @@ -377,9 +389,9 @@ fi # set LIBHDFS_OPTS for hadoop libhdfs export LIBHDFS_OPTS="${final_java_opt}" -# echo "CLASSPATH: ${CLASSPATH}" -# echo "LD_LIBRARY_PATH: ${LD_LIBRARY_PATH}" -# echo "LIBHDFS_OPTS: ${LIBHDFS_OPTS}" +# log "CLASSPATH: ${CLASSPATH}" +# log "LD_LIBRARY_PATH: ${LD_LIBRARY_PATH}" +# log "LIBHDFS_OPTS: ${LIBHDFS_OPTS}" if [[ -z ${JEMALLOC_CONF} ]]; then JEMALLOC_CONF="percpu_arena:percpu,background_thread:true,metadata_thp:auto,muzzy_decay_ms:15000,dirty_decay_ms:15000,oversize_threshold:0,prof:false,lg_prof_interval:32,lg_prof_sample:19,prof_gdump:false,prof_accum:false,prof_leak:false,prof_final:false" diff --git a/regression-test/framework/pom.xml b/regression-test/framework/pom.xml index 9cf3b55409228f..445539041abe47 100644 --- a/regression-test/framework/pom.xml +++ b/regression-test/framework/pom.xml @@ -226,7 +226,7 @@ under the License. com.google.guava guava - 31.0.1-jre + 32.1.2-jre org.codehaus.janino From 827a7d4ea76a98dbfd00203eb1472698d5475873 Mon Sep 17 00:00:00 2001 From: morningman Date: Wed, 5 Jun 2024 23:49:33 +0800 Subject: [PATCH 2/3] style --- be/src/common/logconfig.cpp | 30 +++++++++++++++--------------- bin/start_be.sh | 8 ++++---- 2 files changed, 19 insertions(+), 19 deletions(-) diff --git a/be/src/common/logconfig.cpp b/be/src/common/logconfig.cpp index 597f6ca6c9ad87..2a4716772db660 100644 --- a/be/src/common/logconfig.cpp +++ b/be/src/common/logconfig.cpp @@ -49,26 +49,26 @@ static bool iequals(const std::string& a, const std::string& b) { return true; } -void custom_prefix(std::ostream &s, const google::LogMessageInfo &l, void*) { +void custom_prefix(std::ostream& s, const google::LogMessageInfo& l, void*) { // Add prefix "RuntimeLogger ". s << "RuntimeLogger "; // Same as in fe.log // The following is same as default log format. eg: // I20240605 15:25:15.677153 1763151 wal_manager.cpp:481] msg... - s << l.severity[0] - << std::setw(4) << 1900 + l.time.year() - << std::setw(2) << 1 + l.time.month() - << std::setw(2) << l.time.day() - << ' ' - << std::setw(2) << l.time.hour() << ':' - << std::setw(2) << l.time.min() << ':' - << std::setw(2) << l.time.sec() << "." - << std::setw(6) << l.time.usec() - << ' ' - << std::setfill(' ') << std::setw(5) - << l.thread_id << std::setfill('0') - << ' ' - << l.filename << ':' << l.line_number << "]"; + s << l.severity[0]; + s << std::setw(4) << 1900 + l.time.year(); + s << std::setw(2) << 1 + l.time.month(); + s << std::setw(2) << l.time.day(); + s << ' '; + s << std::setw(2) << l.time.hour() << ':'; + s << std::setw(2) << l.time.min() << ':'; + s << std::setw(2) << l.time.sec() << "."; + s << std::setw(6) << l.time.usec(); + s << ' '; + s << std::setfill(' ') << std::setw(5); + s << l.thread_id << std::setfill('0'); + s << ' '; + s << l.filename << ':' << l.line_number << "]"; } bool init_glog(const char* basename) { diff --git a/bin/start_be.sh b/bin/start_be.sh index fc75a5775d4ace..4fd5670f1fb5da 100755 --- a/bin/start_be.sh +++ b/bin/start_be.sh @@ -111,11 +111,11 @@ jdk_version() { local IFS=$'\n' if ! command -v "${java_cmd}" >/dev/null; then - echo "ERROR: invalid java_cmd ${java_cmd}" >> "${STDOUT_LOGGER}" + echo "ERROR: invalid java_cmd ${java_cmd}" >>"${STDOUT_LOGGER}" result=no_java return 1 else - echo "INFO: java_cmd ${java_cmd}" >> "${STDOUT_LOGGER}" + echo "INFO: java_cmd ${java_cmd}" >>"${STDOUT_LOGGER}" local version # remove \r for Cygwin version="$("${java_cmd}" -Xms32M -Xmx32M -version 2>&1 | tr '\r' '\n' | grep version | awk '{print $3}')" @@ -125,7 +125,7 @@ jdk_version() { else result="$(echo "${version}" | awk -F '.' '{print $1}')" fi - echo "INFO: jdk_version ${result}" >> "${STDOUT_LOGGER}" + echo "INFO: jdk_version ${result}" >>"${STDOUT_LOGGER}" fi echo "${result}" return 0 @@ -263,7 +263,7 @@ if [[ -z "${JAVA_HOME}" ]]; then log "The JAVA_HOME environment variable is not set correctly" log "This environment variable is required to run this program" log "Note: JAVA_HOME should point to a JDK and not a JRE" - log "You can set JAVA_HOME in the be.conf configuration file" + log "You can set JAVA_HOME in the be.conf configuration file" exit 1 fi From 09efd163ab2e13156b76c6964dba10752eb28586 Mon Sep 17 00:00:00 2001 From: morningman Date: Wed, 5 Jun 2024 23:52:45 +0800 Subject: [PATCH 3/3] style --- be/src/common/logconfig.cpp | 1 - bin/start_be.sh | 16 ++++++++-------- 2 files changed, 8 insertions(+), 9 deletions(-) diff --git a/be/src/common/logconfig.cpp b/be/src/common/logconfig.cpp index 2a4716772db660..0865e8ce471d49 100644 --- a/be/src/common/logconfig.cpp +++ b/be/src/common/logconfig.cpp @@ -79,7 +79,6 @@ bool init_glog(const char* basename) { } bool log_to_console = (getenv("DORIS_LOG_TO_STDERR") != nullptr); - std::cout << "xxx log_to_console: " << log_to_console << std::endl; if (log_to_console) { if (config::enable_file_logger) { FLAGS_alsologtostderr = true; diff --git a/bin/start_be.sh b/bin/start_be.sh index 4fd5670f1fb5da..38db43557e22fe 100755 --- a/bin/start_be.sh +++ b/bin/start_be.sh @@ -169,19 +169,19 @@ fi if [[ "$(uname -s)" != 'Darwin' ]]; then MAX_MAP_COUNT="$(cat /proc/sys/vm/max_map_count)" if [[ "${MAX_MAP_COUNT}" -lt 2000000 ]]; then - log "Set kernel parameter 'vm.max_map_count' to a value greater than 2000000, example: 'sysctl -w vm.max_map_count=2000000'" + echo "Set kernel parameter 'vm.max_map_count' to a value greater than 2000000, example: 'sysctl -w vm.max_map_count=2000000'" exit 1 fi if [[ "$(swapon -s | wc -l)" -gt 1 ]]; then - log "Disable swap memory before starting be" + echo "Disable swap memory before starting be" exit 1 fi fi MAX_FILE_COUNT="$(ulimit -n)" if [[ "${MAX_FILE_COUNT}" -lt 60000 ]]; then - log "Set max number of open file descriptors to a value greater than 60000, example: 'ulimit -n 60000'" + echo "Set max number of open file descriptors to a value greater than 60000, example: 'ulimit -n 60000'" exit 1 fi @@ -260,10 +260,10 @@ fi export PPROF_TMPDIR="${LOG_DIR}" if [[ -z "${JAVA_HOME}" ]]; then - log "The JAVA_HOME environment variable is not set correctly" - log "This environment variable is required to run this program" - log "Note: JAVA_HOME should point to a JDK and not a JRE" - log "You can set JAVA_HOME in the be.conf configuration file" + echo "The JAVA_HOME environment variable is not set correctly" + echo "This environment variable is required to run this program" + echo "Note: JAVA_HOME should point to a JDK and not a JRE" + echo "You can set JAVA_HOME in the be.conf configuration file" exit 1 fi @@ -370,7 +370,7 @@ if [[ "${java_version}" -eq 17 ]]; then fi final_java_opt="${JAVA_OPTS_FOR_JDK_17}" else - log "ERROR: The jdk_version is ${java_version}, it must be 17." >>"${LOG_DIR}/be.out" + echo "ERROR: The jdk_version is ${java_version}, it must be 17." >>"${LOG_DIR}/be.out" exit 1 fi