Improve log messages with time.

This commit is contained in:
levlam 2022-12-11 01:32:46 +03:00
parent 1f129ecade
commit d2060a2eb3
4 changed files with 14 additions and 15 deletions

View File

@ -783,9 +783,9 @@ class ConfigRecoverer final : public Actor {
}
if (is_connecting_) {
VLOG(config_recoverer) << "Failed to connect for " << Time::now() - connecting_since_;
VLOG(config_recoverer) << "Failed to connect for " << Time::now() - connecting_since_ << " seconds";
} else {
VLOG(config_recoverer) << "Successfully connected in " << Time::now() - connecting_since_;
VLOG(config_recoverer) << "Successfully connected in " << Time::now() - connecting_since_ << " seconds";
}
Timestamp wakeup_timestamp;

View File

@ -11041,7 +11041,7 @@ void ContactsManager::update_user(User *u, UserId user_id, bool from_binlog, boo
auto left_time = get_user_was_online(u, user_id) - G()->server_time_cached();
if (left_time >= 0 && left_time < 30 * 86400) {
left_time += 2.0; // to guarantee expiration
LOG(DEBUG) << "Set online timeout for " << user_id << " in " << left_time;
LOG(DEBUG) << "Set online timeout for " << user_id << " in " << left_time << " seconds";
user_online_timeout_.set_timeout_in(user_id.get(), left_time);
} else {
LOG(DEBUG) << "Cancel online timeout for " << user_id;
@ -11068,7 +11068,7 @@ void ContactsManager::update_user(User *u, UserId user_id, bool from_binlog, boo
auto until_date = u->emoji_status.get_until_date();
auto left_time = until_date - unix_time;
if (left_time >= 0 && left_time < 30 * 86400) {
LOG(DEBUG) << "Set emoji status timeout for " << user_id << " in " << left_time;
LOG(DEBUG) << "Set emoji status timeout for " << user_id << " in " << left_time << " seconds";
user_emoji_status_timeout_.set_timeout_in(user_id.get(), left_time);
} else {
user_emoji_status_timeout_.cancel_timeout(user_id.get());

View File

@ -22,9 +22,9 @@
#include "td/telegram/DownloadManager.h"
#include "td/telegram/EmojiStatus.h"
#include "td/telegram/FolderId.h"
#include "td/telegram/ForumTopicManager.h"
#include "td/telegram/Global.h"
#include "td/telegram/GroupCallManager.h"
#include "td/telegram/ForumTopicManager.h"
#include "td/telegram/InlineQueriesManager.h"
#include "td/telegram/LanguagePackManager.h"
#include "td/telegram/Location.h"
@ -1727,9 +1727,8 @@ void UpdatesManager::after_get_difference() {
VLOG(get_difference) << "Finished to apply " << total_update_count << " postponed updates";
auto passed_time = Time::now() - begin_time;
if (passed_time >= UPDATE_APPLY_WARNING_TIME) {
LOG(WARNING) << "Applied " << total_update_count << " postponed for "
<< (Time::now() - get_difference_start_time_) << " updates in " << chunk_count << " chunks in "
<< passed_time;
LOG(WARNING) << "Applied " << total_update_count << " updates in " << chunk_count << " chunks in " << passed_time
<< " seconds after postponing them for " << (Time::now() - get_difference_start_time_) << " seconds";
}
}
@ -1752,8 +1751,8 @@ void UpdatesManager::after_get_difference() {
<< postponed_pts_updates_.size() << " pending pts updates";
auto passed_time = Time::now() - begin_time;
if (passed_time >= UPDATE_APPLY_WARNING_TIME) {
LOG(WARNING) << "Applied " << update_count << " postponed for " << (Time::now() - get_difference_start_time_)
<< " pts updates in " << passed_time;
LOG(WARNING) << "Applied " << update_count << " pts updates in " << passed_time
<< " seconds after postponing them for " << (Time::now() - get_difference_start_time_) << " seconds";
}
}
@ -2659,7 +2658,7 @@ void UpdatesManager::process_postponed_pts_updates() {
LOG(WARNING) << "PTS has changed from " << initial_pts << " to " << old_pts << " after skipping "
<< skipped_update_count << ", applying " << applied_update_count << " and keeping "
<< postponed_pts_updates_.size() << " postponed for " << (Time::now() - get_difference_start_time_)
<< " updates in " << passed_time;
<< " seconds updates in " << passed_time << " seconds";
}
}
@ -2714,7 +2713,7 @@ void UpdatesManager::process_pending_pts_updates() {
if (passed_time >= UPDATE_APPLY_WARNING_TIME) {
LOG(WARNING) << "PTS has changed from " << initial_pts << " to " << get_pts() << " after applying "
<< applied_update_count << " and keeping " << pending_pts_updates_.size() << " pending updates in "
<< passed_time;
<< passed_time << " seconds";
}
}
@ -2771,7 +2770,7 @@ void UpdatesManager::process_pending_seq_updates() {
if (passed_time >= UPDATE_APPLY_WARNING_TIME) {
LOG(WARNING) << "Seq has changed from " << initial_seq << " to " << seq_ << " after applying "
<< applied_update_count << " and keeping " << pending_seq_updates_.size() << " pending updates in "
<< passed_time;
<< passed_time << " seconds";
}
}
@ -2825,7 +2824,7 @@ void UpdatesManager::process_pending_qts_updates() {
if (passed_time >= UPDATE_APPLY_WARNING_TIME) {
LOG(WARNING) << "QTS has changed from " << initial_qts << " to " << get_qts() << " after applying "
<< applied_update_count << " and keeping " << pending_qts_updates_.size() << " pending updates in "
<< passed_time;
<< passed_time << " seconds";
}
}

View File

@ -34,7 +34,7 @@ static void test_gzencode(const td::string &s) {
auto r = td::gzencode(s, td::max(2, static_cast<int>(100 / s.size())));
ASSERT_TRUE(!r.empty());
LOG(INFO) << "Encoded string of size " << s.size() << " in " << (td::Time::now() - begin_time)
<< " with compression ratio " << static_cast<double>(r.size()) / static_cast<double>(s.size());
<< " seconds with compression ratio " << static_cast<double>(r.size()) / static_cast<double>(s.size());
}
TEST(Gzip, gzencode) {