wassname/ray
1
0
Fork 0
mirror of https://github.com/wassname/ray.git synced 2026-07-25 13:30:52 +08:00
Code Issues Packages Projects Releases Wiki Activity

[Core] Improve logging messages. (#11082)

Browse Source
This commit is contained in:
SangBin Cho
2020-09-28 21:07:45 -07:00
committed by GitHub
parent 6cfc1a16a0
commit 0a6164ab15
9 changed files with 48 additions and 38 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/ray/core_worker/profiling.cc
+3 -1
View File
@@ -59,7 +59,9 @@ void Profiler::FlushEvents() {
if (cur_profile_data->profile_events_size() != 0) {
if (!gcs_client_->Stats().AsyncAddProfileData(cur_profile_data, nullptr).ok()) {
RAY_LOG(WARNING) << "Failed to push profile events to GCS.";
RAY_LOG(WARNING)
<< "Failed to push profile events to GCS. This won't affect core Ray, but you "
"might lose profile data, and ray timeline might not work as expected.";
} else {
RAY_LOG(DEBUG) << "Pushed " << cur_profile_data->profile_events_size()
<< " events to GCS.";
src/ray/gcs/gcs_server/gcs_actor_manager.cc
+10 -12
View File
@@ -481,7 +481,7 @@ Status GcsActorManager::CreateActor(const ray::rpc::CreateActorRequest &request,
auto iter = registered_actors_.find(actor_id);
if (iter == registered_actors_.end()) {
RAY_LOG(WARNING) << "Actor " << actor_id << " may be already destroyed.";
RAY_LOG(INFO) << "Actor " << actor_id << " may be already destroyed.";
return Status::Invalid("Actor may be already destroyed.");
}
@@ -558,10 +558,10 @@ void GcsActorManager::PollOwnerForActorOutOfScope(
wait_request, [this, owner_node_id, owner_id, actor_id](
Status status, const rpc::WaitForActorOutOfScopeReply &reply) {
if (!status.ok()) {
RAY_LOG(WARNING) << "Worker " << owner_id << " failed, destroying actor child.";
RAY_LOG(INFO) << "Worker " << owner_id << " failed, destroying actor child.";
} else {
RAY_LOG(WARNING) << "Actor " << actor_id
<< " is out of scope,, destroying actor child.";
RAY_LOG(INFO) << "Actor " << actor_id
<< " is out of scope,, destroying actor child.";
}
auto node_it = owners_.find(owner_node_id);
@@ -699,8 +699,8 @@ void GcsActorManager::OnWorkerDead(const ray::NodeID &node_id,
RAY_LOG(INFO) << "Worker " << worker_id << " on node " << node_id
<< " intentional exit.";
} else {
RAY_LOG(WARNING) << "Worker " << worker_id << " on node " << node_id
<< " failed and exited abnormally.";
RAY_LOG(INFO) << "Worker " << worker_id << " on node " << node_id
<< " failed and exited abnormally.";
}
// Destroy all actors that are owned by this worker.
const auto it = owners_.find(node_id);
@@ -747,7 +747,7 @@ void GcsActorManager::OnWorkerDead(const ray::NodeID &node_id,
}
void GcsActorManager::OnNodeDead(const NodeID &node_id) {
RAY_LOG(WARNING) << "Node " << node_id << " failed, reconstructing actors.";
RAY_LOG(INFO) << "Node " << node_id << " failed, reconstructing actors.";
const auto it = owners_.find(node_id);
if (it != owners_.end()) {
std::vector<ActorID> children_ids;
@@ -816,9 +816,9 @@ void GcsActorManager::ReconstructActor(const ActorID &actor_id, bool need_resche
int64_t remaining = max_restarts - num_restarts;
remaining_restarts = std::max(remaining, static_cast<int64_t>(0));
}
RAY_LOG(WARNING) << "Actor is failed " << actor_id << " on worker " << worker_id
<< " at node " << node_id << ", need_reschedule = " << need_reschedule
<< ", remaining_restarts = " << remaining_restarts;
RAY_LOG(INFO) << "Actor is failed " << actor_id << " on worker " << worker_id
<< " at node " << node_id << ", need_reschedule = " << need_reschedule
<< ", remaining_restarts = " << remaining_restarts;
if (remaining_restarts != 0) {
// num_restarts must be set before updating GCS, or num_restarts will be inconsistent
// between memory cache and storage.
@@ -881,8 +881,6 @@ void GcsActorManager::OnActorCreationSuccess(const std::shared_ptr<GcsActor> &ac
// and GCS server will destroy the actor. The actor creation is asynchronous, it may be
// destroyed before the actor creation is completed.
if (registered_actors_.count(actor_id) == 0) {
RAY_LOG(WARNING) << "Actor is destroyed before the creation is completed, actor id = "
<< actor_id;
return;
}
actor->UpdateState(rpc::ActorTableData::ALIVE);
src/ray/gcs/gcs_server/gcs_node_manager.cc
+2 -1
View File
@@ -405,7 +405,8 @@ std::shared_ptr<rpc::GcsNodeInfo> GcsNodeManager::RemoveNode(
std::ostringstream error_message;
error_message << "The node with node id " << node_id
<< " has been marked dead because the detector"
<< " has missed too many heartbeats from it.";
<< " has missed too many heartbeats from it. This can happen when a "
"raylet crashes unexpectedly or has lagging heartbeats.";
auto error_data_ptr =
gcs::CreateErrorTableData(type, error_message.str(), current_time_ms());
RAY_CHECK_OK(gcs_pub_sub_->Publish(ERROR_INFO_CHANNEL, node_id.Hex(),
src/ray/gcs/gcs_server/gcs_placement_group_manager.cc
+7 -7
View File
@@ -120,8 +120,8 @@ PlacementGroupID GcsPlacementGroupManager::GetPlacementGroupIDByName(
void GcsPlacementGroupManager::OnPlacementGroupCreationFailed(
std::shared_ptr<GcsPlacementGroup> placement_group) {
RAY_LOG(WARNING) << "Failed to create placement group " << placement_group->GetName()
<< ", try again.";
RAY_LOG(INFO) << "Failed to create placement group " << placement_group->GetName()
<< ", try again.";
// We will attempt to schedule this placement_group once an eligible node is
// registered.
auto state = placement_group->GetState();
@@ -219,9 +219,9 @@ void GcsPlacementGroupManager::HandleCreatePlacementGroup(
RAY_LOG(INFO) << "Finished registering placement group, "
<< placement_group->DebugString();
} else {
RAY_LOG(WARNING) << "Failed to register placement group, "
<< placement_group->DebugString()
<< ", cause: " << status.message();
RAY_LOG(INFO) << "Failed to register placement group, "
<< placement_group->DebugString()
<< ", cause: " << status.message();
}
GCS_RPC_SEND_REPLY(send_reply_callback, reply, status);
});
@@ -327,8 +327,8 @@ void GcsPlacementGroupManager::RetryCreatingPlacementGroup() {
}
void GcsPlacementGroupManager::OnNodeDead(const NodeID &node_id) {
RAY_LOG(WARNING) << "Node " << node_id
<< " failed, rescheduling the placement groups on the dead node.";
RAY_LOG(INFO) << "Node " << node_id
<< " failed, rescheduling the placement groups on the dead node.";
auto bundles = gcs_placement_group_scheduler_->GetBundlesOnNode(node_id);
for (const auto &bundle : bundles) {
auto iter = registered_placement_groups_.find(bundle.first);
src/ray/gcs/gcs_server/gcs_placement_group_scheduler.cc
+9 -10
View File
@@ -208,8 +208,8 @@ void GcsPlacementGroupScheduler::ScheduleUnplacedBundles(
// If no nodes are available, scheduling fails.
if (selected_nodes.empty()) {
RAY_LOG(WARNING) << "Failed to schedule placement group "
<< placement_group->GetName() << ", because no nodes are available.";
RAY_LOG(INFO) << "Failed to schedule placement group " << placement_group->GetName()
<< ", because no nodes are available.";
failure_callback(placement_group);
return;
}
@@ -299,8 +299,8 @@ void GcsPlacementGroupScheduler::PrepareResources(
RAY_LOG(INFO) << "Finished leasing resource from " << node_id
<< " for bundle: " << bundle->DebugString();
} else {
RAY_LOG(WARNING) << "Failed to lease resource from " << node_id
<< " for bundle: " << bundle->DebugString();
RAY_LOG(INFO) << "Failed to lease resource from " << node_id
<< " for bundle: " << bundle->DebugString();
}
callback(result);
});
@@ -321,8 +321,8 @@ void GcsPlacementGroupScheduler::CommitResources(
RAY_LOG(INFO) << "Finished committing resource to " << node_id
<< " for bundle: " << bundle->DebugString();
} else {
RAY_LOG(WARNING) << "Failed to commit resource to " << node_id
<< " for bundle: " << bundle->DebugString();
RAY_LOG(INFO) << "Failed to commit resource to " << node_id
<< " for bundle: " << bundle->DebugString();
}
RAY_CHECK(callback);
callback(status);
@@ -333,10 +333,9 @@ void GcsPlacementGroupScheduler::CancelResourceReserve(
const std::shared_ptr<BundleSpecification> &bundle_spec,
const std::shared_ptr<ray::rpc::GcsNodeInfo> &node) {
if (node == nullptr) {
RAY_LOG(WARNING) << "Node for a placement group id "
<< bundle_spec->PlacementGroupId() << " and a bundle index, "
<< bundle_spec->Index()
<< " has already removed. Cancellation request will be ignored.";
RAY_LOG(INFO) << "Node for a placement group id " << bundle_spec->PlacementGroupId()
<< " and a bundle index, " << bundle_spec->Index()
<< " has already removed. Cancellation request will be ignored.";
return;
}
auto node_id = NodeID::FromBinary(node->node_id());
src/ray/gcs/gcs_server/gcs_worker_manager.cc
+3 -1
View File
@@ -30,7 +30,9 @@ void GcsWorkerManager::HandleReportWorkerFailure(
if (request.worker_failure().intentional_disconnect()) {
RAY_LOG(INFO) << log_stream.str();
} else {
RAY_LOG(WARNING) << log_stream.str();
RAY_LOG(WARNING) << log_stream.str()
<< ". If there are lots of this logs, that might indicate there are "
"unexpected failures in the cluster.";
}
auto worker_failure_data = std::make_shared<WorkerTableData>();
worker_failure_data->CopyFrom(request.worker_failure());
src/ray/object_manager/object_manager.cc
+1 -1
View File
@@ -397,7 +397,7 @@ void ObjectManager::Push(const ObjectID &object_id, const NodeID &client_id) {
if (config_.push_timeout_ms == 0) {
// The Push request fails directly when config_.push_timeout_ms == 0.
RAY_LOG(WARNING) << "Invalid Push request ObjectID " << object_id
<< " due to direct timeout setting. ";
<< " due to direct timeout setting. (0 ms timeout)";
} else if (config_.push_timeout_ms > 0) {
// Put the task into a queue and wait for the notification of Object added.
timer.reset(new boost::asio::deadline_timer(*main_service_));
src/ray/raylet/node_manager.cc
+10 -4
View File
@@ -380,7 +380,10 @@ void NodeManager::Heartbeat() {
uint64_t interval = now_ms - last_heartbeat_at_ms_;
if (interval > RayConfig::instance().num_heartbeats_warning() *
RayConfig::instance().raylet_heartbeat_timeout_milliseconds()) {
RAY_LOG(WARNING) << "Last heartbeat was sent " << interval << " ms ago ";
RAY_LOG(WARNING)
<< "Last heartbeat was sent " << interval
<< " ms ago. There might be resource pressure on this node. If heartbeat keeps "
"lagging, this node can be marked as dead mistakenly.";
}
last_heartbeat_at_ms_ = now_ms;
@@ -497,7 +500,8 @@ void NodeManager::DoLocalGC() {
for (const auto &driver : worker_pool_.GetAllRegisteredDrivers()) {
all_workers.push_back(driver);
}
RAY_LOG(WARNING) << "Sending local GC request to " << all_workers.size() << " workers.";
RAY_LOG(WARNING) << "Sending local GC request to " << all_workers.size()
<< " workers. It is due to memory pressure on the local node.";
for (const auto &worker : all_workers) {
rpc::LocalGCRequest request;
worker->rpc_client()->LocalGC(
@@ -536,7 +540,7 @@ void NodeManager::SpillObjects(const std::vector<ObjectID> &objects_ids_to_spill
// the local worker.
if (pinned_objects_.count(id) == 0) {
RAY_LOG(WARNING) << "Requested spill for object that has not yet been marked as "
"the primary copy";
"the primary copy.";
}
}
if (objects_ids.empty()) {
@@ -3460,7 +3464,9 @@ void NodeManager::HandleGlobalGC(const rpc::GlobalGCRequest &request,
}
void NodeManager::TriggerGlobalGC() {
RAY_LOG(WARNING) << "Broadcasting global GC request to all raylets.";
RAY_LOG(WARNING)
<< "Broadcasting global GC request to all raylets. This is usually because "
"clusters have memory pressure, and ray needs to GC unused memory.";
should_global_gc_ = true;
// We won't see our own request, so trigger local GC in the next heartbeat.
should_local_gc_ = true;
src/ray/stats/metric_exporter.cc
+3 -1
View File
@@ -208,7 +208,9 @@ void OpenCensusProtoExporter::ExportViewData(
request_proto, [](const Status &status, const rpc::ReportOCMetricsReply &reply) {
RAY_UNUSED(reply);
if (!status.ok()) {
RAY_LOG(WARNING) << "Export metrics to agent failed: " << status;
RAY_LOG(WARNING)
<< "Export metrics to agent failed: " << status
<< ". This won't affect Ray, but you can lose metrics from the cluster.";
}
});
}