Horrible preload logging is gone. spdlogger with updated pattern now used (9031a7bf) · Commits · David Auer / gekkofs

ifs/configure.hpp

+5 −4

Original line number	Diff line number	Diff line
		@@ -7,13 +7,14 @@

		// To enabled logging with info level
		//#define LOG_INFO
		#define LOG_DEBUG
		//#define LOG_TRACE
		//#define LOG_DEBUG
		#define LOG_TRACE
		#define LOG_DAEMON_PATH "/tmp/adafs_daemon.log"

		// Enable logging for daemon
		#define LOG_PRELOAD_DEBUG 1
		#define LOG_PRELOAD_TRACE 1
		//#define LOG_PRELOAD_INFO
		//#define LOG_PRELOAD_DEBUG
		#define LOG_PRELOAD_TRACE
		#define LOG_PRELOAD_PATH "/tmp/adafs_preload.log"

		// If ACM time should be considered

ifs/include/preload/preload.hpp

+4 −15

Original line number	Diff line number	Diff line
		@@ -23,6 +23,9 @@ extern "C" {
		#include <margo.h>
		}

		// third party libs
		#include <extern/spdlog/spdlog.h>

		#include <preload/open_file_map.hpp>
		#include <preload/preload_util.hpp>

		@@ -80,22 +83,8 @@ struct MetadentryUpdateFlags {

		// fs_config is set ONCE in the beginning. It shall not be modified afterwards
		extern shared_ptr<struct FsConfig> fs_config;
		extern shared_ptr<spdlog::logger> ld_logger;

		// TODO get rid of that horrible, disgusting logging X.x
		extern FILE* debug_fd;

		#define LD_LOG_DEBUG(fd, fmt, ...) \
		do { if (LOG_PRELOAD_DEBUG) fprintf(fd, "[" __DATE__ ":" __TIME__ "] [debug] " fmt, ##__VA_ARGS__); fflush(fd); } while (0)
		#define LD_LOG_TRACE(fd, fmt, ...) \
		do { if (LOG_PRELOAD_TRACE) fprintf(fd, "[" __DATE__ ":" __TIME__ "] [trace] " fmt, ##__VA_ARGS__); fflush(fd); } while (0)
		#define LD_LOG_ERROR(fd, fmt, ...) \
		do { fprintf(fd, "[" __DATE__ ":" __TIME__ "] [err] " fmt, ##__VA_ARGS__); fflush(fd); } while (0)
		#define LD_LOG_DEBUG0(fd, fmt) \
		do { if (LOG_PRELOAD_DEBUG) fprintf(fd, "[" __DATE__ ":" __TIME__ "] [debug] " fmt); fflush(fd); } while (0)
		#define LD_LOG_TRACE0(fd, fmt) \
		do { if (LOG_PRELOAD_TRACE) fprintf(fd, "[" __DATE__ ":" __TIME__ "] [trace] " fmt); fflush(fd); } while (0)
		#define LD_LOG_ERROR0(fd, fmt) \
		do { fprintf(fd, "[" __DATE__ ":" __TIME__ "] [err] " fmt); fflush(fd); } while (0)
		#define EUNKNOWN -1

		bool init_ld_argobots();

ifs/include/preload/rpc/ld_rpc_data.hpp

+7 −7

Original line number	Diff line number	Diff line
		@@ -36,27 +36,27 @@ int rpc_send_read(const hg_id_t ipc_read_data_id, const hg_id_t rpc_read_data_id
		auto recipient = get_rpc_node(path);
		if (is_local_op(recipient)) { // local
		ret = margo_create(ld_margo_ipc_id(), daemon_addr(), ipc_read_data_id, &handle);
		LD_LOG_TRACE0(debug_fd, "rpc_send_read to local daemon (IPC)\n");
		ld_logger->debug("{}() to local daemon (IPC)", __func__);
		used_mid = ld_margo_ipc_id();
		} else { // remote
		// TODO HG_ADDR_T is never freed atm. Need to change LRUCache
		if (!get_addr_by_hostid(recipient, svr_addr)) {
		LD_LOG_ERROR(debug_fd, "server address not resolvable for host id %lu\n", recipient);
		ld_logger->error("{}() server address not resolvable for host id {}", __func__, recipient);
		return 1;
		}
		ret = margo_create(ld_margo_rpc_id(), svr_addr, rpc_read_data_id, &handle);
		LD_LOG_TRACE0(debug_fd, "rpc_send_read to remote daemon (RPC)\n");
		ld_logger->debug("{}() to remote daemon (RPC)", __func__);
		used_mid = ld_margo_rpc_id();
		}
		if (ret != HG_SUCCESS) {
		LD_LOG_ERROR0(debug_fd, "creating handle FAILED\n");
		ld_logger->error("{}() creating handle FAILED", __func__);
		return 1;
		}
		/* register local target buffer for bulk access */
		auto b_buf = static_cast<void*>(tar_buf);
		ret = margo_bulk_create(used_mid, 1, &b_buf, &in_size, HG_BULK_WRITE_ONLY, &in.bulk_handle);
		if (ret != 0)
		LD_LOG_ERROR0(debug_fd, "failed to create bulk on client\n");
		ld_logger->error("{}() failed to create bulk on client", __func__);

		int send_ret = HG_FALSE;
		for (int i = 0; i < RPC_TRIES; ++i) {
		@@ -72,12 +72,12 @@ int rpc_send_read(const hg_id_t ipc_read_data_id, const hg_id_t rpc_read_data_id
		tar_buf = static_cast<T*>(b_buf);
		read_size = static_cast<size_t>(out.io_size);
		err = out.res;
		LD_LOG_TRACE(debug_fd, "Got response %d\n", out.res);
		ld_logger->debug("{}() Got response {}", __func__, out.res);
		/* clean up resources consumed by this rpc */
		margo_bulk_free(in.bulk_handle);
		margo_free_output(handle, &out);
		} else {
		LD_LOG_ERROR0(debug_fd, "RPC rpc_send_read (timed out)");
		ld_logger->warn("{}() timed out", __func__);
		err = EAGAIN;
		}

ifs/main.cpp

+7 −3

Original line number	Diff line number	Diff line
		@@ -29,15 +29,19 @@ int main(int argc, const char* argv[]) {

		//set the spdlogger and initialize it with spdlog
		ADAFS_DATA->spdlogger(spdlog::basic_logger_mt("basic_logger", LOG_DAEMON_PATH));
		// set logger format
		spdlog::set_pattern("[%C-%m-%d %H:%M:%S.%f] %P [%L] %v");
		// flush log when info, warning, error messages are encountered
		ADAFS_DATA->spdlogger()->flush_on(spdlog::level::info);
		#if defined(LOG_TRACE)
		spdlog::set_level(spdlog::level::trace);
		ADAFS_DATA->spdlogger()->flush_on(spdlog::level::trace);
		// ADAFS_DATA->spdlogger()->flush_on(spdlog::level::trace);
		#elif defined(LOG_DEBUG)
		spdlog::set_level(spdlog::level::debug);
		ADAFS_DATA->spdlogger()->flush_on(spdlog::level::debug);
		// ADAFS_DATA->spdlogger()->flush_on(spdlog::level::debug);
		#elif defined(LOG_INFO)
		spdlog::set_level(spdlog::level::info);
		ADAFS_DATA->spdlogger()->flush_on(spdlog::level::info);
		// ADAFS_DATA->spdlogger()->flush_on(spdlog::level::info);
		#else
		spdlog::set_level(spdlog::level::off);
		#endif

ifs/src/preload/margo_ipc.cpp

+21 −21

Original line number	Diff line number	Diff line
		@@ -46,10 +46,10 @@ bool ipc_send_get_fs_config(const hg_id_t ipc_get_config_id) {
		in.dummy = 0; // XXX should be removed. havent checked yet how empty input with margo works
		auto ret = margo_create(ld_margo_ipc_id(), daemon_addr(), ipc_get_config_id, &handle);
		if (ret != HG_SUCCESS) {
		LD_LOG_DEBUG0(debug_fd, "creating handle FAILED\n");
		ld_logger->error("{}() creating handle for failed", __func__);
		return false;
		}
		LD_LOG_DEBUG0(debug_fd, "About to send get config IPC to daemon\n");
		ld_logger->debug("{}() About to send get config IPC to daemon", __func__);
		int send_ret = HG_FALSE;
		for (int i = 0; i < RPC_TRIES; ++i) {
		send_ret = margo_forward_timed(handle, &in, RPC_TIMEOUT);
		@@ -59,7 +59,7 @@ bool ipc_send_get_fs_config(const hg_id_t ipc_get_config_id) {
		}
		if (send_ret == HG_SUCCESS) {
		/* decode response */
		LD_LOG_DEBUG0(debug_fd, "Waiting for response\n");
		ld_logger->debug("{}() Waiting for response", __func__);
		ret = margo_get_output(handle, &out);
		if (ret == HG_SUCCESS) {
		fs_config->mountdir = out.mountdir;
		@@ -88,14 +88,14 @@ bool ipc_send_get_fs_config(const hg_id_t ipc_get_config_id) {
		hostmap[i++] = s;
		}
		fs_config->hosts = hostmap;
		LD_LOG_DEBUG(debug_fd, "Got response with mountdir: %s\n", out.mountdir);
		ld_logger->debug("{}() Got response with mountdir {}", __func__, out.mountdir);
		} else {
		printf("[ERR] Retrieving fs configurations from daemon");
		ld_logger->error("{}() Retrieving fs configurations from daemon", __func__);
		}
		/* clean up resources consumed by this rpc */
		margo_free_output(handle, &out);
		} else {
		LD_LOG_ERROR0(debug_fd, "IPC send_get_config (timed out)\n");
		ld_logger->warn("{}() timed out", __func__);
		}

		margo_destroy(handle);
		@@ -113,10 +113,10 @@ int ipc_send_open(const string& path, int flags, const mode_t mode, const hg_id_
		int err = EUNKNOWN;
		auto ret = margo_create(ld_margo_ipc_id(), daemon_addr(), ipc_open_id, &handle);
		if (ret != HG_SUCCESS) {
		LD_LOG_DEBUG0(debug_fd, "creating handle FAILED\n");
		ld_logger->error("{}() creating handle failed", __func__);
		return 1;
		}
		LD_LOG_DEBUG0(debug_fd, "About to send open IPC to daemon\n");
		ld_logger->debug("{}() About to send IPC to daemon", __func__);
		int send_ret = HG_FALSE;
		for (int i = 0; i < RPC_TRIES; ++i) {
		send_ret = margo_forward_timed(handle, &in, RPC_TIMEOUT);
		@@ -126,15 +126,15 @@ int ipc_send_open(const string& path, int flags, const mode_t mode, const hg_id_
		}
		if (send_ret == HG_SUCCESS) {
		/* decode response */
		LD_LOG_DEBUG0(debug_fd, "Waiting for response\n");
		ld_logger->trace("{}() Waiting for response", __func__);
		ret = margo_get_output(handle, &out);

		LD_LOG_DEBUG(debug_fd, "Got response success: %d\n", out.err);
		ld_logger->debug("{}() Got response success: {}", __func__, out.err);
		err = out.err;
		/* clean up resources consumed by this rpc */
		margo_free_output(handle, &out);
		} else {
		LD_LOG_ERROR0(debug_fd, "IPC send_open (timed out)\n");
		ld_logger->warn("{}() timed out");
		}

		margo_destroy(handle);
		@@ -150,10 +150,10 @@ int ipc_send_stat(const string& path, string& attr, const hg_id_t ipc_stat_id) {
		int err;
		auto ret = margo_create(ld_margo_ipc_id(), daemon_addr(), ipc_stat_id, &handle);
		if (ret != HG_SUCCESS) {
		LD_LOG_DEBUG0(debug_fd, "creating handle FAILED\n");
		ld_logger->error("{}() creating handle failed", __func__);
		return 1;
		}
		LD_LOG_DEBUG0(debug_fd, "About to send stat IPC to daemon\n");
		ld_logger->debug("{}() About to send IPC to daemon", __func__);
		int send_ret = HG_FALSE;
		for (int i = 0; i < RPC_TRIES; ++i) {
		send_ret = margo_forward_timed(handle, &in, RPC_TIMEOUT);
		@@ -163,10 +163,10 @@ int ipc_send_stat(const string& path, string& attr, const hg_id_t ipc_stat_id) {
		}
		if (send_ret == HG_SUCCESS) {
		/* decode response */
		LD_LOG_DEBUG0(debug_fd, "Waiting for response\n");
		ld_logger->trace("{}() Waiting for response", __func__);
		ret = margo_get_output(handle, &out);

		LD_LOG_DEBUG(debug_fd, "Got response success: %d\n", out.err);
		ld_logger->debug("{}() Got response success: {}", __func__, out.err);
		err = out.err;
		if (out.err == 0) {
		attr = out.db_val;
		@@ -174,7 +174,7 @@ int ipc_send_stat(const string& path, string& attr, const hg_id_t ipc_stat_id) {
		/* clean up resources consumed by this rpc */
		margo_free_output(handle, &out);
		} else {
		LD_LOG_ERROR0(debug_fd, "IPC send_stat (timed out)\n");
		ld_logger->warn("{}() timed out", __func__);
		err = 1;
		}

		@@ -191,10 +191,10 @@ int ipc_send_unlink(const string& path, const hg_id_t ipc_unlink_id) {
		int err = EUNKNOWN;
		auto ret = margo_create(ld_margo_ipc_id(), daemon_addr(), ipc_unlink_id, &handle);
		if (ret != HG_SUCCESS) {
		LD_LOG_DEBUG0(debug_fd, "creating handle FAILED\n");
		ld_logger->error("{}() creating handle failed", __func__);
		return 1;
		}
		LD_LOG_DEBUG0(debug_fd, "About to send unlink IPC to daemon\n");
		ld_logger->debug("{}() About to send unlink IPC to daemon", __func__);
		int send_ret = HG_FALSE;
		for (int i = 0; i < RPC_TRIES; ++i) {
		send_ret = margo_forward_timed(handle, &in, RPC_TIMEOUT);
		@@ -204,15 +204,15 @@ int ipc_send_unlink(const string& path, const hg_id_t ipc_unlink_id) {
		}
		if (send_ret == HG_SUCCESS) {
		/* decode response */
		LD_LOG_DEBUG0(debug_fd, "Waiting for response\n");
		ld_logger->trace("{}() Waiting for response", __func__);
		ret = margo_get_output(handle, &out);

		LD_LOG_DEBUG(debug_fd, "Got response success: %d\n", out.err);
		ld_logger->debug("{}() Got response success: {}", __func__, out.err);
		err = out.err;
		/* clean up resources consumed by this rpc */
		margo_free_output(handle, &out);
		} else {
		LD_LOG_ERROR0(debug_fd, "IPC send_unlink (timed out)\n");
		ld_logger->warn("{}() timed out", __func__);
		}

		margo_destroy(handle);