From 160bd6ed4f30d3d83fbfa35ba1fb501d59801dee Mon Sep 17 00:00:00 2001 From: Robert Nishihara Date: Thu, 23 Jun 2016 15:34:28 -0700 Subject: [PATCH] log duration of tasks (#150) --- lib/python/ray/worker.py | 5 ++++- src/objstore.cc | 3 ++- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/lib/python/ray/worker.py b/lib/python/ray/worker.py index 976121455..6a44abac6 100644 --- a/lib/python/ray/worker.py +++ b/lib/python/ray/worker.py @@ -1,3 +1,4 @@ +import time import datetime import logging import os @@ -177,9 +178,11 @@ def remote(arg_types, return_types, worker=global_worker): def func_executor(arguments): """This is what gets executed remotely on a worker after a remote function is scheduled by the scheduler.""" logging.info("Calling function {}".format(func.__name__)) + start_time = time.time() result = func(*arguments) + end_time = time.time() check_return_values(func_call, result) # throws an exception if result is invalid - logging.info("Finished executing function {}".format(func.__name__)) + logging.info("Finished executing function {}, it took {} seconds".format(func.__name__, end_time - start_time)) return result def func_call(*args, **kwargs): """This is what gets run immediately when a worker calls a remote function.""" diff --git a/src/objstore.cc b/src/objstore.cc index 242488e88..0fd0ad882 100644 --- a/src/objstore.cc +++ b/src/objstore.cc @@ -156,7 +156,7 @@ Status ObjStoreService::NotifyAlias(ServerContext* context, const NotifyAliasReq Status ObjStoreService::DeallocateObject(ServerContext* context, const DeallocateObjectRequest* request, AckReply* reply) { ObjRef canonical_objref = request->canonical_objref(); - RAY_LOG(RAY_REFCOUNT, "Deallocating canonical_objref " << canonical_objref); + RAY_LOG(RAY_INFO, "Deallocating canonical_objref " << canonical_objref); std::lock_guard memory_lock(memory_lock_); RAY_CHECK_EQ(memory_[canonical_objref].second, MemoryStatusType::READY, "Attempting to deallocate canonical_objref " << canonical_objref << ", but memory_[canonical_objref].second = " << memory_[canonical_objref].second); RAY_CHECK_LT(canonical_objref, memory_.size(), "Attempting to deallocate canonical_objref " << canonical_objref << ", but it is not in the objstore."); @@ -294,6 +294,7 @@ ObjHandle ObjStoreService::alloc(ObjRef objref, size_t size) { void ObjStoreService::object_ready(ObjRef objref, size_t metadata_offset) { { + RAY_LOG(RAY_INFO, "Objref " << objref << " is ready."); std::lock_guard memory_lock(memory_lock_); std::pair& item = memory_[objref]; RAY_CHECK_EQ(item.second, MemoryStatusType::NOT_READY, "A worker notified the object store that objref " << objref << " has been written to the object store, but memory_[objref].second != NOT_READY.");