Skip to content

Commit

Permalink
Improve data warehouse export logging (#1223)
Browse files Browse the repository at this point in the history
  • Loading branch information
jtpalmer authored Jan 24, 2020
1 parent 92175ee commit a8069b9
Show file tree
Hide file tree
Showing 7 changed files with 309 additions and 77 deletions.
129 changes: 93 additions & 36 deletions classes/DataWarehouse/Export/BatchProcessor.php
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,15 @@

class BatchProcessor extends Loggable
{
// Constants used in log messages.
const LOG_MODULE_KEY = 'module';
const LOG_MODULE = 'data-warehouse-export';
const LOG_MESSAGE_KEY = 'message';
const LOG_EVENT_KEY = 'event';
const LOG_REQUEST_ID_KEY = 'batch_export_request.id';
const LOG_USER_ID_KEY = 'Users.id';
const LOG_STACKTRACE_KEY = 'stacktrace';

/**
* Database handle for moddb.
* @var \CCR\DB\iDatabase
Expand Down Expand Up @@ -54,9 +63,9 @@ public function __construct(Log $logger = null)
// Must set properties that are used in `setLogger` before calling the
// parent constructor.
$this->fileManager = new FileManager($logger);
$this->queryHandler = new QueryHandler($logger);
parent::__construct($logger);
$this->dbh = DB::factory('database');
$this->queryHandler = new QueryHandler();
$this->realmManager = new RealmManager();
}

Expand All @@ -71,6 +80,7 @@ public function setLogger(Log $logger = null)
{
parent::setLogger($logger);
$this->fileManager->setLogger($logger);
$this->queryHandler->setLogger($logger);
return $this;
}

Expand Down Expand Up @@ -106,7 +116,10 @@ public function processRequests()
*/
private function processSubmittedRequests()
{
$this->logger->info('Processing submitted requests');
$this->logger->info([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Processing submitted requests'
]);
foreach ($this->queryHandler->listSubmittedRecords() as $request) {
$this->processSubmittedRequest($request);
}
Expand All @@ -119,54 +132,70 @@ private function processSubmittedRequests()
*/
private function processSubmittedRequest(array $request)
{
$requestId = $request['id'];
$userId = $request['user_id'];

$this->logger->info([
'message' => 'Processing request',
'batch_export_request.id' => $request['id']
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Processing request',
self::LOG_USER_ID_KEY => $userId,
self::LOG_REQUEST_ID_KEY => $requestId
]);

$user = XDUser::getUserByID($request['user_id']);
$user = XDUser::getUserByID($userId);

if ($user === null) {
$this->logger->err([
'message' => 'User not found',
'Users.id' => $request['user_id'],
'batch_export_request.id' => $request['id']
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'User not found',
self::LOG_USER_ID_KEY => $userId,
self::LOG_REQUEST_ID_KEY => $requestId
]);
return;
}

try {
$this->dbh->beginTransaction();
if (!$this->dryRun) {
$this->queryHandler->submittedToAvailable($request['id']);
$this->queryHandler->submittedToAvailable($requestId);
}
$dataSet = $this->getDataSet($request, $user);
$format = $this->dryRun ? 'null' : $request['export_file_format'];
$dataFile = $this->fileManager->writeDataSetToFile($dataSet, $format);
if (!$this->dryRun) {
$this->fileManager->createZipFile($dataFile, $request);
$zipFile = $this->fileManager->createZipFile($dataFile, $request);
}

$this->logger->info([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_EVENT_KEY => 'CREATED_EXPORT_FILE',
self::LOG_MESSAGE_KEY => 'Created data warehouse export zip file',
self::LOG_USER_ID_KEY => $userId,
self::LOG_REQUEST_ID_KEY => $requestId,
'file_path' => $zipFile
]);

// Delete file that was added to zip archive.
if (!$this->dryRun && !unlink($dataFile)) {
$this->logger->err(sprintf(
'Failed to delete temporary data file "%s"',
$dataFile
));
$this->logger->err([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => sprintf('Failed to delete temporary data file "%s"', $dataFile)
]);
}

// Query for same record to get expiration date.
$request = $this->queryHandler->getRequestRecord($request['id']);
$request = $this->queryHandler->getRequestRecord($requestId);
$this->sendExportSuccessEmail($user, $request);
$this->dbh->commit();
} catch (Exception $e) {
$this->dbh->rollback();
$this->logger->err([
'message' => 'Failed to export data: ' . $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Failed to export data: ' . $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
if (!$this->dryRun) {
$this->queryHandler->submittedToFailed($request['id']);
$this->queryHandler->submittedToFailed($requestId);
}
$this->sendExportFailureEmail($user, $request, $e);
}
Expand All @@ -180,7 +209,10 @@ private function processSubmittedRequest(array $request)
*/
private function processExpiringRequests()
{
$this->logger->info('Processing expiring requests');
$this->logger->info([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Processing expiring requests'
]);
foreach ($this->queryHandler->listExpiringRecords() as $request) {
$this->processExpiringRequest($request);
}
Expand All @@ -194,12 +226,16 @@ private function processExpiringRequests()
private function processExpiringRequest(array $request)
{
$this->logger->info([
'message' => 'Expiring request',
'batch_export_request.id' => $request['id']
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Expiring request',
self::LOG_REQUEST_ID_KEY => $request['id']
]);

if ($this->dryRun) {
$this->logger->notice('dry run: Not expiring export file');
$this->logger->notice([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'dry run: Not expiring export file'
]);
return;
}

Expand All @@ -211,8 +247,9 @@ private function processExpiringRequest(array $request)
} catch (Exception $e) {
$this->dbh->rollback();
$this->logger->err([
'message' => 'Failed to expire record: ' . $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Failed to expire record: ' . $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
}
}
Expand All @@ -225,7 +262,10 @@ private function processExpiringRequest(array $request)
*/
private function processDeletedRequests()
{
$this->logger->info('Processing deleted requests');
$this->logger->info([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Processing deleted requests'
]);
$this->fileManager->removeDeletedRequests(
array_map(
function ($request) {
Expand All @@ -247,20 +287,24 @@ function ($request) {
private function getDataSet(array $request, XDUser $user)
{
$this->logger->info([
'message' => 'Querying data',
'Users.id' => $user->getUserID(),
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Querying data',
self::LOG_USER_ID_KEY => $user->getUserID(),
'user_email' => $user->getEmailAddress(),
'user_first_name' => $user->getFirstName(),
'user_last_name' => $user->getLastName(),
'batch_export_request.id' => $request['id'],
self::LOG_REQUEST_ID_KEY => $request['id'],
'realm' => $request['realm'],
'start_date' => $request['start_date'],
'end_date' => $request['end_date']
]);

try {
$className = $this->realmManager->getRawDataQueryClass($request['realm']);
$this->logger->debug(sprintf('Instantiating query class "%s"', $className));
$this->logger->debug([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => sprintf('Instantiating query class "%s"', $className)
]);
$query = new $className(
[
'start_date' => $request['start_date'],
Expand All @@ -272,8 +316,9 @@ private function getDataSet(array $request, XDUser $user)
return $dataSet;
} catch (Exception $e) {
$this->logger->err([
'message' => $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
throw new Exception('Failed to create batch export query', 0, $e);
}
Expand All @@ -288,11 +333,18 @@ private function getDataSet(array $request, XDUser $user)
private function sendExportSuccessEmail(XDUser $user, array $request)
{
if ($this->dryRun) {
$this->logger->notice('dry run: Not sending success email');
$this->logger->notice([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'dry run: Not sending success email'
]);
return;
}

$this->logger->info('Sending success email');
$this->logger->info([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_EVENT_KEY => 'SENDING_SUCCESS_EMAIL',
self::LOG_MESSAGE_KEY => 'Sending success email'
]);

// Remove time from expiration date time.
list($expirationDate) = explode(' ', $request['export_expires_datetime']);
Expand Down Expand Up @@ -332,13 +384,18 @@ private function sendExportFailureEmail(
Exception $e
) {
if ($this->dryRun) {
$this->logger->notice('dry run: Not sending failure email');
$this->logger->notice([
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'dry run: Not sending failure email'
]);
return;
}

$this->logger->info([
'message' => 'Sending failure email',
'batch_export_request.id' => $request['id']
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_EVENT_KEY => 'SENDING_FAILURE_EMAIL',
self::LOG_MESSAGE_KEY => 'Sending failure email',
self::LOG_REQUEST_ID_KEY => $request['id']
]);

$message = $e->getMessage();
Expand Down
50 changes: 33 additions & 17 deletions classes/DataWarehouse/Export/FileManager.php
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,14 @@
*/
class FileManager extends Loggable
{
// Constants used in log messages.
const LOG_MODULE_KEY = 'module';
const LOG_MODULE = 'data-warehouse-export';
const LOG_MESSAGE_KEY = 'message';
const LOG_STACKTRACE_KEY = 'stacktrace';
const LOG_REQUEST_ID_KEY = 'batch_export_request.id';
const LOG_ZIP_FILE_KEY = 'zip_file';

/**
* Data warehouse batch export directory path.
*
Expand Down Expand Up @@ -50,8 +58,9 @@ public function __construct(Log $logger = null)
);
} catch (Exception $e) {
$this->logger->err([
'message' => $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
throw new Exception('Export directory is not configured', 0, $e);
}
Expand Down Expand Up @@ -149,7 +158,8 @@ public function getZipFileName(array $request)
public function writeDataSetToFile(BatchDataset $dataSet, $format)
{
$this->logger->info([
'message' => 'Writing data to file',
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Writing data to file',
'format' => $format
]);

Expand All @@ -170,7 +180,8 @@ public function writeDataSetToFile(BatchDataset $dataSet, $format)
);

$this->logger->debug([
'message' => 'Created file writer',
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Created file writer',
'file_writer' => $fileWriter
]);

Expand All @@ -185,8 +196,9 @@ public function writeDataSetToFile(BatchDataset $dataSet, $format)
return $dataFile;
} catch (Exception $e) {
$this->logger->err([
'message' => $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
throw new Exception('Failed to write data set to file', 0, $e);
}
Expand All @@ -205,10 +217,11 @@ public function createZipFile($dataFile, array $request)
$zipFile = $this->getExportDataFilePath($request['id']);

$this->logger->info([
'message' => 'Creating zip file',
'batch_export_request.id' => $request['id'],
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Creating zip file',
self::LOG_REQUEST_ID_KEY => $request['id'],
'data_file' => $dataFile,
'zip_file' => $zipFile
self::LOG_ZIP_FILE_KEY => $zipFile
]);

try {
Expand Down Expand Up @@ -245,8 +258,9 @@ public function createZipFile($dataFile, array $request)
return $zipFile;
} catch (Exception $e) {
$this->logger->err([
'message' => $e->getMessage(),
'stacktrace' => $e->getTraceAsString()
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => $e->getMessage(),
self::LOG_STACKTRACE_KEY => $e->getTraceAsString()
]);
throw new Exception('Failed to create zip file', 0, $e);
}
Expand All @@ -263,9 +277,10 @@ public function removeExportFile($id)
$zipFile = $this->getExportDataFilePath($id);

$this->logger->info([
'message' => 'Removing export file',
'batch_export_request.id' => $id,
'zip_file' => $zipFile
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Removing export file',
self::LOG_REQUEST_ID_KEY => $id,
self::LOG_ZIP_FILE_KEY => $zipFile
]);

if (!unlink($zipFile)) {
Expand All @@ -285,9 +300,10 @@ public function removeDeletedRequests(array $deletedRequestIds)
$exportFile = $this->getExportDataFilePath($id);
if (is_file($exportFile)) {
$this->logger->info([
'message' => 'Removing export file',
'batch_export_request.id' => $id,
'zip_file' => $exportFile
self::LOG_MODULE_KEY => self::LOG_MODULE,
self::LOG_MESSAGE_KEY => 'Removing export file',
self::LOG_REQUEST_ID_KEY => $id,
self::LOG_ZIP_FILE_KEY => $exportFile
]);
if (!unlink($exportFile)) {
throw new Exception(sprintf(
Expand Down
Loading

0 comments on commit a8069b9

Please sign in to comment.