tdesktop/Telegram/SourceFiles/logs.cpp

601 lines
17 KiB
C++
Raw Normal View History

/*
This file is part of Telegram Desktop,
the official desktop application for the Telegram messaging service.
For license and copyright information please follow this link:
https://github.com/telegramdesktop/tdesktop/blob/master/LEGAL
*/
2016-03-24 13:27:34 +00:00
#include "logs.h"
2017-03-04 10:23:56 +00:00
#include "platform/platform_specific.h"
#include "core/crash_reports.h"
#include "core/launcher.h"
#include "mtproto/facade.h"
namespace {
std::atomic<int> ThreadCounter/* = 0*/;
2021-05-12 10:48:44 +00:00
thread_local bool WritingEntryFlag/* = false*/;
class WritingEntryScope final {
public:
WritingEntryScope() {
WritingEntryFlag = true;
}
~WritingEntryScope() {
WritingEntryFlag = false;
}
};
} // namespace
enum LogDataType {
LogDataMain,
LogDataDebug,
LogDataTcp,
LogDataMtp,
LogDataCount
};
QMutex *_logsMutex(LogDataType type, bool clear = false) {
static QMutex *LogsMutexes = 0;
if (clear) {
delete[] LogsMutexes;
LogsMutexes = 0;
} else if (!LogsMutexes) {
LogsMutexes = new QMutex[LogDataCount];
}
return &LogsMutexes[type];
}
QString _logsFilePath(LogDataType type, const QString &postfix = QString()) {
QString path(cWorkingDir());
switch (type) {
2022-11-26 21:20:17 +00:00
case LogDataMain: path += u"log"_q + postfix + u".txt"_q; break;
case LogDataDebug: path += u"DebugLogs/log"_q + postfix + u".txt"_q; break;
case LogDataTcp: path += u"DebugLogs/tcp"_q + postfix + u".txt"_q; break;
case LogDataMtp: path += u"DebugLogs/mtp"_q + postfix + u".txt"_q; break;
}
return path;
}
int32 LogsStartIndexChosen = -1;
QString _logsEntryStart() {
static thread_local auto threadId = ThreadCounter++;
static auto index = 0;
const auto tm = QDateTime::currentDateTime();
return QString("[%1 %2-%3]").arg(tm.toString("hh:mm:ss.zzz"), QString("%1").arg(threadId, 2, 10, QChar('0'))).arg(++index, 7, 10, QChar('0'));
}
class LogsDataFields {
public:
LogsDataFields() {
for (int32 i = 0; i < LogDataCount; ++i) {
files[i].reset(new QFile());
}
}
bool openMain() {
2022-11-29 21:46:36 +00:00
return reopen(LogDataMain, 0, u"start"_q);
}
void closeMain() {
QMutexLocker lock(_logsMutex(LogDataMain));
2021-05-12 10:48:44 +00:00
WritingEntryScope scope;
2018-06-10 07:46:15 +00:00
const auto file = files[LogDataMain].get();
if (file && file->isOpen()) {
file->close();
}
}
bool instanceChecked() {
return reopen(LogDataMain, 0, QString());
}
QString full() {
2018-06-10 07:46:15 +00:00
const auto file = files[LogDataMain].get();
2021-06-01 12:39:19 +00:00
if (!file || !file->isOpen()) {
return QString();
}
2018-06-10 07:46:15 +00:00
QFile out(file->fileName());
if (out.open(QIODevice::ReadOnly)) {
return QString::fromUtf8(out.readAll());
}
return QString();
}
void write(LogDataType type, const QString &msg) {
QMutexLocker lock(_logsMutex(type));
2021-05-12 10:48:44 +00:00
WritingEntryScope scope;
2018-06-10 07:46:15 +00:00
if (type != LogDataMain) {
reopenDebug();
}
const auto file = files[type].get();
if (!file || !file->isOpen()) {
return;
}
file->write(msg.toUtf8());
file->flush();
}
private:
std::unique_ptr<QFile> files[LogDataCount];
2016-01-30 18:24:18 +00:00
int32 part = -1;
bool reopen(LogDataType type, int32 dayIndex, const QString &postfix) {
2018-06-10 07:46:15 +00:00
if (files[type] && files[type]->isOpen()) {
if (type == LogDataMain) {
if (!postfix.isEmpty()) {
return true;
}
} else {
files[type]->close();
}
}
2017-08-31 16:28:58 +00:00
auto mode = QIODevice::WriteOnly | QIODevice::Text;
if (type == LogDataMain) { // we can call LOG() in LogDataMain reopen - mutex not locked
if (postfix.isEmpty()) { // instance checked, need to move to log.txt
Assert(!files[type]->fileName().isEmpty()); // one of log_startXX.txt should've been opened already
auto to = std::make_unique<QFile>(_logsFilePath(type, postfix));
if (to->exists() && !to->remove()) {
2021-04-05 06:19:33 +00:00
LOG(("Could not delete '%1' file to start new logging: %2").arg(to->fileName(), to->errorString()));
return false;
}
if (auto from = QFile(files[type]->fileName()); !from.copy(to->fileName())) { // don't close files[type] yet
LOG(("Could not copy '%1' to '%2' to start new logging: %3").arg(files[type]->fileName(), to->fileName(), from.errorString()));
return false;
}
if (to->open(mode | QIODevice::Append)) {
std::swap(files[type], to);
LOG(("Moved logging from '%1' to '%2'!").arg(to->fileName(), files[type]->fileName()));
to->remove();
LogsStartIndexChosen = -1;
QDir working(cWorkingDir()); // delete all other log_startXX.txt that we can
QStringList oldlogs = working.entryList(QStringList("log_start*.txt"), QDir::Files);
for (QStringList::const_iterator i = oldlogs.cbegin(), e = oldlogs.cend(); i != e; ++i) {
2022-11-26 21:20:17 +00:00
QString oldlog = cWorkingDir() + *i, oldlogend = i->mid(u"log_start"_q.size());
if (oldlogend.size() == 1 + u".txt"_q.size() && oldlogend.at(0).isDigit() && base::StringViewMid(oldlogend, 1) == u".txt"_q) {
2021-03-15 15:21:37 +00:00
bool removed = QFile(oldlog).remove();
LOG(("Old start log '%1' found, deleted: %2").arg(*i, Logs::b(removed)));
}
}
return true;
}
2021-04-05 06:19:33 +00:00
LOG(("Could not open '%1' file to start new logging: %2").arg(to->fileName(), to->errorString()));
return false;
} else {
bool found = false;
int32 oldest = -1; // find not existing log_startX.txt or pick the oldest one (by lastModified)
QDateTime oldestLastModified;
for (int32 i = 0; i < 10; ++i) {
2022-11-29 21:46:36 +00:00
QString trying = _logsFilePath(type, u"_start%1"_q.arg(i));
files[type]->setFileName(trying);
if (!files[type]->exists()) {
LogsStartIndexChosen = i;
found = true;
break;
}
QDateTime lastModified = QFileInfo(trying).lastModified();
if (oldest < 0 || lastModified < oldestLastModified) {
oldestLastModified = lastModified;
oldest = i;
}
}
if (!found) {
2022-11-29 21:46:36 +00:00
files[type]->setFileName(_logsFilePath(type, u"_start%1"_q.arg(oldest)));
LogsStartIndexChosen = oldest;
}
}
} else {
files[type]->setFileName(_logsFilePath(type, postfix));
if (files[type]->exists()) {
if (files[type]->open(QIODevice::ReadOnly | QIODevice::Text)) {
if (QString::fromUtf8(files[type]->readLine()).toInt() == dayIndex) {
mode |= QIODevice::Append;
}
files[type]->close();
}
} else {
2022-11-26 21:20:17 +00:00
QDir().mkdir(cWorkingDir() + u"DebugLogs"_q);
}
}
if (files[type]->open(mode)) {
if (type != LogDataMain) {
2018-06-10 07:46:15 +00:00
files[type]->write(((mode & QIODevice::Append)
? qsl("\
----------------------------------------------------------------\n\
NEW LOGGING INSTANCE STARTED!!!\n\
----------------------------------------------------------------\n")
2018-06-10 07:46:15 +00:00
: qsl("%1\n").arg(dayIndex)).toUtf8());
files[type]->flush();
}
return true;
} else if (type != LogDataMain) {
2021-04-05 06:19:33 +00:00
LOG(("Could not open debug log '%1': %2").arg(files[type]->fileName(), files[type]->errorString()));
}
return false;
}
void reopenDebug() {
time_t t = time(NULL);
struct tm tm;
mylocaltime(&tm, &t);
static const int switchEach = 15; // minutes
int32 newPart = (tm.tm_min + tm.tm_hour * 60) / switchEach;
if (newPart == part) return;
part = newPart;
int32 dayIndex = (tm.tm_year + 1900) * 10000 + (tm.tm_mon + 1) * 100 + tm.tm_mday;
QString postfix = QString("_%4_%5").arg((part * switchEach) / 60, 2, 10, QChar('0')).arg((part * switchEach) % 60, 2, 10, QChar('0'));
reopen(LogDataDebug, dayIndex, postfix);
reopen(LogDataTcp, dayIndex, postfix);
reopen(LogDataMtp, dayIndex, postfix);
}
};
LogsDataFields *LogsData = 0;
using LogsInMemoryList = QList<QPair<LogDataType, QString>>;
LogsInMemoryList *LogsInMemory = 0;
LogsInMemoryList *DeletedLogsInMemory = SharedMemoryLocation<LogsInMemoryList, 0>();
QString LogsBeforeSingleInstanceChecked; // LogsInMemory already dumped in LogsData, but LogsData is about to be deleted
void _logsWrite(LogDataType type, const QString &msg) {
if (LogsData && (type == LogDataMain || LogsStartIndexChosen < 0)) {
if (type == LogDataMain || Logs::DebugEnabled()) {
LogsData->write(type, msg);
}
} else if (LogsInMemory != DeletedLogsInMemory) {
if (!LogsInMemory) {
LogsInMemory = new LogsInMemoryList;
}
LogsInMemory->push_back(qMakePair(type, msg));
} else if (!LogsBeforeSingleInstanceChecked.isEmpty() && type == LogDataMain) {
LogsBeforeSingleInstanceChecked += msg;
}
}
namespace Logs {
namespace {
bool DebugModeEnabled = false;
2023-09-22 20:59:29 +00:00
[[maybe_unused]] void MoveOldDataFiles(const QString &wasDir) {
if (wasDir.isEmpty()) {
return;
}
QFile data(wasDir + "data"), dataConfig(wasDir + "data_config"), tdataConfig(wasDir + "tdata/config");
2021-03-15 15:21:37 +00:00
if (data.exists() && dataConfig.exists() && !QFileInfo::exists(cWorkingDir() + "data") && !QFileInfo::exists(cWorkingDir() + "data_config")) { // move to home dir
LOG(("Copying data to home dir '%1' from '%2'").arg(cWorkingDir(), wasDir));
if (data.copy(cWorkingDir() + "data")) {
LOG(("Copied 'data' to home dir"));
if (dataConfig.copy(cWorkingDir() + "data_config")) {
LOG(("Copied 'data_config' to home dir"));
bool tdataGood = true;
if (tdataConfig.exists()) {
tdataGood = false;
QDir().mkpath(cWorkingDir() + "tdata");
if (tdataConfig.copy(cWorkingDir() + "tdata/config")) {
LOG(("Copied 'tdata/config' to home dir"));
tdataGood = true;
} else {
LOG(("Copied 'data' and 'data_config', but could not copy 'tdata/config'!"));
}
}
if (tdataGood) {
if (data.remove()) {
LOG(("Removed 'data'"));
} else {
LOG(("Could not remove 'data'"));
}
if (dataConfig.remove()) {
LOG(("Removed 'data_config'"));
} else {
LOG(("Could not remove 'data_config'"));
}
if (!tdataConfig.exists() || tdataConfig.remove()) {
LOG(("Removed 'tdata/config'"));
} else {
LOG(("Could not remove 'tdata/config'"));
}
QDir().rmdir(wasDir + "tdata");
}
} else {
LOG(("Copied 'data', but could not copy 'data_config'!!"));
}
} else {
LOG(("Could not copy 'data'!"));
}
}
}
} // namespace
void SetDebugEnabled(bool enabled) {
DebugModeEnabled = enabled;
}
bool DebugEnabled() {
#if defined _DEBUG
return true;
#else
return DebugModeEnabled;
#endif
}
2021-05-12 10:48:44 +00:00
bool WritingEntry() {
return WritingEntryFlag;
}
void start() {
Assert(LogsData == nullptr);
2023-07-22 18:27:45 +00:00
auto &launcher = Core::Launcher::Instance();
if (!launcher.checkPortableVersionFolder()) {
return;
}
LogsData = new LogsDataFields();
if (cWorkingDir().isEmpty()) {
#if (!defined Q_OS_WIN && !defined _DEBUG) || defined Q_OS_WINRT || defined OS_WIN_STORE || defined OS_MAC_STORE
cForceWorkingDir(psAppDataPath());
#else // (!Q_OS_WIN && !_DEBUG) || Q_OS_WINRT || OS_WIN_STORE || OS_MAC_STORE
cForceWorkingDir(cExeDir());
if (!LogsData->openMain()) {
cForceWorkingDir(psAppDataPath());
}
#endif // (!Q_OS_WIN && !_DEBUG) || Q_OS_WINRT || OS_WIN_STORE || OS_MAC_STORE
}
if (launcher.validateCustomWorkingDir()) {
delete LogsData;
LogsData = new LogsDataFields();
}
// WinRT build requires the working dir to stay the same for plugin loading.
#ifndef Q_OS_WINRT
QDir::setCurrent(cWorkingDir());
#endif // !Q_OS_WINRT
2022-11-26 21:20:17 +00:00
QDir().mkpath(cWorkingDir() + u"tdata"_q);
2023-07-22 18:27:45 +00:00
launcher.workingFolderReady();
CrashReports::StartCatching();
if (!LogsData->openMain()) {
delete LogsData;
LogsData = nullptr;
}
LOG(("Launched version: %1, install beta: %2, alpha: %3, debug mode: %4"
).arg(AppVersion
).arg(Logs::b(cInstallBetaVersion())
).arg(cAlphaVersion()
).arg(Logs::b(DebugEnabled())));
LOG(("Executable dir: %1, name: %2").arg(cExeDir(), cExeName()));
LOG(("Initial working dir: %1").arg(launcher.initialWorkingDir()));
LOG(("Working dir: %1").arg(cWorkingDir()));
2023-07-22 18:27:45 +00:00
LOG(("Command line: %1").arg(launcher.arguments().join(' ')));
if (!LogsData) {
LOG(("FATAL: Could not open '%1' for writing log!"
2022-11-29 21:46:36 +00:00
).arg(_logsFilePath(LogDataMain, u"_startXX"_q)));
return;
2016-01-30 18:24:18 +00:00
}
#ifdef Q_OS_WIN
if (cWorkingDir() == psAppDataPath()) { // fix old "Telegram Win (Unofficial)" version
MoveOldDataFiles(psAppDataPathOld());
}
#elif !defined Q_OS_MAC && !defined _DEBUG // fix first version
MoveOldDataFiles(launcher.initialWorkingDir());
#endif
if (LogsInMemory) {
Assert(LogsInMemory != DeletedLogsInMemory);
LogsInMemoryList list = *LogsInMemory;
for (LogsInMemoryList::const_iterator i = list.cbegin(), e = list.cend(); i != e; ++i) {
if (i->first == LogDataMain) {
_logsWrite(i->first, i->second);
}
}
}
LOG(("Logs started"));
}
2016-02-01 10:12:37 +00:00
void finish() {
delete LogsData;
LogsData = 0;
if (LogsInMemory && LogsInMemory != DeletedLogsInMemory) {
delete LogsInMemory;
2016-02-01 10:12:37 +00:00
}
LogsInMemory = DeletedLogsInMemory;
_logsMutex(LogDataMain, true);
2016-02-01 10:12:37 +00:00
CrashReports::FinishCatching();
}
bool started() {
return LogsData != 0;
}
bool instanceChecked() {
if (!LogsData) return false;
2016-02-02 11:48:46 +00:00
if (!LogsData->instanceChecked()) {
LogsBeforeSingleInstanceChecked = Logs::full();
2016-02-01 10:12:37 +00:00
delete LogsData;
LogsData = 0;
LOG(("FATAL: Could not move logging to '%1'!").arg(_logsFilePath(LogDataMain)));
return false;
2016-02-01 10:12:37 +00:00
}
if (LogsInMemory) {
Assert(LogsInMemory != DeletedLogsInMemory);
LogsInMemoryList list = *LogsInMemory;
for (LogsInMemoryList::const_iterator i = list.cbegin(), e = list.cend(); i != e; ++i) {
if (i->first != LogDataMain) {
_logsWrite(i->first, i->second);
}
2016-02-01 10:12:37 +00:00
}
}
if (LogsInMemory) {
Assert(LogsInMemory != DeletedLogsInMemory);
delete LogsInMemory;
}
LogsInMemory = DeletedLogsInMemory;
DEBUG_LOG(("Debug logs started."));
LogsBeforeSingleInstanceChecked.clear();
return true;
}
void multipleInstances() {
if (LogsInMemory) {
Assert(LogsInMemory != DeletedLogsInMemory);
delete LogsInMemory;
2016-02-01 10:12:37 +00:00
}
LogsInMemory = DeletedLogsInMemory;
2016-02-01 10:12:37 +00:00
if (Logs::DebugEnabled()) {
LOG(("WARNING: debug logs are not written in multiple instances mode!"));
}
LogsBeforeSingleInstanceChecked.clear();
}
void closeMain() {
LOG(("Explicitly closing main log and finishing crash handlers."));
if (LogsData) {
LogsData->closeMain();
}
}
void writeMain(const QString &v) {
time_t t = time(NULL);
struct tm tm;
mylocaltime(&tm, &t);
2021-04-20 12:40:54 +00:00
const auto msg = QString("[%1.%2.%3 %4:%5:%6] %7\n"
).arg(tm.tm_year + 1900
).arg(tm.tm_mon + 1, 2, 10, QChar('0')
).arg(tm.tm_mday, 2, 10, QChar('0')
).arg(tm.tm_hour, 2, 10, QChar('0')
).arg(tm.tm_min, 2, 10, QChar('0')
).arg(tm.tm_sec, 2, 10, QChar('0')
).arg(v);
_logsWrite(LogDataMain, msg);
2021-04-20 12:40:54 +00:00
writeDebug(v);
}
2021-04-20 12:40:54 +00:00
void writeDebug(const QString &v) {
const auto msg = QString("%1 %2\n").arg(_logsEntryStart(), v);
_logsWrite(LogDataDebug, msg);
#ifdef Q_OS_WIN
//OutputDebugString(reinterpret_cast<const wchar_t *>(msg.utf16()));
#elif defined Q_OS_MAC
//objc_outputDebugString(msg);
#elif defined _DEBUG
//std::cout << msg.toUtf8().constData();
#endif
}
void writeTcp(const QString &v) {
2021-04-20 12:40:54 +00:00
const auto msg = QString("%1 %2\n").arg(_logsEntryStart(), v);
_logsWrite(LogDataTcp, msg);
}
void writeMtp(int32 dc, const QString &v) {
const auto expanded = [&] {
const auto bare = MTP::isTemporaryDcId(dc)
? MTP::getRealIdFromTemporaryDcId(dc)
: MTP::BareDcId(dc);
const auto base = (MTP::isTemporaryDcId(dc) ? "temporary_" : "")
+ QString::number(bare);
const auto shift = MTP::GetDcIdShift(dc);
if (shift == 0) {
return base + "_main";
} else if (shift == MTP::kExportDcShift) {
return base + "_export";
} else if (shift == MTP::kExportMediaDcShift) {
return base + "_export_download";
} else if (shift == MTP::kConfigDcShift) {
return base + "_config_enumeration";
} else if (shift == MTP::kLogoutDcShift) {
return base + "_logout_guest";
} else if (shift == MTP::kUpdaterDcShift) {
return base + "_download_update";
} else if (shift == MTP::kGroupCallStreamDcShift) {
return base + "_stream";
} else if (MTP::isDownloadDcId(dc)) {
const auto index = shift - MTP::kBaseDownloadDcShift;
return base + "_download" + QString::number(index);
} else if (MTP::isUploadDcId(dc)) {
const auto index = shift - MTP::kBaseUploadDcShift;
return base + "_upload" + QString::number(index);
} else if (shift >= MTP::kDestroyKeyStartDcShift) {
const auto index = shift - MTP::kDestroyKeyStartDcShift;
return base + "_key_destroyer" + QString::number(index);
}
return base + "_unknown" + QString::number(shift);
}();
const auto msg = _logsEntryStart()
+ u" (dc:%1) "_q.arg(expanded)
+ v
+ '\n';
_logsWrite(LogDataMtp, msg);
}
QString full() {
if (LogsData) {
return LogsData->full();
}
if (!LogsInMemory || LogsInMemory == DeletedLogsInMemory) {
return LogsBeforeSingleInstanceChecked;
}
int32 size = LogsBeforeSingleInstanceChecked.size();
for (LogsInMemoryList::const_iterator i = LogsInMemory->cbegin(), e = LogsInMemory->cend(); i != e; ++i) {
if (i->first == LogDataMain) {
size += i->second.size();
}
}
QString result;
result.reserve(size);
if (!LogsBeforeSingleInstanceChecked.isEmpty()) {
result.append(LogsBeforeSingleInstanceChecked);
}
for (LogsInMemoryList::const_iterator i = LogsInMemory->cbegin(), e = LogsInMemory->cend(); i != e; ++i) {
if (i->first == LogDataMain) {
result += i->second;
}
}
return result;
}
} // namespace Logs