diff --git a/core/src/index/knowhere/CMakeLists.txt b/core/src/index/knowhere/CMakeLists.txt index b6aff8a894..d57f2ff906 100644 --- a/core/src/index/knowhere/CMakeLists.txt +++ b/core/src/index/knowhere/CMakeLists.txt @@ -22,6 +22,7 @@ endif () set(external_srcs knowhere/common/Exception.cpp + knowhere/common/Log.cpp knowhere/common/Timer.cpp ) diff --git a/core/src/index/knowhere/knowhere/common/Log.cpp b/core/src/index/knowhere/knowhere/common/Log.cpp new file mode 100644 index 0000000000..75578d105b --- /dev/null +++ b/core/src/index/knowhere/knowhere/common/Log.cpp @@ -0,0 +1,55 @@ +// Copyright (C) 2019-2020 Zilliz. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software distributed under the License +// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express +// or implied. See the License for the specific language governing permissions and limitations under the License. + +#include "knowhere/common/Log.h" + +#include +#include +#include +#include + +namespace milvus { +namespace knowhere { + +std::string +LogOut(const char* pattern, ...) { + size_t len = strnlen(pattern, 1024) + 256; + auto str_p = std::make_unique(len); + memset(str_p.get(), 0, len); + + va_list vl; + va_start(vl, pattern); + vsnprintf(str_p.get(), len, pattern, vl); + va_end(vl); + + return std::string(str_p.get()); +} + +void +SetThreadName(const std::string& name) { + pthread_setname_np(pthread_self(), name.c_str()); +} + +std::string +GetThreadName() { + std::string thread_name = "unamed"; + char name[16]; + size_t len = 16; + auto err = pthread_getname_np(pthread_self(), name, len); + if (not err) { + thread_name = name; + } + + return thread_name; +} + +} // namespace knowhere +} // namespace milvus diff --git a/core/src/index/knowhere/knowhere/common/Log.h b/core/src/index/knowhere/knowhere/common/Log.h index 510799f28c..428f06874f 100644 --- a/core/src/index/knowhere/knowhere/common/Log.h +++ b/core/src/index/knowhere/knowhere/common/Log.h @@ -7,24 +7,50 @@ // // Unless required by applicable law or agreed to in writing, software distributed under the License // is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express -// or implied. See the License for the specific language governing permissions and limitations under the License +// or implied. See the License for the specific language governing permissions and limitations under the License. #pragma once +#include + #include "easyloggingpp/easylogging++.h" namespace milvus { namespace knowhere { -#define KNOWHERE_DOMAIN_NAME "[KNOWHERE] " -#define KNOWHERE_ERROR_TEXT "KNOWHERE Error:" +std::string +LogOut(const char* pattern, ...); -#define KNOWHERE_LOG_TRACE LOG(TRACE) << KNOWHERE_DOMAIN_NAME -#define KNOWHERE_LOG_DEBUG LOG(DEBUG) << KNOWHERE_DOMAIN_NAME -#define KNOWHERE_LOG_INFO LOG(INFO) << KNOWHERE_DOMAIN_NAME -#define KNOWHERE_LOG_WARNING LOG(WARNING) << KNOWHERE_DOMAIN_NAME -#define KNOWHERE_LOG_ERROR LOG(ERROR) << KNOWHERE_DOMAIN_NAME -#define KNOWHERE_LOG_FATAL LOG(FATAL) << KNOWHERE_DOMAIN_NAME +void +SetThreadName(const std::string& name); + +std::string +GetThreadName(); + +/* + * Please use LOG_MODULE_LEVEL_C macro in member function of class + * and LOG_MODULE_LEVEL_ macro in other functions. + */ + +///////////////////////////////////////////////////////////////////////////////////////////////// +#define KNOWHERE_MODULE_NAME "KNOWHERE" +#define KNOWHERE_MODULE_CLASS_FUNCTION \ + LogOut("[%s][%s::%s][%s] ", KNOWHERE_MODULE_NAME, (typeid(*this).name()), __FUNCTION__, GetThreadName().c_str()) +#define KNOWHERE_MODULE_FUNCTION LogOut("[%s][%s][%s] ", KNOWHERE_MODULE_NAME, __FUNCTION__, GetThreadName().c_str()) + +#define LOG_KNOWHERE_TRACE_C LOG(TRACE) << KNOWHERE_MODULE_CLASS_FUNCTION +#define LOG_KNOWHERE_DEBUG_C LOG(DEBUG) << KNOWHERE_MODULE_CLASS_FUNCTION +#define LOG_KNOWHERE_INFO_C LOG(INFO) << KNOWHERE_MODULE_CLASS_FUNCTION +#define LOG_KNOWHERE_WARNING_C LOG(WARNING) << KNOWHERE_MODULE_CLASS_FUNCTION +#define LOG_KNOWHERE_ERROR_C LOG(ERROR) << KNOWHERE_MODULE_CLASS_FUNCTION +#define LOG_KNOWHERE_FATAL_C LOG(FATAL) << KNOWHERE_MODULE_CLASS_FUNCTION + +#define LOG_KNOWHERE_TRACE_ LOG(TRACE) << KNOWHERE_MODULE_FUNCTION +#define LOG_KNOWHERE_DEBUG_ LOG(DEBUG) << KNOWHERE_MODULE_FUNCTION +#define LOG_KNOWHERE_INFO_ LOG(INFO) << KNOWHERE_MODULE_FUNCTION +#define LOG_KNOWHERE_WARNING_ LOG(WARNING) << KNOWHERE_MODULE_FUNCTION +#define LOG_KNOWHERE_ERROR_ LOG(ERROR) << KNOWHERE_MODULE_FUNCTION +#define LOG_KNOWHERE_FATAL_ LOG(FATAL) << KNOWHERE_MODULE_FUNCTION } // namespace knowhere } // namespace milvus diff --git a/core/src/index/knowhere/knowhere/common/Timer.cpp b/core/src/index/knowhere/knowhere/common/Timer.cpp index 3480163481..ac4c4607ad 100644 --- a/core/src/index/knowhere/knowhere/common/Timer.cpp +++ b/core/src/index/knowhere/knowhere/common/Timer.cpp @@ -48,15 +48,15 @@ TimeRecorder::PrintTimeRecord(const std::string& msg, double span) { break; } case 1: { - KNOWHERE_LOG_DEBUG << str_log; + LOG_KNOWHERE_DEBUG_ << str_log; break; } // case 2: { - // KNOWHERE_LOG_TRACE << str_log; + // LOG_KNOWHERE_TRACE_ << str_log; // break; // } // case 3: { - // KNOWHERE_LOG_WARNING << str_log; + // LOG_KNOWHERE_WARNING_ << str_log; // break; // } } diff --git a/core/src/index/knowhere/knowhere/index/vector_index/IndexAnnoy.cpp b/core/src/index/knowhere/knowhere/index/vector_index/IndexAnnoy.cpp index 042b7a55e0..5d0eedb4b7 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/IndexAnnoy.cpp +++ b/core/src/index/knowhere/knowhere/index/vector_index/IndexAnnoy.cpp @@ -85,7 +85,7 @@ void IndexAnnoy::BuildAll(const DatasetPtr& dataset_ptr, const Config& config) { if (index_) { // it is builded all - KNOWHERE_LOG_DEBUG << "IndexAnnoy::BuildAll: index_ has been built!"; + LOG_KNOWHERE_DEBUG_ << "IndexAnnoy::BuildAll: index_ has been built!"; return; } diff --git a/core/src/index/knowhere/knowhere/index/vector_index/IndexBinaryIVF.cpp b/core/src/index/knowhere/knowhere/index/vector_index/IndexBinaryIVF.cpp index f2a0ceac25..f951f3b332 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/IndexBinaryIVF.cpp +++ b/core/src/index/knowhere/knowhere/index/vector_index/IndexBinaryIVF.cpp @@ -189,9 +189,9 @@ BinaryIVF::QueryImpl(int64_t n, const uint8_t* data, int64_t k, float* distances stdclock::time_point after = stdclock::now(); double search_cost = (std::chrono::duration(after - before)).count(); - KNOWHERE_LOG_DEBUG << "IVF search cost: " << search_cost - << ", quantization cost: " << faiss::indexIVF_stats.quantization_time - << ", data search cost: " << faiss::indexIVF_stats.search_time; + LOG_KNOWHERE_DEBUG_ << "IVF search cost: " << search_cost + << ", quantization cost: " << faiss::indexIVF_stats.quantization_time + << ", data search cost: " << faiss::indexIVF_stats.search_time; faiss::indexIVF_stats.quantization_time = 0; faiss::indexIVF_stats.search_time = 0; } diff --git a/core/src/index/knowhere/knowhere/index/vector_index/IndexIVF.cpp b/core/src/index/knowhere/knowhere/index/vector_index/IndexIVF.cpp index 4b256b1b8f..c5f315334d 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/IndexIVF.cpp +++ b/core/src/index/knowhere/knowhere/index/vector_index/IndexIVF.cpp @@ -297,9 +297,9 @@ IVF::QueryImpl(int64_t n, const float* data, int64_t k, float* distances, int64_ ivf_index->search(n, (float*)data, k, distances, labels, bitset_); stdclock::time_point after = stdclock::now(); double search_cost = (std::chrono::duration(after - before)).count(); - KNOWHERE_LOG_DEBUG << "IVF search cost: " << search_cost - << ", quantization cost: " << faiss::indexIVF_stats.quantization_time - << ", data search cost: " << faiss::indexIVF_stats.search_time; + LOG_KNOWHERE_DEBUG_ << "IVF search cost: " << search_cost + << ", quantization cost: " << faiss::indexIVF_stats.quantization_time + << ", data search cost: " << faiss::indexIVF_stats.search_time; faiss::indexIVF_stats.quantization_time = 0; faiss::indexIVF_stats.search_time = 0; } @@ -311,7 +311,7 @@ IVF::SealImpl() { auto idx = dynamic_cast(index); if (idx != nullptr) { // To be deleted - KNOWHERE_LOG_DEBUG << "Test before to_readonly: IVF READONLY " << std::boolalpha << idx->is_readonly(); + LOG_KNOWHERE_DEBUG_ << "Test before to_readonly: IVF READONLY " << std::boolalpha << idx->is_readonly(); idx->to_readonly(); } #endif diff --git a/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.cpp b/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.cpp index e0bb96e3d6..051c5496d4 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.cpp +++ b/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.cpp @@ -10,6 +10,7 @@ // or implied. See the License for the specific language governing permissions and limitations under the License #include "knowhere/index/vector_index/helpers/FaissGpuResourceMgr.h" +#include "knowhere/common/Log.h" #include #include @@ -24,7 +25,7 @@ FaissGpuResourceMgr::GetInstance() { } void -FaissGpuResourceMgr::AllocateTempMem(ResPtr& resource, const int64_t& device_id, const int64_t& size) { +FaissGpuResourceMgr::AllocateTempMem(ResPtr& resource, const int64_t device_id, const int64_t size) { if (size) { resource->faiss_res->setTempMemory(size); } else { @@ -44,6 +45,8 @@ FaissGpuResourceMgr::InitDevice(int64_t device_id, int64_t pin_mem_size, int64_t params.resource_num = res_num; devices_params_.emplace(device_id, params); + LOG_KNOWHERE_DEBUG_ << "DEVICEID " << device_id << ", pin_mem_size " << pin_mem_size << ", temp_mem_size " + << temp_mem_size << ", resource count " << res_num; } void @@ -53,18 +56,15 @@ FaissGpuResourceMgr::InitResource() { is_init = true; - // std::cout << "InitResource" << std::endl; for (auto& device : devices_params_) { auto& device_id = device.first; mutex_cache_.emplace(device_id, std::make_unique()); - // std::cout << "Device Id: " << DEVICEID << std::endl; auto& device_param = device.second; auto& bq = idle_map_[device_id]; for (int64_t i = 0; i < device_param.resource_num; ++i) { - // std::cout << "Resource Id: " << i << std::endl; auto raw_resource = std::make_shared(); // TODO(linxj): enable set pinned memory @@ -73,12 +73,12 @@ FaissGpuResourceMgr::InitResource() { bq.Put(res_wrapper); } + LOG_KNOWHERE_DEBUG_ << "DEVICEID " << device_id << ", resource count " << bq.Size(); } - // std::cout << "End initResource" << std::endl; } ResPtr -FaissGpuResourceMgr::GetRes(const int64_t& device_id, const int64_t& alloc_size) { +FaissGpuResourceMgr::GetRes(const int64_t device_id, const int64_t alloc_size) { fiu_return_on("FaissGpuResourceMgr.GetRes.ret_null", nullptr); InitResource(); @@ -88,12 +88,18 @@ FaissGpuResourceMgr::GetRes(const int64_t& device_id, const int64_t& alloc_size) auto&& resource = bq.Take(); AllocateTempMem(resource, device_id, alloc_size); return resource; + } else { + LOG_KNOWHERE_ERROR_ << "GPU device " << device_id << " not initialized"; + for (auto& item : idle_map_) { + auto& bq = item.second; + LOG_KNOWHERE_ERROR_ << "DEVICEID " << item.first << ", resource count " << bq.Size(); + } + return nullptr; } - return nullptr; } void -FaissGpuResourceMgr::MoveToIdle(const int64_t& device_id, const ResPtr& res) { +FaissGpuResourceMgr::MoveToIdle(const int64_t device_id, const ResPtr& res) { auto finder = idle_map_.find(device_id); if (finder != idle_map_.end()) { auto& bq = finder->second; diff --git a/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.h b/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.h index 926140d2d7..e97b2ab05b 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.h +++ b/core/src/index/knowhere/knowhere/index/vector_index/helpers/FaissGpuResourceMgr.h @@ -58,7 +58,7 @@ class FaissGpuResourceMgr { Free(); void - AllocateTempMem(ResPtr& resource, const int64_t& device_id, const int64_t& size); + AllocateTempMem(ResPtr& resource, const int64_t device_id, const int64_t size); void InitDevice(int64_t device_id, int64_t pin_mem_size = 0, int64_t temp_mem_size = 0, int64_t res_num = 2); @@ -68,10 +68,10 @@ class FaissGpuResourceMgr { // allocate gpu memory invoke by build or copy_to_gpu ResPtr - GetRes(const int64_t& device_id, const int64_t& alloc_size = 0); + GetRes(const int64_t device_id, const int64_t alloc_size = 0); void - MoveToIdle(const int64_t& device_id, const ResPtr& res); + MoveToIdle(const int64_t device_id, const ResPtr& res); void Dump(); diff --git a/core/src/index/knowhere/knowhere/index/vector_index/impl/nsg/NSG.cpp b/core/src/index/knowhere/knowhere/index/vector_index/impl/nsg/NSG.cpp index 332c6db675..376182d15b 100644 --- a/core/src/index/knowhere/knowhere/index/vector_index/impl/nsg/NSG.cpp +++ b/core/src/index/knowhere/knowhere/index/vector_index/impl/nsg/NSG.cpp @@ -74,8 +74,8 @@ NsgIndex::Build_with_ids(size_t nb, const float* data, const int64_t* ids, const for (size_t i = 0; i < ntotal; ++i) { total_degree += nsg[i].size(); } - KNOWHERE_LOG_DEBUG << "Graph physical size: " << total_degree * sizeof(node_t) / 1024 / 1024 << "m"; - KNOWHERE_LOG_DEBUG << "Average degree: " << total_degree / ntotal; + LOG_KNOWHERE_DEBUG_ << "Graph physical size: " << total_degree * sizeof(node_t) / 1024 / 1024 << "m"; + LOG_KNOWHERE_DEBUG_ << "Average degree: " << total_degree / ntotal; // Debug code // for (size_t i = 0; i < ntotal; i++) { diff --git a/core/src/index/unittest/CMakeLists.txt b/core/src/index/unittest/CMakeLists.txt index b44391f881..631c8355a0 100644 --- a/core/src/index/unittest/CMakeLists.txt +++ b/core/src/index/unittest/CMakeLists.txt @@ -33,6 +33,7 @@ set(util_srcs ${INDEX_SOURCE_DIR}/knowhere/knowhere/index/vector_index/helpers/IndexParameter.cpp ${INDEX_SOURCE_DIR}/knowhere/knowhere/index/vector_index/IndexType.cpp ${INDEX_SOURCE_DIR}/knowhere/knowhere/common/Exception.cpp + ${INDEX_SOURCE_DIR}/knowhere/knowhere/common/Log.cpp ${INDEX_SOURCE_DIR}/knowhere/knowhere/common/Timer.cpp ${INDEX_SOURCE_DIR}/unittest/utils.cpp ) diff --git a/sdk/examples/simple/src/ClientTest.cpp b/sdk/examples/simple/src/ClientTest.cpp index edb77d763b..9d19bb3c9f 100644 --- a/sdk/examples/simple/src/ClientTest.cpp +++ b/sdk/examples/simple/src/ClientTest.cpp @@ -35,7 +35,6 @@ constexpr int64_t SEARCH_TARGET = BATCH_ENTITY_COUNT / 2; // change this value, constexpr int64_t ADD_ENTITY_LOOP = 5; constexpr milvus::IndexType INDEX_TYPE = milvus::IndexType::IVFSQ8; constexpr int32_t NLIST = 16384; -constexpr uint64_t FIELD_NUM = 3; void PrintEntity(const std::string& tag, const milvus::Entity& entity) { std::cout << tag << "\t[";