Skip to content

Commit 1bac102

Browse files
umar456pradeep
umar456
authored and
pradeep
committed
Added logging support for memory operations
Added logging support to memory operations. By default this is turned off but you can enable them by setting the AF_TRACE environment variable to 'mem'. Other components can also be added in a later commit This is implemented using the spdlog library.
1 parent 3e3598b commit 1bac102

12 files changed

Lines changed: 248 additions & 35 deletions

File tree

‎CMakeLists.txt‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@ find_package(CBLAS)
3333
find_package(LAPACKE)
3434
find_package(Doxygen)
3535
find_package(MKL)
36+
find_package(spdlog QUIET)
3637

3738
# Graphics dependencies
3839
find_package(glbinding QUIET)
@@ -48,6 +49,7 @@ option(AF_BUILD_EXAMPLES "Build Examples" ON)
4849

4950
option(AF_WITH_GRAPHICS "Build ArrayFire with Forge Graphics" $<AND:${OPENGL_FOUND},${Forge_FOUND},${glbinding_FOUND}>)
5051
option(AF_WITH_NONFREE "Build ArrayFire nonfree algorithms" OFF)
52+
option(AF_WITH_LOGGING "Build ArrayFire with logging support" ${spdlog_FOUND})
5153

5254
option(AF_INSTALL_STANDALONE "Build installers that include all dependencies" OFF)
5355

@@ -60,6 +62,7 @@ cmake_dependent_option(AF_WITH_IMAGEIO "Build ArrayFire with Image IO support" $
6062
"FreeImage_FOUND" OFF)
6163
cmake_dependent_option(AF_BUILD_FRAMEWORK "Build an ArrayFire framework for Apple platforms.(Experimental)" OFF
6264
"APPLE" OFF)
65+
6366
option(AF_WITH_STATIC_FREEIMAGE "Use Static FreeImage Lib" OFF)
6467

6568
set(AF_WITH_CPUID ON CACHE BOOL "Build with CPUID integration")

‎docs/pages/configuring_arrayfire_environment.md‎

