From 539b1caa793d0be14e28a5e6217f4fb90d585e3a Mon Sep 17 00:00:00 2001 From: bit-dance <2634358021@qq.com> Date: Mon, 6 Jan 2025 06:45:30 +0000 Subject: [PATCH] [CP] [#2024120500106003679]Fix : add log for evicted pl obj in pl cache --- src/pl/ob_pl.cpp | 10 +++---- src/pl/ob_pl.h | 5 ++-- src/pl/pl_cache/ob_pl_cache.cpp | 43 +++++++++++++++++++++++++++- src/pl/pl_cache/ob_pl_cache.h | 8 ++++++ src/pl/pl_cache/ob_pl_cache_mgr.cpp | 2 +- src/pl/pl_cache/ob_pl_cache_object.h | 11 +++++-- 6 files changed, 67 insertions(+), 12 deletions(-) diff --git a/src/pl/ob_pl.cpp b/src/pl/ob_pl.cpp index 7dcc011f0..9d576124f 100644 --- a/src/pl/ob_pl.cpp +++ b/src/pl/ob_pl.cpp @@ -2470,7 +2470,7 @@ int ObPL::get_pl_function(ObExecContext &ctx, // use stmt id as key pc_ctx.key_.key_id_ = stmt_id; if (OB_FAIL(ObPLCacheMgr::get_pl_cache(ctx.get_my_session()->get_plan_cache(), cacheobj_guard, pc_ctx))) { - LOG_INFO("get pl function from plan cache failed", + LOG_INFO("get pl function by stmt id from plan cache failed", K(ret), K(pc_ctx.key_), K(stmt_id), K(sql), K(params)); ret = OB_ERR_UNEXPECTED != ret ? OB_SUCCESS : ret; } else if (FALSE_IT(routine = static_cast(cacheobj_guard.get_cache_obj()))) { @@ -2701,17 +2701,17 @@ int ObPL::add_pl_lib_cache(ObPLFunction *pl_func, ObPLCacheCtx &pc_ctx) } else if (OB_FAIL(ObPLCacheMgr::add_pl_cache(plan_cache, pl_func, pc_ctx))) { if (OB_SQL_PC_PLAN_DUPLICATE == ret) { ret = OB_SUCCESS; - LOG_DEBUG("this plan has been added by others, need not add again", KPC(pl_func)); + LOG_WARN("this plan has been added by others, need not add again", KPC(pl_func)); } else if (OB_REACH_MEMORY_LIMIT == ret || OB_SQL_PC_PLAN_SIZE_LIMIT == ret) { if (REACH_TIME_INTERVAL(1000000)) { //1s, 当内存达到上限时, 该日志打印会比较频繁, 所以以1s为间隔打印 - LOG_DEBUG("can't add plan to plan cache", + LOG_WARN("can't add plan to plan cache", K(ret), K(pl_func->get_mem_size()), K(pc_ctx.key_), K(plan_cache->get_mem_used())); } ret = OB_SUCCESS; } else if (is_not_supported_err(ret)) { ret = OB_SUCCESS; - LOG_DEBUG("plan cache don't support add this kind of plan now", KPC(pl_func)); + LOG_WARN("plan cache don't support add this kind of plan now", KPC(pl_func)); } else { if (OB_REACH_MAX_CONCURRENT_NUM != ret) { //如果是达到限流上限, 则将错误码抛出去 ret = OB_SUCCESS; //add plan出错, 覆盖错误码, 确保因plan cache失败不影响正常执行路径 @@ -2719,7 +2719,7 @@ int ObPL::add_pl_lib_cache(ObPLFunction *pl_func, ObPLCacheCtx &pc_ctx) } } } else { - LOG_DEBUG("add pl function to plan cache success", K(pc_ctx.key_)); + LOG_INFO("add pl function to plan cache success", K(pc_ctx.key_)); } return ret; } diff --git a/src/pl/ob_pl.h b/src/pl/ob_pl.h index 6be3e0c3c..7a33f7411 100644 --- a/src/pl/ob_pl.h +++ b/src/pl/ob_pl.h @@ -273,7 +273,7 @@ public: OB_INLINE void set_profiler_unit_info(const std::pair &unit_info) { profiler_unit_info_ = unit_info; } TO_STRING_KV(K_(routine_table), K_(can_cached), - K_(tenant_schema_version), K_(sys_schema_version)); + K_(tenant_schema_version), K_(sys_schema_version), K_(stat)); protected: @@ -525,7 +525,8 @@ public: K_(variables), K_(default_idxs), K_(function_name), - K_(priv_user)); + K_(priv_user), + K_(stat)); private: //符号表信息 diff --git a/src/pl/pl_cache/ob_pl_cache.cpp b/src/pl/pl_cache/ob_pl_cache.cpp index 828972f71..a32ff5eec 100644 --- a/src/pl/pl_cache/ob_pl_cache.cpp +++ b/src/pl/pl_cache/ob_pl_cache.cpp @@ -11,6 +11,7 @@ */ #define USING_LOG_PREFIX PL_CACHE +#define LONG_COMPILE_TIME 10000000 #include "ob_pl_cache.h" #include "lib/oblog/ob_log_module.h" #include "share/rc/ob_tenant_base.h" //MTL @@ -477,7 +478,8 @@ int ObPLObjectValue::check_value_version(share::schema::ObSchemaGetterGuard *sch is_old_version = true; } if (OB_SUCC(ret) && is_old_version) { - LOG_WARN("mismatched schema objs", K(*schema_obj1), K(schema_obj2), K(i)); + copy_obj_schema_version(pl_routine_obj_->get_stat_for_update().out_of_date_dependcy_version_, schema_obj1); + LOG_WARN("mismatched schema objs", K(ret) ,K(*schema_obj1), K(schema_obj2), K(i)); } } } @@ -657,6 +659,7 @@ int ObPLObjectValue::get_all_dep_schema(ObPLCacheCtx &pc_ctx, } if (OB_INVALID_VERSION == new_version) { ret = OB_OLD_SCHEMA_VERSION; + copy_obj_schema_version(pl_routine_obj_->get_stat_for_update().out_of_date_dependcy_version_, pcv_schema); LOG_WARN("can not get newer schema version", K(ret)); } else if (OB_SUCC(ret)) { tmp_schema_obj.schema_id_ = pcv_schema->schema_id_; // same id @@ -691,6 +694,7 @@ int ObPLObjectValue::get_all_dep_schema(ObPLCacheCtx &pc_ctx, tmp_schema_obj.reset(); } else if (nullptr == table_schema) { ret = OB_OLD_SCHEMA_VERSION; + copy_obj_schema_version(pl_routine_obj_->get_stat_for_update().out_of_date_dependcy_version_, pcv_schema); LOG_WARN("table not exist", K(ret), K(*pcv_schema), K(table_schema)); } else if (OB_FAIL(tmp_schema_obj.init_without_copy_name(table_schema))) { LOG_WARN("failed to init pcv schema obj", K(ret)); @@ -731,6 +735,7 @@ int ObPLObjectValue::match_dep_schema(const ObPLCacheCtx &pc_ctx, && !stored_schema_objs_.at(i)->match_compare(schema_array.at(i))) { // check whether common table name is same as system table in oracle mode is_same = false; + copy_obj_schema_version(pl_routine_obj_->get_stat_for_update().out_of_date_dependcy_version_, stored_schema_objs_.at(i)); LOG_WARN("mismatched schema objs", K(*stored_schema_objs_.at(i)), K(stored_schema_objs_.at(i)), K(i)); } else { // do nothing @@ -1076,6 +1081,42 @@ int ObPLObjectSet::create_new_pl_object_value(ObPLObjectValue *&pl_object_value) return ret; } +int ObPLObjectSet::before_cache_evicted() +{ + int ret = OB_SUCCESS; + ObPlanCache *plan_cache = get_lib_cache(); + ObSEArray stat_array; + bool has_out_of_date_obj = false; + int64_t compile_time = 0; + CK (OB_NOT_NULL(plan_cache)); + if (OB_SUCC(ret)) { + DLIST_FOREACH(pl_object_value, object_value_sets_) { + const PLCacheObjStat& cache_obj_stat = pl_object_value->pl_routine_obj_->get_stat(); + compile_time += cache_obj_stat.compile_time_; + OZ (stat_array.push_back(cache_obj_stat)); + if (OB_SUCC(ret) && cache_obj_stat.out_of_date_dependcy_version_.is_valid()) { + has_out_of_date_obj = true; + } + } + } + if (OB_FAIL(ret)) { + } else if (plan_cache->get_mem_hold() > plan_cache->get_mem_high()) { + if (compile_time >= LONG_COMPILE_TIME) { + LOG_WARN("Plan cache size reached upper limit and evict obj which need long time to re-compile", + K(ret), K(plan_cache->get_tenant_id()), K(stat_array), K(compile_time), + K(plan_cache->get_mem_hold()), K(plan_cache->get_mem_high())); + } else { + LOG_TRACE("Plan cache size reached upper limit need check plan cache mem conf", + K(ret), K(plan_cache->get_tenant_id()), K(stat_array), + K(plan_cache->get_mem_hold()), K(plan_cache->get_mem_high())); + } + } else if (has_out_of_date_obj) { + LOG_TRACE("Remove out_of_dated pl cache obj which has mismatched dep schema version", + K(ret), K(plan_cache->get_tenant_id()), K(stat_array)); + } + return ret; +} + void ObPLObjectSet::free_pl_object_value(ObPLObjectValue *pl_object_value) { int ret = OB_SUCCESS; diff --git a/src/pl/pl_cache/ob_pl_cache.h b/src/pl/pl_cache/ob_pl_cache.h index 3804084b5..dddbdbdae 100644 --- a/src/pl/pl_cache/ob_pl_cache.h +++ b/src/pl/pl_cache/ob_pl_cache.h @@ -18,6 +18,7 @@ #include "sql/plan_cache/ob_i_lib_cache_object.h" #include "sql/plan_cache/ob_i_lib_cache_node.h" #include "sql/plan_cache/ob_i_lib_cache_context.h" +#include "sql/plan_cache/ob_plan_cache.h" #include "sql/plan_cache/ob_cache_object_factory.h" #include "sql/plan_cache/ob_lib_cache_register.h" #include "pl/ob_pl.h" @@ -318,6 +319,12 @@ public: int match_params_info(const ParamStore *params, bool &is_same); + OB_INLINE void copy_obj_schema_version(ObSchemaObjVersion& dest, const PCVPlSchemaObj *src) + { + dest.object_id_ = src->schema_id_; + dest.version_ = src->schema_version_; + } + void reset(); int64_t get_mem_size(); @@ -405,6 +412,7 @@ public: ObILibCacheKey *key, ObILibCacheObject *cache_obj) override; + virtual int before_cache_evicted(); void destroy(); common::ObString &get_sql_id() { return sql_id_; } diff --git a/src/pl/pl_cache/ob_pl_cache_mgr.cpp b/src/pl/pl_cache/ob_pl_cache_mgr.cpp index e5c096e65..a93167499 100644 --- a/src/pl/pl_cache/ob_pl_cache_mgr.cpp +++ b/src/pl/pl_cache/ob_pl_cache_mgr.cpp @@ -153,7 +153,7 @@ int ObPLCacheMgr::add_pl_cache(ObPlanCache *lib_cache, ObILibCacheObject *pl_obj PL_CACHE_LOG(WARN, "invalid physical plan", K(ret)); } else if (lib_cache->get_mem_hold() > lib_cache->get_mem_limit()) { ret = OB_REACH_MEMORY_LIMIT; - PL_CACHE_LOG(DEBUG, "lib cache memory used reach the high water mark", + PL_CACHE_LOG(WARN, "lib cache memory used reach the high water mark", K(lib_cache->get_mem_used()), K(lib_cache->get_mem_limit()), K(ret)); } else if (pl_object->get_mem_size() >= lib_cache->get_mem_high()) { // do nothing diff --git a/src/pl/pl_cache/ob_pl_cache_object.h b/src/pl/pl_cache/ob_pl_cache_object.h index 66d454f85..d16c513c5 100644 --- a/src/pl/pl_cache/ob_pl_cache_object.h +++ b/src/pl/pl_cache/ob_pl_cache_object.h @@ -94,6 +94,7 @@ struct PLCacheObjStat int64_t pl_cg_mem_hold_; common::ObString sys_vars_str_; common::ObString param_infos_; + ObSchemaObjVersion out_of_date_dependcy_version_; // out_of_date dependcy version PLCacheObjStat() : pl_schema_id_(OB_INVALID_ID), @@ -115,7 +116,8 @@ struct PLCacheObjStat ps_stmt_id_(OB_INVALID_ID), pl_cg_mem_hold_(0), sys_vars_str_(), - param_infos_() + param_infos_(), + out_of_date_dependcy_version_() { sql_id_[0] = '\0'; } @@ -147,6 +149,7 @@ struct PLCacheObjStat pl_cg_mem_hold_ = 0; sys_vars_str_.reset(); param_infos_.reset(); + out_of_date_dependcy_version_.reset(); } TO_STRING_KV(K_(pl_schema_id), @@ -162,7 +165,8 @@ struct PLCacheObjStat K_(schema_version), K_(pl_cg_mem_hold), K_(sys_vars_str), - K_(param_infos)); + K_(param_infos), + K_(out_of_date_dependcy_version)); }; class ObPLCacheObject : public sql::ObILibCacheObject @@ -222,7 +226,8 @@ public: TO_STRING_KV(K_(expr_op_size), K_(tenant_schema_version), K_(sys_schema_version), - K_(dependency_tables)); + K_(dependency_tables), + K_(stat)); protected: int64_t tenant_schema_version_;