2018-02-08 13:32:48 +01:00
|
|
|
|
/*
|
2019-01-09 11:25:21 +01:00
|
|
|
|
* Copyright (c) 2019 ETH Zürich, Educational Development and Technology (LET)
|
2018-02-08 13:32:48 +01:00
|
|
|
|
*
|
|
|
|
|
* This Source Code Form is subject to the terms of the Mozilla Public
|
|
|
|
|
* License, v. 2.0. If a copy of the MPL was not distributed with this
|
|
|
|
|
* file, You can obtain one at http://mozilla.org/MPL/2.0/.
|
|
|
|
|
*/
|
|
|
|
|
|
2018-02-14 15:26:05 +01:00
|
|
|
|
using System.Threading;
|
2018-06-21 07:56:25 +02:00
|
|
|
|
using SafeExamBrowser.Contracts.Communication.Events;
|
2018-03-15 14:32:07 +01:00
|
|
|
|
using SafeExamBrowser.Contracts.Communication.Hosts;
|
|
|
|
|
using SafeExamBrowser.Contracts.Communication.Proxies;
|
2018-08-31 10:06:27 +02:00
|
|
|
|
using SafeExamBrowser.Contracts.Core.OperationModel;
|
2018-10-03 14:35:27 +02:00
|
|
|
|
using SafeExamBrowser.Contracts.Core.OperationModel.Events;
|
2018-02-08 13:32:48 +01:00
|
|
|
|
using SafeExamBrowser.Contracts.I18n;
|
|
|
|
|
using SafeExamBrowser.Contracts.Logging;
|
2018-02-14 15:26:05 +01:00
|
|
|
|
using SafeExamBrowser.Contracts.WindowsApi;
|
2018-07-06 15:57:38 +02:00
|
|
|
|
using SafeExamBrowser.Contracts.WindowsApi.Events;
|
2018-02-08 13:32:48 +01:00
|
|
|
|
|
2018-08-31 10:06:27 +02:00
|
|
|
|
namespace SafeExamBrowser.Runtime.Operations
|
2018-02-08 13:32:48 +01:00
|
|
|
|
{
|
2018-10-12 11:16:59 +02:00
|
|
|
|
internal class ClientOperation : SessionOperation
|
2018-02-08 13:32:48 +01:00
|
|
|
|
{
|
2019-03-28 09:05:18 +01:00
|
|
|
|
private readonly int startup_timeout_ms;
|
|
|
|
|
private readonly int shutdown_timeout_ms;
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private ILogger logger;
|
|
|
|
|
private IProcessFactory processFactory;
|
|
|
|
|
private IProxyFactory proxyFactory;
|
|
|
|
|
private IRuntimeHost runtimeHost;
|
2018-02-08 13:32:48 +01:00
|
|
|
|
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private IProcess ClientProcess
|
2018-09-04 10:58:56 +02:00
|
|
|
|
{
|
2018-10-12 11:16:59 +02:00
|
|
|
|
get { return Context.ClientProcess; }
|
|
|
|
|
set { Context.ClientProcess = value; }
|
2018-09-04 10:58:56 +02:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private IClientProxy ClientProxy
|
2018-09-04 10:58:56 +02:00
|
|
|
|
{
|
2018-10-12 11:16:59 +02:00
|
|
|
|
get { return Context.ClientProxy; }
|
|
|
|
|
set { Context.ClientProxy = value; }
|
2018-09-04 10:58:56 +02:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-12 11:16:59 +02:00
|
|
|
|
public override event ActionRequiredEventHandler ActionRequired { add { } remove { } }
|
|
|
|
|
public override event StatusChangedEventHandler StatusChanged;
|
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
public ClientOperation(
|
2018-02-14 15:26:05 +01:00
|
|
|
|
ILogger logger,
|
|
|
|
|
IProcessFactory processFactory,
|
2018-03-14 11:04:28 +01:00
|
|
|
|
IProxyFactory proxyFactory,
|
2018-03-21 15:28:59 +01:00
|
|
|
|
IRuntimeHost runtimeHost,
|
2018-10-12 11:16:59 +02:00
|
|
|
|
SessionContext sessionContext,
|
2019-03-28 09:05:18 +01:00
|
|
|
|
int startup_timeout_ms,
|
|
|
|
|
int shutdown_timeout_ms) : base(sessionContext)
|
2018-02-08 13:32:48 +01:00
|
|
|
|
{
|
|
|
|
|
this.logger = logger;
|
2018-02-14 15:26:05 +01:00
|
|
|
|
this.processFactory = processFactory;
|
2018-03-14 11:04:28 +01:00
|
|
|
|
this.proxyFactory = proxyFactory;
|
2018-02-14 15:26:05 +01:00
|
|
|
|
this.runtimeHost = runtimeHost;
|
2019-03-28 09:05:18 +01:00
|
|
|
|
this.startup_timeout_ms = startup_timeout_ms;
|
|
|
|
|
this.shutdown_timeout_ms = shutdown_timeout_ms;
|
2018-02-08 13:32:48 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-12 11:16:59 +02:00
|
|
|
|
public override OperationResult Perform()
|
2018-02-08 13:32:48 +01:00
|
|
|
|
{
|
2018-10-03 15:42:50 +02:00
|
|
|
|
StatusChanged?.Invoke(TextKey.OperationStatus_StartClient);
|
2018-02-08 13:32:48 +01:00
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
var success = TryStartClient();
|
2018-02-14 15:26:05 +01:00
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
if (success)
|
2018-02-14 15:26:05 +01:00
|
|
|
|
{
|
2018-10-12 15:23:43 +02:00
|
|
|
|
logger.Info("Successfully started new client instance.");
|
2018-02-14 15:26:05 +01:00
|
|
|
|
}
|
2018-03-21 10:23:15 +01:00
|
|
|
|
else
|
2018-02-08 13:32:48 +01:00
|
|
|
|
{
|
2018-10-12 15:23:43 +02:00
|
|
|
|
logger.Error("Failed to start new client instance! Aborting procedure...");
|
2018-02-14 15:26:05 +01:00
|
|
|
|
}
|
2018-02-28 15:49:06 +01:00
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
return success ? OperationResult.Success : OperationResult.Failed;
|
2018-02-14 15:26:05 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-12 11:16:59 +02:00
|
|
|
|
public override OperationResult Repeat()
|
2018-03-14 11:04:28 +01:00
|
|
|
|
{
|
2018-03-21 10:23:15 +01:00
|
|
|
|
return Perform();
|
2018-03-14 11:04:28 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-12 11:16:59 +02:00
|
|
|
|
public override OperationResult Revert()
|
2018-03-14 11:04:28 +01:00
|
|
|
|
{
|
2018-10-10 09:19:03 +02:00
|
|
|
|
var success = true;
|
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
if (ClientProcess != null && !ClientProcess.HasTerminated)
|
|
|
|
|
{
|
2018-10-03 15:42:50 +02:00
|
|
|
|
StatusChanged?.Invoke(TextKey.OperationStatus_StopClient);
|
2018-10-10 09:19:03 +02:00
|
|
|
|
success = TryStopClient();
|
2018-03-21 10:23:15 +01:00
|
|
|
|
}
|
2018-10-10 09:19:03 +02:00
|
|
|
|
|
|
|
|
|
return success ? OperationResult.Success : OperationResult.Failed;
|
2018-03-14 11:04:28 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private bool TryStartClient()
|
2018-02-14 15:26:05 +01:00
|
|
|
|
{
|
2018-10-12 11:16:59 +02:00
|
|
|
|
var clientExecutable = Context.Next.AppConfig.ClientExecutablePath;
|
|
|
|
|
var clientLogFile = $"{'"' + Context.Next.AppConfig.ClientLogFile + '"'}";
|
2019-01-30 14:43:41 +01:00
|
|
|
|
var clientLogLevel = Context.Next.Settings.LogLevel.ToString();
|
2019-01-23 08:12:15 +01:00
|
|
|
|
var runtimeHostUri = Context.Next.AppConfig.RuntimeAddress;
|
|
|
|
|
var startupToken = Context.Next.StartupToken.ToString("D");
|
2019-03-21 16:05:16 +01:00
|
|
|
|
var uiMode = Context.Next.Settings.UserInterfaceMode.ToString();
|
2018-02-14 15:26:05 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
var clientReady = false;
|
|
|
|
|
var clientReadyEvent = new AutoResetEvent(false);
|
|
|
|
|
var clientReadyEventHandler = new CommunicationEventHandler(() => clientReadyEvent.Set());
|
|
|
|
|
|
|
|
|
|
var clientTerminated = false;
|
|
|
|
|
var clientTerminatedEventHandler = new ProcessTerminatedEventHandler(_ => { clientTerminated = true; clientReadyEvent.Set(); });
|
|
|
|
|
|
2018-03-14 11:04:28 +01:00
|
|
|
|
logger.Info("Starting new client process...");
|
2018-12-11 16:06:10 +01:00
|
|
|
|
runtimeHost.AllowConnection = true;
|
2018-02-16 13:15:16 +01:00
|
|
|
|
runtimeHost.ClientReady += clientReadyEventHandler;
|
2019-03-21 16:05:16 +01:00
|
|
|
|
ClientProcess = processFactory.StartNew(clientExecutable, clientLogFile, clientLogLevel, runtimeHostUri, startupToken, uiMode);
|
2019-03-22 15:41:25 +01:00
|
|
|
|
ClientProcess.Terminated += clientTerminatedEventHandler;
|
2018-02-15 15:42:54 +01:00
|
|
|
|
|
2018-02-22 10:00:18 +01:00
|
|
|
|
logger.Info("Waiting for client to complete initialization...");
|
2019-03-28 09:05:18 +01:00
|
|
|
|
clientReady = clientReadyEvent.WaitOne(startup_timeout_ms);
|
2019-03-22 15:41:25 +01:00
|
|
|
|
|
2018-12-11 16:06:10 +01:00
|
|
|
|
runtimeHost.AllowConnection = false;
|
2019-03-22 15:41:25 +01:00
|
|
|
|
runtimeHost.ClientReady -= clientReadyEventHandler;
|
|
|
|
|
ClientProcess.Terminated -= clientTerminatedEventHandler;
|
|
|
|
|
|
|
|
|
|
if (clientReady && !clientTerminated)
|
|
|
|
|
{
|
|
|
|
|
return TryStartCommunication();
|
|
|
|
|
}
|
2018-02-14 15:26:05 +01:00
|
|
|
|
|
2018-02-22 10:00:18 +01:00
|
|
|
|
if (!clientReady)
|
2018-02-14 15:26:05 +01:00
|
|
|
|
{
|
2019-03-28 09:05:18 +01:00
|
|
|
|
logger.Error($"Failed to start client within {startup_timeout_ms / 1000} seconds!");
|
2019-03-22 15:41:25 +01:00
|
|
|
|
}
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
if (clientTerminated)
|
|
|
|
|
{
|
|
|
|
|
logger.Error("Client instance terminated unexpectedly during initialization!");
|
2018-02-14 15:26:05 +01:00
|
|
|
|
}
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
return false;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
private bool TryStartCommunication()
|
|
|
|
|
{
|
|
|
|
|
var success = false;
|
|
|
|
|
|
2018-03-14 11:13:30 +01:00
|
|
|
|
logger.Info("Client has been successfully started and initialized. Creating communication proxy for client host...");
|
2018-10-12 11:16:59 +02:00
|
|
|
|
ClientProxy = proxyFactory.CreateClientProxy(Context.Next.AppConfig.ClientAddress);
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
if (ClientProxy.Connect(Context.Next.StartupToken))
|
2018-02-14 15:26:05 +01:00
|
|
|
|
{
|
2019-03-22 15:41:25 +01:00
|
|
|
|
logger.Info("Connection with client has been established. Requesting authentication...");
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
var communication = ClientProxy.RequestAuthentication();
|
|
|
|
|
var response = communication.Value;
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
success = communication.Success && ClientProcess.Id == response?.ProcessId;
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
if (success)
|
|
|
|
|
{
|
|
|
|
|
logger.Info("Authentication of client has been successful, client is ready to operate.");
|
|
|
|
|
}
|
|
|
|
|
else
|
|
|
|
|
{
|
|
|
|
|
logger.Error("Failed to verify client integrity!");
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
else
|
2018-02-22 10:00:18 +01:00
|
|
|
|
{
|
2019-03-22 15:41:25 +01:00
|
|
|
|
logger.Error("Failed to connect to client!");
|
2018-02-22 10:00:18 +01:00
|
|
|
|
}
|
|
|
|
|
|
2019-03-22 15:41:25 +01:00
|
|
|
|
return success;
|
2018-02-08 13:32:48 +01:00
|
|
|
|
}
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private bool TryStopClient()
|
2018-02-20 15:15:26 +01:00
|
|
|
|
{
|
2018-03-21 10:23:15 +01:00
|
|
|
|
var success = false;
|
|
|
|
|
|
2018-02-20 15:15:26 +01:00
|
|
|
|
var disconnected = false;
|
|
|
|
|
var disconnectedEvent = new AutoResetEvent(false);
|
|
|
|
|
var disconnectedEventHandler = new CommunicationEventHandler(() => disconnectedEvent.Set());
|
|
|
|
|
|
|
|
|
|
var terminated = false;
|
|
|
|
|
var terminatedEvent = new AutoResetEvent(false);
|
|
|
|
|
var terminatedEventHandler = new ProcessTerminatedEventHandler((_) => terminatedEvent.Set());
|
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
if (ClientProxy != null)
|
|
|
|
|
{
|
|
|
|
|
runtimeHost.ClientDisconnected += disconnectedEventHandler;
|
|
|
|
|
ClientProcess.Terminated += terminatedEventHandler;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
logger.Info("Instructing client to initiate shutdown procedure.");
|
|
|
|
|
ClientProxy.InitiateShutdown();
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
logger.Info("Disconnecting from client communication host.");
|
|
|
|
|
ClientProxy.Disconnect();
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
logger.Info("Waiting for client to disconnect from runtime communication host...");
|
2019-03-28 09:05:18 +01:00
|
|
|
|
disconnected = disconnectedEvent.WaitOne(shutdown_timeout_ms);
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
if (!disconnected)
|
|
|
|
|
{
|
2019-03-28 09:05:18 +01:00
|
|
|
|
logger.Error($"Client failed to disconnect within {shutdown_timeout_ms / 1000} seconds!");
|
2018-11-22 14:36:20 +01:00
|
|
|
|
}
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
logger.Info("Waiting for client process to terminate...");
|
2019-03-28 09:05:18 +01:00
|
|
|
|
terminated = terminatedEvent.WaitOne(shutdown_timeout_ms);
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
if (!terminated)
|
|
|
|
|
{
|
2019-03-28 09:05:18 +01:00
|
|
|
|
logger.Error($"Client failed to terminate within {shutdown_timeout_ms / 1000} seconds!");
|
2018-11-22 14:36:20 +01:00
|
|
|
|
}
|
2018-02-22 10:00:18 +01:00
|
|
|
|
|
2018-11-22 14:36:20 +01:00
|
|
|
|
runtimeHost.ClientDisconnected -= disconnectedEventHandler;
|
|
|
|
|
ClientProcess.Terminated -= terminatedEventHandler;
|
|
|
|
|
}
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
|
|
|
|
if (disconnected && terminated)
|
|
|
|
|
{
|
|
|
|
|
logger.Info("Client has been successfully terminated.");
|
2018-03-21 10:23:15 +01:00
|
|
|
|
success = true;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
|
|
|
|
else
|
|
|
|
|
{
|
2018-02-27 15:28:54 +01:00
|
|
|
|
logger.Warn("Attempting to kill client process since graceful termination failed!");
|
2018-03-21 10:23:15 +01:00
|
|
|
|
success = TryKillClient();
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (success)
|
|
|
|
|
{
|
2018-09-04 10:58:56 +02:00
|
|
|
|
ClientProcess = null;
|
|
|
|
|
ClientProxy = null;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
2018-03-21 10:23:15 +01:00
|
|
|
|
|
|
|
|
|
return success;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-10-10 09:19:03 +02:00
|
|
|
|
private bool TryKillClient(int attempt = 0)
|
2018-02-20 15:15:26 +01:00
|
|
|
|
{
|
|
|
|
|
const int MAX_ATTEMPTS = 5;
|
|
|
|
|
|
|
|
|
|
if (attempt == MAX_ATTEMPTS)
|
|
|
|
|
{
|
|
|
|
|
logger.Error($"Failed to kill client process within {MAX_ATTEMPTS} attempts!");
|
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
return false;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
logger.Info($"Killing client process with ID = {ClientProcess.Id}.");
|
|
|
|
|
ClientProcess.Kill();
|
2018-02-20 15:15:26 +01:00
|
|
|
|
|
2018-03-21 10:23:15 +01:00
|
|
|
|
if (ClientProcess.HasTerminated)
|
2018-02-20 15:15:26 +01:00
|
|
|
|
{
|
|
|
|
|
logger.Info("Client process has terminated.");
|
2018-03-21 10:23:15 +01:00
|
|
|
|
|
|
|
|
|
return true;
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
|
|
|
|
else
|
|
|
|
|
{
|
|
|
|
|
logger.Warn("Failed to kill client process. Trying again...");
|
2018-03-21 10:23:15 +01:00
|
|
|
|
|
2018-03-21 15:28:59 +01:00
|
|
|
|
return TryKillClient(++attempt);
|
2018-02-20 15:15:26 +01:00
|
|
|
|
}
|
|
|
|
|
}
|
2018-02-08 13:32:48 +01:00
|
|
|
|
}
|
|
|
|
|
}
|