in remote/ServerApplication.cpp [195:344]
bool ServerApplication::init(int argc, char* argv[]) {
myTimeStart = std::chrono::steady_clock::now();
if (!myCmdArgs.init(argc, argv)) {
Log::debug("Show help and exit.");
return false;
}
Log::info("Init ServerApplication with transport: %s.", myCmdArgs.getTransportDesc().c_str());
myFactory = std::make_shared<MyServerProcessorFactory>();
#if defined(OS_MAC)
const std::chrono::steady_clock::time_point t0 = std::chrono::steady_clock::now();
if (!CefUtils::loadCefFramework()) {
Log::error("Can't load CEF framework library.");
return false;
}
const std::chrono::steady_clock::time_point t1 = std::chrono::steady_clock::now();
if (Log::isDebugEnabled()) {
auto d1 = std::chrono::duration_cast<std::chrono::milliseconds>(t1 - t0);
Log::debug("Loaded CEF framework library, spent %d ms", (int)d1.count());
}
#elif defined(OS_LINUX)
XInitThreads();
#endif
CefSettings settings;
myCmdArgs.prepareCefSettings(&settings);
myAppHandler = new RemoteAppHandler(myCmdArgs.myChromiumSwitches, settings, myCmdArgs.myCustomSchemes);
myAppHandler->AddRef();
// Read constants from env
TRACE_HANDLERS_LIFESPAN = getBoolEnv("CEF_SERVER_TRACE_HANDLERS_LIFESPAN");
const char* envTraceMessagesRegexp = getenv("CEF_SERVER_TRACE_THRIFT_MESSAGES_REGEXP");
if (envTraceMessagesRegexp != nullptr)
TRACE_THRIFT_MESSAGES_REGEXP = new std::regex(envTraceMessagesRegexp);
// Init watcher thread
myStopWatcher = std::make_shared<CancellationPoint>();
myThreadWatcher = std::thread([&]() {
Log::setThreadName("Watcher");
const std::chrono::milliseconds timeoutWatchMs(getLongEnv("CEF_SERVER_timeoutWatchMs", 5000));
std::chrono::milliseconds timeoutDebugLogMs(getLongEnv("CEF_SERVER_TimeoutStacktraceLogMs", 30 * 1000));
std::chrono::milliseconds timeoutExecutionMs(getLongEnv("CEF_SERVER_ourTimeoutExecutionMs", 5 * 1000));
std::chrono::milliseconds timeoutShuttingDownMs(getLongEnv("CEF_SERVER_ourTimeoutShuttingDownMs", 25 * 1000));
std::chrono::steady_clock::time_point lastDebugLog = std::chrono::steady_clock::now() - timeoutDebugLogMs;
while (true) {
try {
myStopWatcher->wait(std::chrono::milliseconds(timeoutWatchMs));
} catch (const cancelled_error&) {
Log::debug("Watcher thread was stopped.");
return 0;
}
std::this_thread::sleep_for(timeoutWatchMs);
const std::chrono::time_point now(std::chrono::steady_clock::now());
myFactory->forEach([&](const MyServerProcessor* p){
if (!p || !p->getServerHandler()) {
Log::error("Can't be: !p || !p->getServerHandler()");
return;
}
if (!p->getServerHandler()->getCtx())
return;
enum {
ServerHandler,
JavaService,
JavaServiceIO
};
using namespace std::chrono_literals;
std::chrono::duration<float, std::micro> execTimes[] = {0us, 0us, 0us};
const std::chrono::time_point now(std::chrono::steady_clock::now());
// 1. Check ServerHandler timings
if (p->isProcessing())
execTimes[ServerHandler] = now - p->getStartDispatch();
// 2. Check JavaService timings
std::shared_ptr<RpcExecutor> rpcExecutor = p->getServerHandler()->getCtx()->javaService();
if (rpcExecutor && rpcExecutor->isProcessing())
execTimes[JavaService] = now - rpcExecutor->getProcessingStart();
//printDebugIfNecessary(,);
std::shared_ptr<RpcExecutor> rpcExecutorIO = p->getServerHandler()->getCtx()->javaServiceIO();
if (rpcExecutorIO && rpcExecutorIO->isProcessing())
execTimes[JavaServiceIO] = now - rpcExecutorIO->getProcessingStart();
//printDebugIfNecessary(rpcExecutorIO->getProcessingName(),
const bool isTimeoutServerHandler = execTimes[ServerHandler] > timeoutExecutionMs;
const bool isTimeoutJavaService = execTimes[JavaService] > timeoutExecutionMs;
const bool isTimeoutJavaServiceIO = execTimes[JavaServiceIO] > timeoutExecutionMs;
const bool needPrintDebugLog = (now - lastDebugLog) >= timeoutDebugLogMs;
if (isTimeoutServerHandler || isTimeoutJavaService || isTimeoutJavaServiceIO) {
if (needPrintDebugLog) {
Log::warn("Execution time exceeds timeout. Probably deadlock occurred. Events:");
if (isTimeoutServerHandler)
Log::info("Java2Native function '%s' executes more than %d seconds",
p->getFuncName().c_str(), (int)(std::chrono::duration_cast<std::chrono::seconds>(execTimes[ServerHandler])).count());
else if (p->isProcessing())
Log::info("Java2Native function '%s' was started.", p->getFuncName().c_str());
else
Log::info("Java2Native function '%s' was finished.", p->getFuncName().c_str());
if (isTimeoutJavaService)
Log::info("Native2Java function '%s' executes more than %d seconds",
rpcExecutor->getProcessingName().c_str(), (int)(std::chrono::duration_cast<std::chrono::seconds>(execTimes[JavaService])).count());
else if (rpcExecutor->isProcessing())
Log::info("Native2Java function '%s' was started.", rpcExecutor->getProcessingName().c_str());
else
Log::info("Native2Java function '%s' was finished.", rpcExecutor->getProcessingName().c_str());
if (isTimeoutJavaServiceIO)
Log::info("Native2Java IO function '%s' executes more than %d seconds",
rpcExecutorIO->getProcessingName().c_str(), (int)(std::chrono::duration_cast<std::chrono::seconds>(execTimes[JavaServiceIO])).count());
else if (rpcExecutorIO->isProcessing())
Log::info("Native2Java IO function '%s' was started.", rpcExecutorIO->getProcessingName().c_str());
else
Log::info("Native2Java IO function '%s' was finished.", rpcExecutorIO->getProcessingName().c_str());
}
}
});
// 3. Check application timings
bool needShutdownHard = false;
{
Lock lock(myMutexState);
if (myState >= SS_SHUTTING_DOWN) {
std::chrono::duration<float, std::micro> elapsed = now - myTimeStartShuttingDown;
if (elapsed > timeoutShuttingDownMs) {
Log::warn("Start hard shutdown (elapsed %d ms)", std::chrono::duration_cast<std::chrono::milliseconds>(elapsed).count());
myState = SS_SHUTDOWN;
needShutdownHard = true;
}
}
}
if (needShutdownHard) {
CefPostTask(TID_UI, base::BindOnce(CefQuitMessageLoop));
Log::debug("CefQuitMessageLoop is posted (to be executed on UI thread), wait a little before exit...");
std::this_thread::sleep_for(std::chrono::milliseconds(2000));
Log::debug("Buy [%s]!", myCmdArgs.getTransportDesc().c_str());
std::exit(0);
}
}
});
myThreadWatcher.detach();
return true;
}