public function __call($methodName, $args)
{
$timeStart = microtime(TRUE);
$result = call_user_func_array(array($this->instance, $methodName), $args);
LogHelper::log_info(t('Data Controller execution time for @methodName(): !executionTime', array('@methodName' => $methodName, '!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart))));
return $result;
}
public final function join(JoinController_SourceConfiguration $sourceConfigurationA, JoinController_SourceConfiguration $sourceConfigurationB)
{
$timeStart = microtime(TRUE);
$result = $this->joinSourceConfigurations($sourceConfigurationA, $sourceConfigurationB);
LogHelper::log_info(t('@className execution time: !executionTime', array('@className' => get_class($this), '!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart))));
return $result;
}
public function setValues($values, $expiration = NULL)
{
$timeStart = microtime(TRUE);
$errorEntryNames = parent::setValues($values, $expiration);
$entryCount = count($values);
$errorEntryCount = count($errorEntryNames);
$successfulEntryCount = $entryCount - $errorEntryCount;
LogHelper::log_info(t("[@cacheType] Execution time for @successFlag storing of @entryCount entries is !executionTime", array('@cacheType' => $this->getCacheType(), '@entryCount' => $errorEntryCount == 0 ? $entryCount : ($successfulEntryCount == 0 ? $entryCount : "{$successfulEntryCount} out of {$entryCount}"), '!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart), '@successFlag' => $errorEntryCount == 0 ? 'SUCCESSFUL' : ($successfulEntryCount == 0 ? 'UNSUCCESSFUL' : 'successful'))));
// some errors but also some success
return $errorEntryNames;
}
public function executeQuery(DataControllerCallContext $callcontext, DataSourceMetaData $datasource, $sql, ResultFormatter $resultFormatter)
{
$timeStart = microtime(TRUE);
$records = $this->executeQueryStatement($callcontext, $datasource, $sql, new __SQLDataSourceHandler__QueryExecutionCallbackProxy($this->prepareQueryStatementExecutionCallbackInstance(), $resultFormatter));
LogHelper::log_info(t('Database execution time: !executionTime', array('!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart))));
$count = count($records);
LogHelper::log_info(t('Processed @count record(s)', array('@count' => $count)));
LogHelper::log_debug($records);
return $records;
}
protected function transmitData(DataSourceMetaData $datasource, $serverRequest) {
$COMMENT_MAX_LENGTH__REQUEST_BODY = 10000;
$transmissionResponse->status = FALSE;
$requestURL = $serverRequest->url;
$requestBody = isset($serverRequest->body) ? $serverRequest->body : NULL;
$lengthRequestBody = isset($requestBody) ? strlen($requestBody) : 0;
$httpVersion = '1.1';
$httpMethod = isset($serverRequest->method)
? $serverRequest->method
: (isset($requestBody) ? 'POST' : 'GET');
LogHelper::log_info(t('Request: @httpMethod @requestURL', array('@httpMethod' => $httpMethod, '@requestURL' => $requestURL)));
if (isset($requestBody)) {
LogHelper::log_debug($requestBody);
}
$timeStart = microtime(TRUE);
// checking / opening connection to the database
$serverKey = $this->prepareServerKey($datasource);
$socket = isset($this->sockets[$serverKey]) ? $this->sockets[$serverKey] : NULL;
if (!isset($socket)) {
$socket = fsockopen($datasource->host, $datasource->port, $errno, $errstr);
if ($socket === FALSE) {
$transmissionResponse->error = t(
"Could not connect to the database server: @errorCode-'@errorMessage'",
array('@errorCode' => $errno, '@errorMessage' => $errstr));
return $transmissionResponse;
}
else {
$this->sockets[$serverKey] = $socket;
}
}
// preparing a request
$request = "$httpMethod $requestURL HTTP/$httpVersion\r\nHost: $datasource->host\r\n";
if (isset($serverRequest->authorizationRequired) && $serverRequest->authorizationRequired) {
$request .= 'Authorization: Basic ' . base64_encode($datasource->username . ':' . $datasource->password) . "\r\n";
}
$request .= "Connection: Keep-Alive\r\n";
if (isset($requestBody)) {
$request .= "Content-Type: application/json\r\n";
$request .= 'Content-Length: ' . $lengthRequestBody . "\r\n\r\n";
$request .= $requestBody;
}
// sending the request
$bytesWritten = fwrite($socket, $request . "\r\n");
if ($bytesWritten === FALSE) {
$transmissionResponse->error = t('Could not submit the request to the database server');
return $transmissionResponse;
}
// processing response headers
$headers = NULL;
while (TRUE) {
$header = fgets($socket);
if ($header === FALSE) {
$transmissionResponse->error = t('Could not read the response header');
return $transmissionResponse;
}
else {
$header = trim($header);
if (strlen($header) === 0) {
if (isset($headers)) {
// it is a delimiter between response header and body
break;
}
else {
// empty lines before response header. Should not happen
}
}
// processing only headers with values (':' is default delimiter)
if (strpos($header, ':') !== FALSE) {
list($key, $value) = explode(':', $header, 2);
$headers[strtolower(trim($key))] = trim($value);
}
}
}
// reading response body (if any)
$responseBody = '';
if (isset($headers['transfer-encoding']) && ($headers['transfer-encoding'] == 'chunked')) {
// chunked response support
do {
$bytesToRead = 0;
$line = fgets($socket);
if ($line === FALSE) {
$transmissionResponse->error = t('Could not read the response chunk size');
return $transmissionResponse;
}
$line = rtrim($line);
if (preg_match('(^([0-9a-f]+)(?:;.*)?$)', $line, $match)) {
$bytesToRead = hexdec($match[1]);
$bytesLeft = $bytesToRead;
while ($bytesLeft > 0) {
$read = fread($socket, $bytesLeft + 2);
if ($read === FALSE) {
$transmissionResponse->error = t(
'Could not read the whole response. @bytesLeft bytes left',
array('@bytesLeft' => $bytesLeft));
return $transmissionResponse;
}
else {
$responseBody .= $read;
$bytesLeft -= strlen($read);
}
}
}
} while ($bytesToRead > 0);
}
else {
// Non-chunked response support
$bytesToRead = (isset($headers['content-length']) ? (int) $headers['content-length'] : NULL);
while (!isset($bytesToRead) || ($bytesToRead > 0)) {
$read = isset($bytesToRead) ? fgets($socket, $bytesToRead + 1) : fgets($socket);
if ($read === FALSE) {
if (isset($bytesToRead) && ($bytesToRead > 0)) {
$transmissionResponse->error = t(
'Could not read the whole response. $bytesToRead bytes left',
array('@bytesToRead' => $bytesToRead));
return $transmissionResponse;
}
else {
break;
}
}
else {
$responseBody .= $read;
if (isset($bytesToRead)) {
$bytesToRead -= strlen($read);
}
}
}
}
LogHelper::log_info(t('Database execution time: !executionTime', array('!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart))));
$responseBodyObject = $this->converterJson2PHP->convert($responseBody);
if (!isset($responseBodyObject)) {
$error = t('Database server did not provide parsable response body');
LogHelper::log_error($error);
LogHelper::log_error(t('Response headers:'));
LogHelper::log_error($headers);
LogHelper::log_error(t('Response body:'));
LogHelper::log_error($responseBody);
throw new Exception($error);
}
$transmissionResponse->status = TRUE;
$transmissionResponse->result = $responseBodyObject;
return $transmissionResponse;
}
protected function executeStatement(DataSourceMetaData $datasource, $sql)
{
$timeStart = microtime(TRUE);
$connection = $this->getConnection($datasource);
$affectedRecordCount = 0;
if (self::$STATEMENT_EXECUTION_MODE == self::STATEMENT_EXECUTION_MODE__PROCEED) {
$affectedRecordCount = $this->getExtension('executeStatement')->execute($this, $connection, $sql);
}
LogHelper::log_info(t('Database execution time for @statementCount statement(s): !executionTime', array('@statementCount' => count($sql), '!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($timeStart))));
return $affectedRecordCount;
}
protected function loadMetaModel(AbstractMetaModel $metamodel)
{
$metaModelName = $this->getMetaModelName();
LogHelper::log_notice(t('Loading @metamodelName ...', array('@metamodelName' => $metaModelName)));
$metamodelTimeStart = microtime(TRUE);
$metamodelMemoryUsage = memory_get_usage();
if (isset($this->loaders)) {
// preparing each loader for load operation
foreach ($this->loaders as $loader) {
$loader->prepare($this, $metamodel);
}
$filters = $this->getMetaModelFilters();
// creating a copy of list of loaders. A loader is removed from the list once corresponding load operation is completed
$loaders = $this->loaders;
$finalAttempt = FALSE;
$index = $postponedLoaderCounter = 0;
while (($count = count($loaders)) > 0) {
if ($index >= $count) {
if ($postponedLoaderCounter >= $count) {
if ($finalAttempt) {
// ALL loaders were postponed. There is no data which they depend on
break;
} else {
$finalAttempt = TRUE;
}
}
// resetting indexes to start from first loader
$index = $postponedLoaderCounter = 0;
} elseif ($count == 1) {
// to avoid receiving 'postponed' status from last loader
$finalAttempt = TRUE;
}
$loader = $loaders[$index];
$loaderClassName = get_class($loader);
$loaderTimeStart = microtime(TRUE);
$state = $loader->load($this, $metamodel, $filters, $finalAttempt);
LogHelper::log_info(t("'@loaderClassName' Meta Model Loader execution time: !executionTime", array('@loaderClassName' => $loaderClassName, '!executionTime' => ExecutionPerformanceHelper::formatExecutionTime($loaderTimeStart))));
switch ($state) {
case AbstractMetaModelLoader::LOAD_STATE__SUCCESSFUL:
case AbstractMetaModelLoader::LOAD_STATE__SKIPPED:
unset($loaders[$index]);
$loaders = array_values($loaders);
// re-indexing the array
$postponedLoaderCounter = 0;
$finalAttempt = FALSE;
break;
case AbstractMetaModelLoader::LOAD_STATE__POSTPONED:
LogHelper::log_notice(t("Execution of '@loaderClassName' Meta Model Loader is postponed", array('@loaderClassName' => $loaderClassName)));
$index++;
$postponedLoaderCounter++;
break;
default:
throw new IllegalStateException(t("'@loaderClassName' Meta Model Loader returned unsupported state: @stateName", array('@loaderClassName' => $loaderClassName, '@stateName' => $state)));
}
}
// finalizing loading operation
foreach ($this->loaders as $loader) {
$loader->finalize($this, $metamodel);
}
}
LogHelper::log_info(t('@metamodelName loading time: !loadingTime; Memory consumed: !memoryUsage', array('@metamodelName' => $metaModelName, '!loadingTime' => ExecutionPerformanceHelper::formatExecutionTime($metamodelTimeStart), '!memoryUsage' => memory_get_usage() - $metamodelMemoryUsage)));
}
