diff options
author | bbiff <bbiff@yandex-team.com> | 2022-07-29 11:15:14 +0300 |
---|---|---|
committer | bbiff <bbiff@yandex-team.com> | 2022-07-29 11:15:14 +0300 |
commit | b45274303f581b597349d67572a79bd4107df5ab (patch) | |
tree | 3a7a9e25ae41fde7f07315c70d227279a21cce88 | |
parent | 6680613e3d1f09a604866924b2a21855ffbeb249 (diff) | |
download | ydb-b45274303f581b597349d67572a79bd4107df5ab.tar.gz |
reduce debug logs
12 files changed, 63 insertions, 52 deletions
diff --git a/library/cpp/actors/interconnect/interconnect_nameserver_dynamic.cpp b/library/cpp/actors/interconnect/interconnect_nameserver_dynamic.cpp index 79007f2738..6ab3d84724 100644 --- a/library/cpp/actors/interconnect/interconnect_nameserver_dynamic.cpp +++ b/library/cpp/actors/interconnect/interconnect_nameserver_dynamic.cpp @@ -34,18 +34,18 @@ namespace NActors { TString str = TStringBuilder() << "\n > Node " << nodeId << " `" << node.Address << "`:" << node.Port << ", host: " << node.Host << ", resolveHost: " << node.ResolveHost; logMsg += str; } - LOG_DEBUG_IC("ICN01", "%s", logMsg.c_str()); + LOG_TRACE_IC("ICN01", "%s", logMsg.c_str()); } bool IsNodeUpdated(const ui32 nodeId, const TString& address, const ui32 port) { bool printInfo = false; auto it = NodeTable.find(nodeId); if (it == NodeTable.end()) { - LOG_DEBUG_IC("ICN02", "New node %u `%s`: %u", + LOG_TRACE_IC("ICN02", "New node %u `%s`: %u", nodeId, address.c_str(), port); printInfo = true; } else if (it->second.Address != address || it->second.Port != port) { - LOG_DEBUG_IC("ICN03", "Updated node %u `%s`: %u (from `%s`: %u)", + LOG_TRACE_IC("ICN03", "Updated node %u `%s`: %u (from `%s`: %u)", nodeId, address.c_str(), port, it->second.Address.c_str(), it->second.Port); printInfo = true; Send(TActivationContext::InterconnectProxy(nodeId), new TEvInterconnect::TEvDisconnect); @@ -132,7 +132,7 @@ namespace NActors { const TActorContext& ctx) { auto request = ev->Get(); - LOG_DEBUG_IC("ICN04", "Update TEvNodesInfo with sz: %lu ", request->Nodes.size()); + LOG_TRACE_IC("ICN04", "Update TEvNodesInfo with sz: %lu ", request->Nodes.size()); bool printInfo = false; ui32 compactionCount = 0; @@ -145,7 +145,7 @@ namespace NActors { for (auto& pending : PendingRequests) { if (pending.Request && pending.Request->Get()->Record.GetNodeId() == node.NodeId) { - LOG_DEBUG_IC("ICN05", "Pending nodeId: %u discovered", node.NodeId); + LOG_TRACE_IC("ICN05", "Pending nodeId: %u discovered", node.NodeId); RegisterWithSameMailbox( CreateResolveActor(node.NodeId, NodeTable[node.NodeId], pending.Request->Sender, SelfId(), pending.Deadline)); pending.Request.Reset(); @@ -169,7 +169,7 @@ namespace NActors { } }; - IActor* CreateDynamicNameserver(const TIntrusivePtr<TTableNameserverSetup>& setup, + IActor* CreateDynamicNameserver(const TIntrusivePtr<TTableNameserverSetup>& setup, const TDuration& pendingPeriod, ui32 poolId) { return new TInterconnectDynamicNameserver(setup, pendingPeriod, poolId); diff --git a/library/cpp/actors/interconnect/logging.h b/library/cpp/actors/interconnect/logging.h index c429d1cade..010a4aa93b 100644 --- a/library/cpp/actors/interconnect/logging.h +++ b/library/cpp/actors/interconnect/logging.h @@ -35,6 +35,7 @@ #define LOG_NOTICE_IC(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT, marker, ::NActors::NLog::PRI_NOTICE, __VA_ARGS__) #define LOG_INFO_IC(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT, marker, ::NActors::NLog::PRI_INFO, __VA_ARGS__) #define LOG_DEBUG_IC(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT, marker, ::NActors::NLog::PRI_DEBUG, __VA_ARGS__) +#define LOG_TRACE_IC(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT, marker, ::NActors::NLog::PRI_TRACE, __VA_ARGS__) #define LOG_EMER_IC_SESSION(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT_SESSION, marker, ::NActors::NLog::PRI_EMER, __VA_ARGS__) #define LOG_ALERT_IC_SESSION(marker, ...) LOG_LOG_IC(::NActorsServices::INTERCONNECT_SESSION, marker, ::NActors::NLog::PRI_ALERT, __VA_ARGS__) diff --git a/ydb/core/kqp/runtime/kqp_channel_storage.cpp b/ydb/core/kqp/runtime/kqp_channel_storage.cpp index d39d009090..9018077eb4 100644 --- a/ydb/core/kqp/runtime/kqp_channel_storage.cpp +++ b/ydb/core/kqp/runtime/kqp_channel_storage.cpp @@ -32,6 +32,8 @@ using namespace NYql::NDq; LOG_CRIT_S(*TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", channelId: " << ChannelId << ". " << s) #define LOG_W(s) \ LOG_WARN_S(*TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", channelId: " << ChannelId << ". " << s) +#define LOG_T(s) \ + LOG_TRACE_S(*TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", channelId: " << ChannelId << ". " << s) namespace { @@ -78,7 +80,7 @@ private: void HandleWork(TEvKqpSpilling::TEvWriteResult::TPtr& ev) { auto& msg = *ev->Get(); - LOG_D("[TEvWriteResult] blobId: " << msg.BlobId); + LOG_T("[TEvWriteResult] blobId: " << msg.BlobId); auto it = WritingBlobs.find(msg.BlobId); if (it == WritingBlobs.end()) { @@ -100,7 +102,7 @@ private: void HandleWork(TEvKqpSpilling::TEvReadResult::TPtr& ev) { auto& msg = *ev->Get(); - LOG_D("[TEvReadResult] blobId: " << msg.BlobId << ", size: " << msg.Blob.size()); + LOG_T("[TEvReadResult] blobId: " << msg.BlobId << ", size: " << msg.Blob.size()); if (LoadingBlobs.erase(msg.BlobId) != 1) { LOG_E("[TEvReadResult] unexpected, blobId: " << msg.BlobId << ", size: " << msg.Blob.size()); diff --git a/ydb/core/yq/libs/actors/pending_fetcher.cpp b/ydb/core/yq/libs/actors/pending_fetcher.cpp index c1eee984a6..9673894fda 100644 --- a/ydb/core/yq/libs/actors/pending_fetcher.cpp +++ b/ydb/core/yq/libs/actors/pending_fetcher.cpp @@ -66,6 +66,8 @@ LOG_INFO_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "Fetcher: " << stream) #define LOG_D(stream) \ LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "Fetcher: " << stream) +#define LOG_T(stream) \ + LOG_TRACE_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "Fetcher: " << stream) namespace NYq { @@ -203,7 +205,7 @@ private: void Handle(TEvInternalService::TEvGetTaskResponse::TPtr& ev) { HasRunningRequest = false; - LOG_D("Got GetTask response from PrivateApi"); + LOG_T("Got GetTask response from PrivateApi"); if (!ev->Get()->Status.IsSuccess()) { LOG_E("Error with GetTask: "<< ev->Get()->Status.GetIssues().ToString()); return; @@ -211,7 +213,7 @@ private: const auto& res = ev->Get()->Result; - LOG_D("Tasks count: " << res.tasks().size()); + LOG_T("Tasks count: " << res.tasks().size()); if (!res.tasks().empty()) { ProcessTask(res); HasRunningRequest = true; @@ -241,7 +243,7 @@ private: void GetPendingTask() { FetcherGeneration++; - LOG_D("Request Private::GetTask" << ", Owner: " << GetOwnerId() << ", Host: " << HostName() << ", Tenant: " << TenantName); + LOG_T("Request Private::GetTask" << ", Owner: " << GetOwnerId() << ", Host: " << HostName() << ", Tenant: " << TenantName); Fq::Private::GetTaskRequest request; request.set_owner_id(GetOwnerId()); request.set_host(HostName()); diff --git a/ydb/core/yq/libs/actors/pinger.cpp b/ydb/core/yq/libs/actors/pinger.cpp index cd42c7f0a7..9060182a50 100644 --- a/ydb/core/yq/libs/actors/pinger.cpp +++ b/ydb/core/yq/libs/actors/pinger.cpp @@ -171,7 +171,7 @@ public: static constexpr char ActorName[] = "YQ_PINGER"; void Bootstrap() { - LOG_D("Start Pinger"); + LOG_T("Start Pinger"); StartLeaseTime = TActivationContext::Now(); // Not accurate value, but it allows us to retry the first unsuccessful ping request. ScheduleNextPing(); Become(&TPingerActor::StateFunc); @@ -187,7 +187,7 @@ private: ) void PassAway() override { - LOG_D("Stop Pinger"); + LOG_T("Stop Pinger"); NActors::TActorBootstrapped<TPingerActor>::PassAway(); } @@ -245,7 +245,7 @@ private: SchedulerCookieHolder.Reset(nullptr); } - LOG_D("Forward ping request: " << ev->Get()->Request); + LOG_T("Forward ping request: " << ev->Get()->Request); if (FatalError) { if (Finishing) { LOG_D("Got final ping request after fatal error"); @@ -333,7 +333,7 @@ private: } if (success) { - LOG_D("Ping response success: " << ev->Get()->Result); + LOG_T("Ping response success: " << ev->Get()->Result); StartLeaseTime = now; auto action = ev->Get()->Result.action(); if (action != YandexQuery::QUERY_ACTION_UNSPECIFIED && !Finishing) { @@ -382,14 +382,14 @@ private: if (!retry && !reqInfo.RetryState) { reqInfo.RetryState.Init(TActivationContext::Now(), StartLeaseTime, Config.PingPeriod); } - LOG_D((retry ? "Retry forward" : "Forward") << " request Private::PingTask"); + LOG_T((retry ? "Retry forward" : "Forward") << " request Private::PingTask"); Ping(reqInfo.Request->Get()->Request, reqInfo.Request->Cookie); } } void Ping(bool retry = false) { - LOG_D((retry ? "Retry request" : "Request") << " Private::PingTask"); + LOG_T((retry ? "Retry request" : "Request") << " Private::PingTask"); Y_VERIFY(!Requested); Requested = true; diff --git a/ydb/core/yq/libs/actors/run_actor.cpp b/ydb/core/yq/libs/actors/run_actor.cpp index f76aff64ed..1dcba28f7d 100644 --- a/ydb/core/yq/libs/actors/run_actor.cpp +++ b/ydb/core/yq/libs/actors/run_actor.cpp @@ -79,6 +79,9 @@ #define LOG_D(stream) \ LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, Params.QueryId << " RunActor : " << stream) +#define LOG_T(stream) \ + LOG_TRACE_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, Params.QueryId << " RunActor : " << stream) + namespace NYq { using namespace NActors; @@ -614,7 +617,7 @@ private: } void Handle(TEvents::TEvForwardPingResponse::TPtr& ev) { - LOG_D("Forward ping response. Success: " << ev->Get()->Success << ". Cookie: " << ev->Cookie); + LOG_T("Forward ping response. Success: " << ev->Get()->Success << ". Cookie: " << ev->Cookie); if (!ev->Get()->Success) { // Failed setting new status or lease was lost ResignQuery(NYql::NDqProto::StatusIds::UNAVAILABLE); return; @@ -640,7 +643,7 @@ private: } void HandleFinish(TEvents::TEvForwardPingResponse::TPtr& ev) { - LOG_D("Forward ping response. Success: " << ev->Get()->Success << ". Cookie: " << ev->Cookie); + LOG_T("Forward ping response. Success: " << ev->Get()->Success << ". Cookie: " << ev->Cookie); if (!ev->Get()->Success) { // Failed setting new status or lease was lost Fail("Failed to write finalizing status"); return; diff --git a/ydb/core/yq/libs/shared_resources/db_pool.cpp b/ydb/core/yq/libs/shared_resources/db_pool.cpp index 5b1fff9913..0fa75f141e 100644 --- a/ydb/core/yq/libs/shared_resources/db_pool.cpp +++ b/ydb/core/yq/libs/shared_resources/db_pool.cpp @@ -75,7 +75,7 @@ public: RequestInProgressTimestamp = TInstant::Now(); const auto& requestVariant = Requests.front(); - LOG_D(ctx, "TDbPoolActor: ProcessQueue " << SelfId() << " Queue size = " << Requests.size()); + LOG_T(ctx, "TDbPoolActor: ProcessQueue " << SelfId() << " Queue size = " << Requests.size()); if (auto pRequest = std::get_if<TRequest>(&requestVariant)) { auto& request = *pRequest; @@ -98,7 +98,7 @@ public: if (state.lock()) { actorSystem->Send(new IEventHandle(selfId, selfId, new TEvents::TEvDbResponse(statusFuture.GetValue(), *sharedResult), 0, cookie)); } else { - LOG_D(*actorSystem, "TDbPoolActor: ProcessQueue " << selfId << " State destroyed"); + LOG_T(*actorSystem, "TDbPoolActor: ProcessQueue " << selfId << " State destroyed"); } }); } else if (auto pRequest = std::get_if<TFunctionRequest>(&requestVariant)) { @@ -113,7 +113,7 @@ public: if (state.lock()) { actorSystem->Send(new IEventHandle(selfId, selfId, new TEvents::TEvDbFunctionResponse(statusFuture.GetValue()), 0, cookie)); } else { - LOG_D(*actorSystem, "TDbPoolActor: ProcessQueue " << selfId << " State destroyed"); + LOG_T(*actorSystem, "TDbPoolActor: ProcessQueue " << selfId << " State destroyed"); } }); } @@ -135,21 +135,21 @@ public: } void HandleResponse(TEvents::TEvDbResponse::TPtr& ev, const TActorContext& ctx) { - LOG_D(ctx, "TDbPoolActor: TEvDbResponse " << SelfId() << " Queue size = " << Requests.size()); + LOG_T(ctx, "TDbPoolActor: TEvDbResponse " << SelfId() << " Queue size = " << Requests.size()); const auto& request = Requests.front(); ctx.Send(ev->Forward(std::visit([](const auto& arg) { return arg.Sender; }, request))); PopFromQueueAndProcess(ctx); } void HandleRequest(TEvents::TEvDbFunctionRequest::TPtr& ev, const TActorContext& ctx) { - LOG_D(ctx, "TDbPoolActor: TEvDbFunctionRequest " << SelfId() << " Queue size = " << Requests.size()); + LOG_T(ctx, "TDbPoolActor: TEvDbFunctionRequest " << SelfId() << " Queue size = " << Requests.size()); auto request = ev->Get(); Requests.emplace_back(TFunctionRequest{ev->Sender, ev->Cookie, std::move(request->Handler)}); ProcessQueue(ctx); } void HandleResponse(TEvents::TEvDbFunctionResponse::TPtr& ev, const TActorContext& ctx) { - LOG_D(ctx, "TDbPoolActor: TEvDbFunctionResponse " << SelfId() << " Queue size = " << Requests.size()); + LOG_T(ctx, "TDbPoolActor: TEvDbFunctionResponse " << SelfId() << " Queue size = " << Requests.size()); const auto& request = Requests.front(); ctx.Send(ev->Forward(std::visit([](const auto& arg) { return arg.Sender; }, request))); PopFromQueueAndProcess(ctx); @@ -200,7 +200,7 @@ private: TDbPool::TDbPool( ui32 sessionsCount, const NYdb::NTable::TTableClient& tableClient, - const ::NMonitoring::TDynamicCounterPtr& counters, + const ::NMonitoring::TDynamicCounterPtr& counters, const TString& tablePathPrefix) { TablePathPrefix = tablePathPrefix; diff --git a/ydb/library/yql/dq/actors/compute/dq_async_compute_actor.cpp b/ydb/library/yql/dq/actors/compute/dq_async_compute_actor.cpp index 685108ff31..0094a0c1b3 100644 --- a/ydb/library/yql/dq/actors/compute/dq_async_compute_actor.cpp +++ b/ydb/library/yql/dq/actors/compute/dq_async_compute_actor.cpp @@ -99,7 +99,7 @@ private: }; void OnStateRequest(TEvDqCompute::TEvStateRequest::TPtr& ev) { - CA_LOG_D("Got TEvStateRequest from actor " << ev->Sender << " TaskId: " << Task.GetId() << " PingCookie: " << ev->Cookie); + CA_LOG_T("Got TEvStateRequest from actor " << ev->Sender << " TaskId: " << Task.GetId() << " PingCookie: " << ev->Cookie); if (!SentStatsRequest) { Send(TaskRunnerActorId, new NTaskRunnerActor::TEvStatistics(GetIds(SinksMap))); SentStatsRequest = true; @@ -178,7 +178,7 @@ private: const i64 toSend = peerState.PeerFreeSpace + allowedOvercommit - peerState.InFlightBytes; - CA_LOG_D("About to drain channelId: " << channelId + CA_LOG_T("About to drain channelId: " << channelId << ", hasPeer: " << outputChannel.HasPeer << ", peerFreeSpace: " << peerState.PeerFreeSpace << ", inFlightBytes: " << peerState.InFlightBytes @@ -221,7 +221,7 @@ private: const i64 sinkFreeSpaceBeforeSend = sinkInfo.AsyncOutput->GetFreeSpace(); i64 toSend = sinkFreeSpaceBeforeSend + allowedOvercommit; - CA_LOG_D("About to drain sink " << outputIndex + CA_LOG_T("About to drain sink " << outputIndex << ". FreeSpace: " << sinkFreeSpaceBeforeSend << ", allowedOvercommit: " << allowedOvercommit << ", toSend: " << toSend @@ -314,7 +314,7 @@ private: PollAsyncInput(); if (ProcessSourcesState.Inflight == 0) { auto req = GetCheckpointRequest(); - CA_LOG_D("DoExecuteImpl: " << (bool) req); + CA_LOG_T("DoExecuteImpl: " << (bool) req); Send(TaskRunnerActorId, new NTaskRunnerActor::TEvContinueRun(std::move(req), /* checkpointOnly = */ false)); } } @@ -386,7 +386,7 @@ private: auto sourcesState = GetSourcesState(); auto status = ev->Get()->RunStatus; - CA_LOG_D("Resume execution, run status: " << status << " checkpoint: " << (bool) ev->Get()->ProgramState); + CA_LOG_T("Resume execution, run status: " << status << " checkpoint: " << (bool) ev->Get()->ProgramState); for (const auto& [channelId, freeSpace] : ev->Get()->InputChannelFreeSpace) { auto it = InputChannelsMap.find(channelId); @@ -437,7 +437,7 @@ private: // source.FreeSpace = ev->Get()->FreeSpace; TODO:XXX get freespace on run ProcessSourcesState.Inflight--; if (ProcessSourcesState.Inflight == 0) { - CA_LOG_D("send TEvContinueRun on OnAsyncInputPushFinished"); + CA_LOG_T("send TEvContinueRun on OnAsyncInputPushFinished"); Send(TaskRunnerActorId, new NTaskRunnerActor::TEvContinueRun()); } } @@ -446,7 +446,7 @@ private: if (ev->Get()->Stats) { TaskRunnerStats = std::move(ev->Get()->Stats); } - CA_LOG_D("OnPopFinished, stats: " << *TaskRunnerStats.Get()); + CA_LOG_T("OnPopFinished, stats: " << *TaskRunnerStats.Get()); auto it = OutputChannelsMap.find(ev->Get()->ChannelId); Y_VERIFY(it != OutputChannelsMap.end()); TOutputChannelInfo& outputChannel = it->second; @@ -578,9 +578,9 @@ private: } Y_VERIFY(batch.empty()); - CA_LOG_D("Sink " << outputIndex << ": sent " << dataSize << " bytes of data and " << checkpointSize << " bytes of checkpoint barrier"); + CA_LOG_T("Sink " << outputIndex << ": sent " << dataSize << " bytes of data and " << checkpointSize << " bytes of checkpoint barrier"); - CA_LOG_D("Drain sink " << outputIndex + CA_LOG_T("Drain sink " << outputIndex << ". Free space decreased: " << (sinkInfo.FreeSpaceBeforeSend - sinkInfo.AsyncOutput->GetFreeSpace()) << ", sent data from buffer: " << dataSize); diff --git a/ydb/library/yql/dq/actors/compute/dq_compute_actor_channels.cpp b/ydb/library/yql/dq/actors/compute/dq_compute_actor_channels.cpp index 920c1a7d19..d66cc6b539 100644 --- a/ydb/library/yql/dq/actors/compute/dq_compute_actor_channels.cpp +++ b/ydb/library/yql/dq/actors/compute/dq_compute_actor_channels.cpp @@ -13,6 +13,9 @@ LOG_ERROR_S(*NActors::TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", task: " << TaskId << ". " << s) #define LOG_C(s) \ LOG_CRIT_S(*NActors::TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", task: " << TaskId << ". " << s) +#define LOG_T(s) \ + LOG_TRACE_S(*NActors::TlsActivationContext, NKikimrServices::KQP_COMPUTE, "TxId: " << TxId << ", task: " << TaskId << ". " << s) + namespace NYql::NDq { @@ -161,7 +164,7 @@ void TDqComputeActorChannels::HandleWork(TEvDqCompute::TEvChannelDataAck::TPtr& TOutputChannelState& outputChannel = OutCh(record.GetChannelId()); - LOG_D("Received channel data ack for channelId: " << record.GetChannelId() + LOG_T("Received channel data ack for channelId: " << record.GetChannelId() << ", seqNo: " << record.GetSeqNo() << ", lastSentSeqNo: " << outputChannel.LastSentSeqNo << ", freeSpace: " << record.GetFreeSpace() @@ -192,7 +195,7 @@ void TDqComputeActorChannels::HandleWork(TEvDqCompute::TEvChannelDataAck::TPtr& outputChannel.PeerState.PeerFreeSpace = record.GetFreeSpace(); - LOG_D("PeerState, freeSpace: " << outputChannel.PeerState.PeerFreeSpace + LOG_T("PeerState, freeSpace: " << outputChannel.PeerState.PeerFreeSpace << ", inflight bytes: " << outputChannel.PeerState.InFlightBytes << ", inflight count: " << outputChannel.PeerState.InFlightCount << ", sentSeqNo: " << outputChannel.LastSentSeqNo @@ -209,13 +212,13 @@ void TDqComputeActorChannels::HandleWork(TEvDqCompute::TEvChannelDataAck::TPtr& return; } - LOG_D("Resume compute actor"); + LOG_T("Resume compute actor"); Cbs->ResumeExecution(); } void TDqComputeActorChannels::HandleWork(TEvDqCompute::TEvRetryChannelData::TPtr& ev) { auto* msg = ev->Get(); - LOG_D("Resend channel data events for output channelId: " << msg->ChannelId + LOG_T("Resend channel data events for output channelId: " << msg->ChannelId << ", seqNo: [" << msg->FromSeqNo << ".." << msg->ToSeqNo << ']'); TOutputChannelState& outputChannel = OutCh(msg->ChannelId); @@ -691,7 +694,7 @@ void TDqComputeActorChannels::SendChannelDataAck(i64 channelId, i64 freeSpace) { } void TDqComputeActorChannels::SendChannelDataAck(TInputChannelState& inputChannel, i64 freeSpace) { - LOG_D("Sending channel data ack to" + LOG_T("Sending channel data ack to" << " channelId: " << inputChannel.ChannelId << ", peer: " << *inputChannel.Peer << ", from: " << Owner diff --git a/ydb/library/yql/dq/actors/compute/dq_compute_actor_impl.h b/ydb/library/yql/dq/actors/compute/dq_compute_actor_impl.h index 7eafdbb4f6..309bacc7de 100644 --- a/ydb/library/yql/dq/actors/compute/dq_compute_actor_impl.h +++ b/ydb/library/yql/dq/actors/compute/dq_compute_actor_impl.h @@ -337,7 +337,7 @@ protected: PollAsyncInput(); ERunStatus status = TaskRunner->Run(); - CA_LOG_D("Resume execution, run status: " << status); + CA_LOG_T("Resume execution, run status: " << status); if (status != ERunStatus::Finished) { PollSources(std::move(sourcesState)); @@ -1070,7 +1070,7 @@ protected: } void HandleExecuteBase(TEvDqCompute::TEvStateRequest::TPtr& ev) { - CA_LOG_D("Got TEvStateRequest from actor " << ev->Sender << " TaskId: " << Task.GetId() << " PingCookie: " << ev->Cookie); + CA_LOG_T("Got TEvStateRequest from actor " << ev->Sender << " TaskId: " << Task.GetId() << " PingCookie: " << ev->Cookie); auto evState = MakeHolder<TEvDqCompute::TEvState>(); evState->Record.SetState(NDqProto::COMPUTE_STATE_EXECUTING); evState->Record.SetStatusCode(NYql::NDqProto::StatusIds::SUCCESS); @@ -1291,7 +1291,7 @@ private: } outputInfo.AsyncOutput->SendData(std::move(dataBatch), dataSize, maybeCheckpoint, outputInfo.Finished); - CA_LOG_D("sink " << outputIndex << ": sent " << dataSize << " bytes of data and " << checkpointSize << " bytes of checkpoint barrier"); + CA_LOG_T("sink " << outputIndex << ": sent " << dataSize << " bytes of data and " << checkpointSize << " bytes of checkpoint barrier"); return dataSize + checkpointSize; } @@ -1478,7 +1478,7 @@ protected: Y_VERIFY(info.AsyncInput); bool finished = false; const i64 space = info.AsyncInput->GetAsyncInputData(batch, finished, freeSpace); - CA_LOG_D("Poll async input " << inputIndex + CA_LOG_T("Poll async input " << inputIndex << ". Buffer free space: " << freeSpace << ", read from async input: " << space << " bytes, " << batch.size() << " rows, finished: " << finished); @@ -1496,7 +1496,7 @@ protected: void PollAsyncInput() { // Don't produce any input from sources if we're about to save checkpoint. if (!Running || (Checkpoints && Checkpoints->HasPendingCheckpoint() && !Checkpoints->ComputeActorStateSaved())) { - CA_LOG_D("Skip polling sources because of pending checkpoint"); + CA_LOG_T("Skip polling sources because of pending checkpoint"); return; } diff --git a/ydb/library/yql/dq/actors/task_runner/task_runner_actor_local.cpp b/ydb/library/yql/dq/actors/task_runner/task_runner_actor_local.cpp index 84a97e14d8..77063c8c09 100644 --- a/ydb/library/yql/dq/actors/task_runner/task_runner_actor_local.cpp +++ b/ydb/library/yql/dq/actors/task_runner/task_runner_actor_local.cpp @@ -22,7 +22,7 @@ #define LOG_E(stream) LOG_ERROR_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "SelfId: " << SelfId() << ", TxId: " << TxId << ", task: " << TaskId << ". " << stream); #define LOG_I(stream) LOG_INFO_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "SelfId: " << SelfId() << ", TxId: " << TxId << ", task: " << TaskId << ". " << stream); #define LOG_D(stream) LOG_DEBUG_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "SelfId: " << SelfId() << ", TxId: " << TxId << ", task: " << TaskId << ". " << stream); - +#define LOG_T(stream) LOG_TRACE_S(*TlsActivationContext, NKikimrServices::YQL_PROXY, "SelfId: " << SelfId() << ", TxId: " << TxId << ", task: " << TaskId << ". " << stream); using namespace NActors; namespace NYql::NDq { @@ -145,7 +145,7 @@ private: THashMap<ui32, ui64> sourcesFreeSpace; if (!ev->Get()->CheckpointOnly) { res = TaskRunner->Run(); - LOG_D("Resume execution, run status: " << res); + LOG_T("Resume execution, run status: " << res); } if (res == ERunStatus::PendingInput) { for (auto& channelId : inputMap) { diff --git a/ydb/library/yql/providers/dq/actors/task_controller.cpp b/ydb/library/yql/providers/dq/actors/task_controller.cpp index d5fbfe8cb0..ef399d1bed 100644 --- a/ydb/library/yql/providers/dq/actors/task_controller.cpp +++ b/ydb/library/yql/providers/dq/actors/task_controller.cpp @@ -122,7 +122,7 @@ private: auto& state = ev->Get()->Record; ui64 taskId = state.GetTaskId(); YQL_LOG_CTX_ROOT_SCOPE(TraceId); - YQL_CLOG(DEBUG, ProviderDq) + YQL_CLOG(TRACE, ProviderDq) << SelfId() << " EvState TaskId: " << taskId << " State: " << state.GetState() @@ -130,7 +130,7 @@ private: << " StatusCode: " << NYql::NDqProto::StatusIds_StatusCode_Name(state.GetStatusCode()); if (state.HasStats() && state.GetStats().GetTasks().size()) { - YQL_CLOG(DEBUG, ProviderDq) << " " << SelfId() << " AddStats " << taskId; + YQL_CLOG(TRACE, ProviderDq) << " " << SelfId() << " AddStats " << taskId; AddStats(state.GetStats()); if (ServiceCounters.Counters && !AggrPeriod) { ExportStats(TaskStat, taskId); @@ -155,7 +155,7 @@ private: } case NDqProto::COMPUTE_STATE_EXECUTING: { Issues.AddIssues(localIssues); - YQL_CLOG(DEBUG, ProviderDq) << " " << SelfId() << " Executing TaskId: " << taskId; + YQL_CLOG(TRACE, ProviderDq) << " " << SelfId() << " Executing TaskId: " << taskId; if (!FinishedTasks.contains(taskId)) { // may get late/reordered? message Executing[taskId] = Now(); @@ -183,7 +183,7 @@ private: for (auto& taskActors: Executing) { if (now > taskActors.second + PingPeriod) { PingCookie++; - YQL_CLOG(DEBUG, ProviderDq) << " Ping TaskId: " << taskActors.first << ", Compute ActorId: " << ActorIds[taskActors.first] << ", PingCookie: " << PingCookie; + YQL_CLOG(TRACE, ProviderDq) << " Ping TaskId: " << taskActors.first << ", Compute ActorId: " << ActorIds[taskActors.first] << ", PingCookie: " << PingCookie; Send(ActorIds[taskActors.first], new NDq::TEvDqCompute::TEvStateRequest(), IEventHandle::FlagTrackDelivery | IEventHandle::FlagGenerateUnsureUndelivered, PingCookie); taskActors.second = now; } @@ -223,7 +223,7 @@ private: } void ExportStats(const TCounters& stat, ui64 taskId) { - YQL_CLOG(DEBUG, ProviderDq) << " " << SelfId() << " ExportStats " << (taskId ? ToString(taskId) : "Summary"); + YQL_CLOG(TRACE, ProviderDq) << " " << SelfId() << " ExportStats " << (taskId ? ToString(taskId) : "Summary"); TString name; std::map<TString, TString> labels; static const TString SourceLabel = "Source"; |