Lines changed: 34 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -145,42 +145,68 @@ paths, then those paths are shown in full.
145145
AF_MEM_DEBUG {#af_mem_debug}
146146
-------------------------------------------------------------------------------
147147

148-
When AF_MEM_DEBUG is set to 1 (or anything not equal to 0), the caching mechanism in the memory manager is disabled.
149-
The device buffers are allocated using native functions as needed and freed when going out of scope.
148+
When AF_MEM_DEBUG is set to 1 (or anything not equal to 0), the caching
149+
mechanism in the memory manager is disabled. The device buffers are allocated
150+
using native functions as needed and freed when going out of scope.
150151

151152
When the environment variable is not set, it is treated to be zero.
152153

153154
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
154155
AF_MEM_DEBUG=1 ./myprogram
155156
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
156157

158+
AF_TRACE {#af_trace}
159+
-------------------------------------------------------------------------------
160+
161+
If ArrayFire was built with logging support, this enviornment variable will
162+
enable tracing of various modules within ArrayFire. This is a comma separated
163+
list of modules to trace. If enabled, ArrayFire will print relevant information
164+
to stdout. Currently the following modules are supported:
165+
166+
- mem: Memory management allocation, free and garbage collection information
167+
168+
Tracing displays the information that could be useful when debugging or
169+
optimizing your application. Here is how you would use this variable:
170+
171+
AF_TRACE=mem ./myprogram
172+
173+
This will print information about memory operations such as allocations,
174+
deallocations, and garbage collection.
175+
157176

158177
AF_MAX_BUFFERS {#af_max_buffers}
159178
-------------------------------------------------------------------------
160179

161-
When AF_MAX_BUFFERS is set, this environment variable specifies the maximum number of buffers allocated before garbage collection kicks in.
180+
When AF_MAX_BUFFERS is set, this environment variable specifies the maximum
181+
number of buffers allocated before garbage collection kicks in.
162182

163-
Please note that the total number of buffers that can exist simultaneously can be higher than this number. This variable tells the garbage collector that it should free any available buffers immediately if the treshold is reached.
183+
Please note that the total number of buffers that can exist simultaneously can
184+
be higher than this number. This variable tells the garbage collector that it
185+
should free any available buffers immediately if the treshold is reached.
164186

165187
When not set, the default value is 1000.
166188

167189
AF_OPENCL_MAX_JIT_LEN {#af_opencl_max_jit_len}
168190
-------------------------------------------------------------------------------
169191

170-
When set, this environment variable specifies the maximum height of the OpenCL JIT tree after which evaluation is forced.
192+
When set, this environment variable specifies the maximum height of the OpenCL
193+
JIT tree after which evaluation is forced.
171194

172-
The default value, as of v3.4, is 50 on OSX, 100 everywhere else. This value was 20 for older versions.
195+
The default value, as of v3.4, is 50 on OSX, 100 everywhere else. This value was
196+
20 for older versions.
173197

174198
AF_CUDA_MAX_JIT_LEN {#af_cuda_max_jit_len}
175199
-------------------------------------------------------------------------------
176200

177-
When set, this environment variable specifies the maximum height of the CUDA JIT tree after which evaluation is forced.
201+
When set, this environment variable specifies the maximum height of the CUDA JIT
202+
tree after which evaluation is forced.
178203

179204
The default value, as of v3.4, 100. This value was 20 for older versions.
180205

181206
AF_CPU_MAX_JIT_LEN {#af_cpu_max_jit_len}
182207
-------------------------------------------------------------------------------
183208

184-
When set, this environment variable specifies the maximum length of the CPU JIT tree after which evaluation is forced.
209+
When set, this environment variable specifies the maximum length of the CPU JIT
210+
tree after which evaluation is forced.
185211

186212
The default value, as of v3.4, 100. This value was 20 for older versions.

‎src/backend/common/CMakeLists.txt‎

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,10 +14,11 @@ target_sources(afcommon_interface
1414
${CMAKE_CURRENT_SOURCE_DIR}/DependencyModule.cpp
1515
${CMAKE_CURRENT_SOURCE_DIR}/DependencyModule.hpp
1616
${CMAKE_CURRENT_SOURCE_DIR}/FFTPlanCache.hpp
17+
${CMAKE_CURRENT_SOURCE_DIR}/Logger.cpp
18+
${CMAKE_CURRENT_SOURCE_DIR}/Logger.hpp
1719
${CMAKE_CURRENT_SOURCE_DIR}/MatrixAlgebraHandle.hpp
1820
${CMAKE_CURRENT_SOURCE_DIR}/MemoryManager.hpp
1921
${CMAKE_CURRENT_SOURCE_DIR}/MersenneTwister.hpp
20-
${CMAKE_CURRENT_SOURCE_DIR}/module_loading.hpp
2122
${CMAKE_CURRENT_SOURCE_DIR}/SparseArray.cpp
2223
${CMAKE_CURRENT_SOURCE_DIR}/SparseArray.hpp
2324
${CMAKE_CURRENT_SOURCE_DIR}/blas_headers.hpp
@@ -31,6 +32,7 @@ target_sources(afcommon_interface
3132
${CMAKE_CURRENT_SOURCE_DIR}/err_common.hpp
3233
${CMAKE_CURRENT_SOURCE_DIR}/host_memory.cpp
3334
${CMAKE_CURRENT_SOURCE_DIR}/host_memory.hpp
35+
${CMAKE_CURRENT_SOURCE_DIR}/module_loading.hpp
3436
${CMAKE_CURRENT_SOURCE_DIR}/sparse_helpers.hpp
3537
${CMAKE_CURRENT_SOURCE_DIR}/util.cpp
3638
${CMAKE_CURRENT_SOURCE_DIR}/util.hpp
@@ -51,6 +53,16 @@ target_include_directories(afcommon_interface
5153

5254
add_library(afcommon_lapack_interface INTERFACE)
5355

56+
57+
if(AF_WITH_LOGGING)
58+
dependency_check(spdlog_FOUND "spdlog not found.")
59+
target_compile_definitions(afcommon_interface
60+
INTERFACE AF_WITH_LOGGING)
61+
target_link_libraries(afcommon_interface
62+
INTERFACE
63+
spdlog::spdlog)
64+
endif()
65+
5466
if(AF_WITH_GRAPHICS)
5567
dependency_check(glbinding_FOUND "glbinding not found.")
5668

‎src/backend/common/Logger.cpp‎

Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,67 @@
1+
/*******************************************************
2+
* Copyright (c) 2018, ArrayFire
3+
* All rights reserved.
4+
*
5+
* This file is distributed under 3-clause BSD license.
6+
* The complete license agreement can be obtained at:
7+
* http://arrayfire.com/licenses/BSD-3-Clause
8+
********************************************************/
9+
10+
#include <common/Logger.hpp>
11+
#include <common/util.hpp>
12+
13+
#include <array>
14+
#include <cstdlib>
15+
#include <string>
16+
#include <memory>
17+
18+
using std::array;
19+
using std::make_shared;
20+
using std::string;
21+
using std::shared_ptr;
22+
using std::to_string;
23+
24+
using spdlog::get;
25+
using spdlog::level::trace;
26+
using spdlog::logger;
27+
using spdlog::stdout_logger_mt;
28+
29+
namespace common {
30+
31+
#ifdef AF_WITH_LOGGING
32+
shared_ptr<logger>
33+
loggerFactory(string name) {
34+
shared_ptr<logger> logger;
35+
if(!(logger = get(name))) {
36+
logger = stdout_logger_mt(name);
37+
logger->set_pattern("[%n][%t] %v");
38+
39+
// Log mode
40+
string env_var = getEnvVar("AF_TRACE");
41+
if(env_var.find_first_of("all") != string::npos ||
42+
env_var.find_first_of(name) != string::npos)
43+
logger->set_level(trace);
44+
}
45+
return logger;
46+
}
47+
48+
string bytesToString(size_t bytes) {
49+
static array<const char *, 5> units{"B", "KB", "MB", "GB", "TB"};
50+
int count = 0;
51+
double fbytes = static_cast<double>(bytes);
52+
for(count = 0; count < units.size() && fbytes > 1000.0; count++) {
53+
fbytes *= (1.0 / 1024.0);
54+
}
55+
return fmt::format("{:.3g} {}", fbytes, units[count]);
56+
}
57+
#else
58+
shared_ptr<logger>
59+
loggerFactory(string name) {
60+
return make_shared<logger>();
61+
}
62+
63+
string bytesToString(size_t bytes) {
64+
return "";
65+
}
66+
#endif
67+
}

‎src/backend/common/Logger.hpp‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
/*******************************************************
2+
* Copyright (c) 2018, ArrayFire
3+
* All rights reserved.
4+
*
5+
* This file is distributed under 3-clause BSD license.
6+
* The complete license agreement can be obtained at:
7+
* http://arrayfire.com/licenses/BSD-3-Clause
8+
********************************************************/
9+
10+
#pragma once
11+
12+
#include <memory>
13+
#include <string>
14+
15+
#ifdef AF_WITH_LOGGING
16+
#include <spdlog/spdlog.h>
17+
#else
18+
19+
/// This is a stub class to match the spdlog API in case it is not installed on
20+
/// the users system. Only the functions we used are implemented here. Other
21+
/// functions will need to be implemented later.
22+
namespace spdlog {
23+
class logger { public: logger() {} };
24+
std::shared_ptr<spdlog::logger> get(std::string &name);
25+
std::shared_ptr<spdlog::logger> stdout_logger_mt(std::string&);
26+
namespace level {
27+
enum enum_level { trace };
28+
}
29+
}
30+
#endif
31+
32+
namespace common {
33+
std::shared_ptr<spdlog::logger> loggerFactory(std::string name);
34+
std::string bytesToString(size_t bytes);
35+
}
36+
37+
#ifdef AF_WITH_LOGGING
38+
#define AF_STR_H(x) #x
39+
#define AF_STR_HELPER(x) AF_STR_H(x)
40+
#ifdef _MSC_VER
41+
#define AF_TRACE(...) getLogger()->trace("[ " __FILE__ "(" AF_STR_HELPER(__LINE__) ") ] " __VA_ARGS__)
42+
#else
43+
#define AF_TRACE(...) getLogger()->trace("[ " __FILE__ ":" AF_STR_HELPER(__LINE__) " ] " __VA_ARGS__)
44+
#endif
45+
#else
46+
#define AF_TRACE(logger, ...) (void)0
47+
#endif

‎src/backend/common/MemoryManager.hpp‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,9 @@
2222
#include <unordered_map>
2323
#include <vector>
2424

25+
namespace spdlog {
26+
class logger;
27+
}
2528
namespace common
2629
{
2730
using mutex_t = std::mutex;
@@ -74,6 +77,7 @@ class MemoryManager
7477
size_t mem_step_size;
7578
unsigned max_buffers;
7679
std::vector<memory_info> memory;
80+
std::shared_ptr<spdlog::logger> logger;
7781
bool debug_mode;
7882

7983
memory_info& getCurrentMemoryInfo();
@@ -83,7 +87,7 @@ class MemoryManager
8387
void cleanDeviceMemoryManager(int device);
8488

8589
public:
86-
MemoryManager(int num_devices, unsigned max_buffers, bool debug);
90+
MemoryManager(int num_devices, unsigned max_buffers, bool debug);
8791

8892
// Intended to be used with OpenCL backend, where
8993
// users are allowed to add external devices(context, device pair)
@@ -130,6 +134,7 @@ class MemoryManager
130134
inline void nativeFree(void *ptr);
131135
bool checkMemoryLimit();
132136
protected:
137+
spdlog::logger* getLogger();
133138
MemoryManager() = delete;
134139
~MemoryManager() = default;
135140
MemoryManager(const MemoryManager& other) = delete;

‎src/backend/common/MemoryManagerImpl.hpp‎

Lines changed: 36 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,24 @@
1+
/*******************************************************
2+
* Copyright (c) 2018, ArrayFire
3+
* All rights reserved.
4+
*
5+
* This file is distributed under 3-clause BSD license.
6+
* The complete license agreement can be obtained at:
7+
* http://arrayfire.com/licenses/BSD-3-Clause
8+
********************************************************/
19

210
#include <common/MemoryManager.hpp>
11+
#include <common/Logger.hpp>
12+
13+
#include <string>
14+
#include <vector>
15+
16+
using std::max;
17+
using std::stoi;
18+
using std::string;
19+
using std::vector;
20+
21+
using spdlog::logger;
322

423
namespace common
524
{
@@ -26,7 +45,8 @@ void MemoryManager<T>::cleanDeviceMemoryManager(int device) {
2645
// This vector is used to store the pointers which will be deleted by
2746
// the memory manager. We are using this to avoid calling free while
2847
// the lock is being held becasue the CPU backend calls sync.
29-
std::vector<void*> free_ptrs;
48+
vector<void*> free_ptrs;
49+
size_t bytes_freed = 0;
3050
memory_info& current = memory[device];
3151
{
3252
lock_guard_t lock(this->memory_mutex);
@@ -42,10 +62,13 @@ void MemoryManager<T>::cleanDeviceMemoryManager(int device) {
4262
free_ptrs.push_back(p);
4363
}
4464
current.total_bytes -= num_ptrs * kv.first;
65+
bytes_freed += num_ptrs * kv.first;
4566
current.total_buffers -= num_ptrs;
4667
}
4768
current.free_map.clear();
4869
}
70+
71+
AF_TRACE("GC: Clearing {} buffers {}", free_ptrs.size(), bytesToString(bytes_freed));
4972
// Free memory outside of the lock
5073
for(auto ptr : free_ptrs) {
5174
this->nativeFree(ptr);
@@ -54,23 +77,24 @@ void MemoryManager<T>::cleanDeviceMemoryManager(int device) {
5477

5578
template<typename T>
5679
MemoryManager<T>::MemoryManager(int num_devices,
57-
unsigned max_buffers,
58-
bool debug)
80+
unsigned max_buffers,
81+
bool debug)
5982
: mem_step_size(1024),
6083
max_buffers(max_buffers),
6184
memory(num_devices),
62-
debug_mode(debug) {
85+
debug_mode(debug),
86+
logger (loggerFactory("mem")) {
6387
// Check for environment variables
6488

6589
// Debug mode
66-
std::string env_var = getEnvVar("AF_MEM_DEBUG");
90+
string env_var = getEnvVar("AF_MEM_DEBUG");
6791
if (!env_var.empty()) this->debug_mode = env_var[0] != '0';
6892
if (this->debug_mode) mem_step_size = 1;
6993

7094
// Max Buffer count
7195
env_var = getEnvVar("AF_MAX_BUFFERS");
7296
if (!env_var.empty())
73-
this->max_buffers = std::max(1, std::stoi(env_var));
97+
this->max_buffers = max(1, stoi(env_var));
7498
}
7599

76100
template<typename T>
@@ -105,7 +129,7 @@ void MemoryManager<T>::setMaxMemorySize() {
105129
// memsize returned 0, then use 1GB
106130
size_t memsize = this->getMaxMemorySize(n);
107131
memory[n].max_bytes = memsize == 0 ? ONE_GB :
108-
std::max(memsize * 0.75, (double)(memsize - ONE_GB));
132+
max(memsize * 0.75, (double)(memsize - ONE_GB));
109133
}
110134
}
111135

@@ -337,6 +361,11 @@ unsigned MemoryManager<T>::getMaxBuffers() {
337361
return this->max_buffers;
338362
}
339363

364+
template<typename T>
365+
logger* MemoryManager<T>::getLogger() {
366+
return this->logger.get();
367+
}
368+
340369
template<typename T>
341370
void MemoryManager<T>::setMemStepSize(size_t new_step_size) {
342371
lock_guard_t lock(this->memory_mutex);

0 commit comments

Comments
 (0)