Add webhook response time to log.

This commit is contained in:
levlam 2021-02-03 17:32:43 +03:00
parent 8b2926a92f
commit f781aab119
2 changed files with 15 additions and 4 deletions

View File

@ -435,6 +435,7 @@ void WebhookActor::load_updates() {
void WebhookActor::drop_event(td::TQueue::EventId event_id) { void WebhookActor::drop_event(td::TQueue::EventId event_id) {
auto it = update_map_.find(event_id); auto it = update_map_.find(event_id);
CHECK(it != update_map_.end());
auto queue_id = it->second.queue_id_; auto queue_id = it->second.queue_id_;
update_map_.erase(it); update_map_.erase(it);
@ -456,7 +457,12 @@ void WebhookActor::drop_event(td::TQueue::EventId event_id) {
void WebhookActor::on_update_ok(td::TQueue::EventId event_id) { void WebhookActor::on_update_ok(td::TQueue::EventId event_id) {
last_update_was_successful_ = true; last_update_was_successful_ = true;
last_success_time_ = td::Time::now(); last_success_time_ = td::Time::now();
VLOG(webhook) << "Receive ok for update " << event_id;
auto it = update_map_.find(event_id);
CHECK(it != update_map_.end());
VLOG(webhook) << "Receive ok for update " << event_id << " in " << (last_success_time_ - it->second.last_send_time_)
<< " seconds";
drop_event(event_id); drop_event(event_id);
} }
@ -466,6 +472,7 @@ void WebhookActor::on_update_error(td::TQueue::EventId event_id, td::Slice error
double now = td::Time::now(); double now = td::Time::now();
auto it = update_map_.find(event_id); auto it = update_map_.find(event_id);
CHECK(it != update_map_.end());
const int MAX_RETRY_AFTER = 3600; const int MAX_RETRY_AFTER = 3600;
retry_after = td::clamp(retry_after, 0, MAX_RETRY_AFTER); retry_after = td::clamp(retry_after, 0, MAX_RETRY_AFTER);
@ -486,7 +493,8 @@ void WebhookActor::on_update_error(td::TQueue::EventId event_id, td::Slice error
update.fail_count_++; update.fail_count_++;
queues_.emplace(update.wakeup_at_, update.queue_id_); queues_.emplace(update.wakeup_at_, update.queue_id_);
VLOG(webhook) << "Delay update " << event_id << " for " << (update.wakeup_at_ - now) << " seconds because of " VLOG(webhook) << "Delay update " << event_id << " for " << (update.wakeup_at_ - now) << " seconds because of "
<< error << " after " << update.fail_count_ << " fails"; << error << " after " << update.fail_count_ << " fails received in " << (now - update.last_send_time_)
<< " seconds";
} }
td::Status WebhookActor::send_update() { td::Status WebhookActor::send_update() {
@ -498,7 +506,8 @@ td::Status WebhookActor::send_update() {
return td::Status::Error("No pending updates"); return td::Status::Error("No pending updates");
} }
auto it = queues_.begin(); auto it = queues_.begin();
if (it->wakeup_at > td::Time::now()) { auto now = td::Time::now();
if (it->wakeup_at > now) {
relax_wakeup_at(it->wakeup_at, "send_update"); relax_wakeup_at(it->wakeup_at, "send_update");
return td::Status::Error("No ready updates"); return td::Status::Error("No ready updates");
} }
@ -508,6 +517,7 @@ td::Status WebhookActor::send_update() {
auto event_id = queue_updates_[queue_id].event_ids.front(); auto event_id = queue_updates_[queue_id].event_ids.front();
auto &update = update_map_[event_id]; auto &update = update_map_[event_id];
update.last_send_time_ = now;
auto body = td::json_encode<td::BufferSlice>(JsonUpdate(update.id_.value(), update.json_)); auto body = td::json_encode<td::BufferSlice>(JsonUpdate(update.id_.value(), update.json_));

View File

@ -94,10 +94,11 @@ class WebhookActor : public td::HttpOutboundConnection::Callback {
td::TQueue::EventId id_; td::TQueue::EventId id_;
td::string json_; td::string json_;
td::int32 expires_at_ = 0; td::int32 expires_at_ = 0;
double last_send_time_ = 0;
double wakeup_at_ = 0; double wakeup_at_ = 0;
int delay_ = 0; int delay_ = 0;
int fail_count_ = 0; int fail_count_ = 0;
td::int64 queue_id_{0}; td::int64 queue_id_ = 0;
}; };
struct QueueUpdates { struct QueueUpdates {