Apply max execution query time to Live.getCounters API and queryAdjacentVisitorId method (#18852)

7 files changed, 193 insertions, 44 deletions

diff --git a/plugins/Live/Controller.php b/plugins/Live/Controller.php
index 9d1dbc9a6b..5d9590df6b 100644
--- a/plugins/Live/Controller.php
+++ b/plugins/Live/Controller.php
@@ -14,6 +14,7 @@ use Piwik\Config;
 use Piwik\Piwik;
 use Piwik\DataTable;
 use Piwik\Plugins\Goals\API as APIGoals;
+use Piwik\Plugins\Live\Exception\MaxExecutionTimeExceededException;
 use Piwik\Plugins\Live\Visualizations\VisitorLog;
 use Piwik\Url;
 use Piwik\View;
@@ -116,20 +117,40 @@ class Controller extends \Piwik\Plugin\Controller
     private function setCounters($view)
     {
         $segment = Request::getRawSegmentFromRequest();
-        $last30min = Request::processRequest('Live.getCounters', [
-            'idSite' => $this->idSite,
-            'lastMinutes' => 30,
-            'segment' => $segment,
-            'showColumns' => 'visits,actions',
-        ], $default = []);
-        $last30min = $last30min[0];
-        $today = Request::processRequest('Live.getCounters', [
-            'idSite' => $this->idSite,
-            'lastMinutes' => 24 * 60,
-            'segment' => $segment,
-            'showColumns' => 'visits,actions',
-        ], $default = []);
-        $today = $today[0];
+        $executeTodayQuery = true;
+        $view->countErrorToday = '';
+        $view->countErrorHalfHour = '';
+        try {
+            $last30min = Request::processRequest('Live.getCounters', [
+                'idSite' => $this->idSite,
+                'lastMinutes' => 30,
+                'segment' => $segment,
+                'showColumns' => 'visits,actions',
+            ], $default = []);
+            $last30min = $last30min[0];
+        } catch (MaxExecutionTimeExceededException $e) {
+            $last30min = ['visits' => '-', 'actions' => '-'];
+            $today = ['visits' => '-', 'actions' => '-'];
+            $view->countErrorToday = $e->getMessage();
+            $view->countErrorHalfHour = $e->getMessage();
+            $executeTodayQuery = false; // if query for last 30 min failed, we also expect the 24 hour query to fail
+        }
+
+        try {
+            if ($executeTodayQuery) {
+                $today = Request::processRequest('Live.getCounters', [
+                    'idSite' => $this->idSite,
+                    'lastMinutes' => 24 * 60,
+                    'segment' => $segment,
+                    'showColumns' => 'visits,actions',
+                ], $default = []);
+                $today = $today[0];
+            }
+        } catch (MaxExecutionTimeExceededException $e) {
+            $today = ['visits' => '-', 'actions' => '-'];
+            $view->countErrorToday = $e->getMessage();
+        }
+
         $view->visitorsCountHalfHour = $last30min['visits'];
         $view->visitorsCountToday = $today['visits'];
         $view->pisHalfhour = $last30min['actions'];
diff --git a/plugins/Live/Model.php b/plugins/Live/Model.php
index 604ce0a399..b8a1274183 100644
--- a/plugins/Live/Model.php
+++ b/plugins/Live/Model.php
@@ -28,6 +28,11 @@ use Piwik\Updater\Migration\Db as DbMigration;
 class Model
 {
     /**
+     * @internal for tests only
+     */
+    public $queryAndWhereSleepTestsOnly = false;
+
+    /**
      * @param $idSite
      * @param $period
      * @param $date
@@ -371,6 +376,11 @@ class Model
         );
     }
 
+    private function shouldQuerySleepInTests()
+    {
+        return $this->queryAndWhereSleepTestsOnly && defined('PIWIK_TEST_MODE') && PIWIK_TEST_MODE;
+    }
+
     private function getLastMinutesCounterForQuery($idSite, $lastMinutes, $segment, $select, $from, $where)
     {
         $lastMinutes = (int)$lastMinutes;
@@ -394,11 +404,31 @@ class Model
         $bind[] = $startDate->toString('Y-m-d H:i:s');
 
         $where = $whereIdSites . "AND " . $where;
+        if ($this->shouldQuerySleepInTests()) {
+            $where = ' SLEEP(1)';
+        }
 
         $segment = new Segment($segment, $idSite, $startDate, $endDate = null);
         $query   = $segment->getSelectQuery($select, $from, $where, $bind);
 
-        $numVisitors = Db::getReader()->fetchOne($query['sql'], $query['bind']);
+        if ($this->shouldQuerySleepInTests()) {
+            $query['bind'] = [];
+        }
+
+        $query['sql'] = trim($query['sql']);
+        if (0 === stripos($query['sql'], 'SELECT')) {
+            $query['sql'] = 'SELECT /* Live.getCounters */' . mb_substr($query['sql'], strlen('SELECT'));
+        }
+
+        $query['sql'] = DbHelper::addMaxExecutionTimeHintToQuery($query['sql'], $this->getLiveQueryMaxExecutionTime());
+
+        $readerDb = Db::getReader();
+        try {
+            $numVisitors = $readerDb->fetchOne($query['sql'], $query['bind']);
+        } catch (Exception $e) {
+            $this->handleMaxExecutionTimeError($readerDb, $e, $segment->getOriginalString(), $startDate, Date::now(), null, 0, $query);
+            throw $e;
+        }
 
         return $numVisitors;
     }
@@ -460,15 +490,35 @@ class Model
         $orderBy = "MAX(log_visit.visit_last_action_time) $orderByDir";
         $groupBy = "log_visit.idvisitor";
 
+        if ($this->shouldQuerySleepInTests()) {
+            $where = ' SLEEP(1)';
+            $visitLastActionTimeCondition = 'SLEEP(1)';
+        }
+
         $segment = new Segment($segment, $idSite, $dateOneDayAgo, $dateOneDayInFuture);
         $queryInfo = $segment->getSelectQuery($select, $from, $where, $whereBind, $orderBy, $groupBy);
 
-        $sql = "SELECT sub.idvisitor, sub.visit_last_action_time FROM ({$queryInfo['sql']}) as sub
+        $sql = "SELECT /* Live.queryAdjacentVisitorId */ sub.idvisitor, sub.visit_last_action_time FROM ({$queryInfo['sql']}) as sub
                  WHERE $visitLastActionTimeCondition
                  LIMIT 1";
         $bind = array_merge($queryInfo['bind'], array($visitLastActionTime));
 
-        $visitorId = Db::getReader()->fetchOne($sql, $bind);
+        if ($this->shouldQuerySleepInTests()) {
+            $bind = [];
+        }
+
+        $sql = DbHelper::addMaxExecutionTimeHintToQuery($sql, $this->getLiveQueryMaxExecutionTime());
+
+        $readerDb = Db::getReader();
+        try {
+            $visitorId = $readerDb->fetchOne($sql, $bind);
+        } catch (Exception $e) {
+            $this->handleMaxExecutionTimeError($readerDb, $e, $segment->getOriginalString(), Date::now(), Date::now(), null, 1, [
+                'sql' => $sql, 'bind' => $bind
+            ]);
+            throw $e;
+        }
+
         if (!empty($visitorId)) {
             $visitorId = bin2hex($visitorId);
         }
@@ -529,7 +579,9 @@ class Model
 
         if (!$visitorId) {
             // for now let's not apply when looking for a specific visitor
-            $innerQuery['sql'] = DbHelper::addMaxExecutionTimeHintToQuery($innerQuery['sql'], Config::getInstance()->General['live_query_max_execution_time']);
+            $innerQuery['sql'] = DbHelper::addMaxExecutionTimeHintToQuery($innerQuery['sql'],
+                $this->getLiveQueryMaxExecutionTime()
+            );
         }
 
         return array($innerQuery['sql'], $bind);
@@ -656,4 +708,9 @@ class Model
         }
         return array($whereBind, $where);
     }
+
+    private function getLiveQueryMaxExecutionTime()
+    {
+        return Config::getInstance()->General['live_query_max_execution_time'];
+    }
 }
diff --git a/plugins/Live/Reports/GetSimpleLastVisitCount.php b/plugins/Live/Reports/GetSimpleLastVisitCount.php
index 469618f900..642cf5e354 100644
--- a/plugins/Live/Reports/GetSimpleLastVisitCount.php
+++ b/plugins/Live/Reports/GetSimpleLastVisitCount.php
@@ -14,6 +14,7 @@ use Piwik\Piwik;
 use Piwik\Plugin\Report;
 use Piwik\Plugins\Live\Controller;
 use Piwik\API\Request;
+use Piwik\Plugins\Live\Exception\MaxExecutionTimeExceededException;
 use Piwik\Report\ReportWidgetFactory;
 use Piwik\View;
 use Piwik\Widget\WidgetsList;
@@ -38,16 +39,26 @@ class GetSimpleLastVisitCount extends Base
         $lastMinutes = Config::getInstance()->General[Controller::SIMPLE_VISIT_COUNT_WIDGET_LAST_MINUTES_CONFIG_KEY];
 
         $params    = array('lastMinutes' => $lastMinutes, 'showColumns' => array('visits', 'visitors', 'actions'));
-        $lastNData = Request::processRequest('Live.getCounters', $params);
+        $refereshAfterSeconds = Config::getInstance()->General['live_widget_refresh_after_seconds'];
+
+        $error = '';
+        try {
+            $lastNData = Request::processRequest('Live.getCounters', $params);
+        } catch (MaxExecutionTimeExceededException $e) {
+            $error = $e->getMessage();
+            $lastNData = [0 => ['visitors' => '-', 'visits' => '-', 'actions' => '-']];
+            $refereshAfterSeconds = 999999999; // we don't want it to refresh again any time soon as same issue would happen again
+        }
 
         $formatter = new Formatter();
 
         $view = new View('@Live/getSimpleLastVisitCount');
+        $view->error = $error;
         $view->lastMinutes = $lastMinutes;
         $view->visitors    = $formatter->getPrettyNumber($lastNData[0]['visitors']);
         $view->visits      = $formatter->getPrettyNumber($lastNData[0]['visits']);
         $view->actions     = $formatter->getPrettyNumber($lastNData[0]['actions']);
-        $view->refreshAfterXSecs = Config::getInstance()->General['live_widget_refresh_after_seconds'];
+        $view->refreshAfterXSecs = $refereshAfterSeconds;
         $view->translations = array(
             'one_visitor' => Piwik::translate('Live_NbVisitor'),
             'visitors'    => Piwik::translate('Live_NbVisitors'),
@@ -61,4 +72,4 @@ class GetSimpleLastVisitCount extends Base
 
         return $view->render();
     }
-}
\ No newline at end of file
+}
diff --git a/plugins/Live/VisitorProfile.php b/plugins/Live/VisitorProfile.php
index 12b99d72c8..9c6ed1a7a1 100644
--- a/plugins/Live/VisitorProfile.php
+++ b/plugins/Live/VisitorProfile.php
@@ -11,6 +11,7 @@ namespace Piwik\Plugins\Live;
 
 use Exception;
 use Piwik\DataTable;
+use Piwik\Plugins\Live\Exception\MaxExecutionTimeExceededException;
 
 class VisitorProfile
 {
@@ -90,10 +91,19 @@ class VisitorProfile
         $rows            = $visits->getRows();
         $latestVisitTime = reset($rows)->getColumn('lastActionDateTime');
 
-        $model                              = new Model();
-        $this->profile['nextVisitorId']     = $model->queryAdjacentVisitorId($this->idSite, $visitorId,
-            $latestVisitTime, $segment, $getNext = true);
-        $this->profile['previousVisitorId'] = $model->queryAdjacentVisitorId($this->idSite, $visitorId,
-            $latestVisitTime, $segment, $getNext = false);
+        $model = new Model();
+        try {
+            $this->profile['nextVisitorId'] = $model->queryAdjacentVisitorId($this->idSite, $visitorId, $latestVisitTime, $segment, $getNext = true);
+        } catch (MaxExecutionTimeExceededException $e) {
+            $this->profile['nextVisitorId'] = false;
+            $this->profile['previousVisitorId'] = false; // if query for next visitor is too slow, we assume query for previous visitor is too slow too
+            return;
+        }
+        try {
+            $this->profile['previousVisitorId'] = $model->queryAdjacentVisitorId($this->idSite, $visitorId, $latestVisitTime, $segment, $getNext = false);
+        } catch (MaxExecutionTimeExceededException $e) {
+            // we simply assume there is no previous visitor in that case
+            $this->profile['previousVisitorId'] = false;
+        }
     }
 }
diff --git a/plugins/Live/templates/_totalVisitors.twig b/plugins/Live/templates/_totalVisitors.twig
index 665617e926..70e37b3c77 100644
--- a/plugins/Live/templates/_totalVisitors.twig
+++ b/plugins/Live/templates/_totalVisitors.twig
@@ -16,13 +16,13 @@
         <tbody>
         <tr class="">
             <td class="label column">{{ 'Live_LastHours'|translate(24) }}</td>
-            <td class="column">{{ visitorsCountToday|number }}</td>
-            <td class="column">{{ pisToday|number }}</td>
+            <td class="column" {% if countErrorToday %}title="{{ countErrorToday|e('html_attr') }}"{% endif %}>{{ visitorsCountToday|number }}</td>
+            <td class="column" {% if countErrorToday %}title="{{ countErrorToday|e('html_attr') }}"{% endif %}>{{ pisToday|number }}</td>
         </tr>
         <tr class="">
             <td class="label column">{{ 'Live_LastMinutes'|translate(30) }}</td>
-            <td class="column">{{ visitorsCountHalfHour|number }}</td>
-            <td class="column">{{ pisHalfhour|number }}</td>
+            <td class="column" {% if countErrorHalfHour %}title="{{ countErrorHalfHour|e('html_attr') }}"{% endif %}>{{ visitorsCountHalfHour|number }}</td>
+            <td class="column" {% if countErrorHalfHour %}title="{{ countErrorHalfHour|e('html_attr') }}"{% endif %}>{{ pisHalfhour|number }}</td>
         </tr>
         </tbody>
     </table>
diff --git a/plugins/Live/templates/getSimpleLastVisitCount.twig b/plugins/Live/templates/getSimpleLastVisitCount.twig
index 8f167544eb..3d4fd53600 100644
--- a/plugins/Live/templates/getSimpleLastVisitCount.twig
+++ b/plugins/Live/templates/getSimpleLastVisitCount.twig
@@ -3,6 +3,7 @@
         <div>{{ visitors }}</div>
     </div>
     <br/>
+    {% if error is not empty %}<div class="alert alert-danger">{{ error }}</div>{% endif %}
 
     <div class='simple-realtime-elaboration'>
         {% set visitsMessage %}
@@ -18,4 +19,4 @@
         {{ 'Live_SimpleRealTimeWidget_Message'|translate(visitsMessage,actionsMessage,minutesMessage) | raw }}
     </div>
 </div>
-<script type="text/javascript">$(document).ready(function () {require('piwik/Live').initSimpleRealtimeVisitorWidget();});</script>
\ No newline at end of file
+<script type="text/javascript">$(document).ready(function () {require('piwik/Live').initSimpleRealtimeVisitorWidget();});</script>
diff --git a/plugins/Live/tests/Integration/ModelTest.php b/plugins/Live/tests/Integration/ModelTest.php
index 6f883e1937..cbd182c6a4 100644
--- a/plugins/Live/tests/Integration/ModelTest.php
+++ b/plugins/Live/tests/Integration/ModelTest.php
@@ -18,6 +18,7 @@ use Piwik\Plugins\Live\Model;
 use Piwik\Tests\Framework\Fixture;
 use Piwik\Tests\Framework\Mock\FakeAccess;
 use Piwik\Tests\Framework\TestCase\IntegrationTestCase;
+use Piwik\Tests\Framework\TestCase\SystemTestCase;
 use Piwik\Tests\Integration\SegmentTest;
 
 /**
@@ -118,6 +119,39 @@ class ModelTest extends IntegrationTestCase
         Model::handleMaxExecutionTimeError($db, $e, $segment, $dateStart, $dateEnd, $minTimestamp, $limit, ['param' => 'value']);
     }
 
+    public function test_getLastMinutesCounterForQuery_maxExecutionTime()
+    {
+        if (SystemTestCase::isMysqli()) {
+            $this->markTestSkipped('max_execution_time not supported on mysqli');
+            return;
+        }
+        $this->expectException(MaxExecutionTimeExceededException::class);
+        $this->expectExceptionMessage('Live_QueryMaxExecutionTimeExceeded');
+        $this->setLowestMaxExecutionTime();
+
+        $this->trackPageView();
+
+        $model = new Model();
+        $model->queryAndWhereSleepTestsOnly = true;
+        $model->getNumVisits(1, 999999, '');
+    }
+
+    public function test_queryAdjacentVisitorId_maxExecutionTime()
+    {
+        if (SystemTestCase::isMysqli()) {
+            $this->markTestSkipped('max_execution_time not supported on mysqli');
+            return;
+        }
+        $this->expectException(MaxExecutionTimeExceededException::class);
+        $this->expectExceptionMessage('Live_QueryMaxExecutionTimeExceeded');
+        $this->setLowestMaxExecutionTime();
+
+        $this->trackPageView();
+        $model = new Model();
+        $model->queryAndWhereSleepTestsOnly = true;
+        $model->queryAdjacentVisitorId(1, '1234567812345678', Date::yesterday()->getDatetime(), '', true);
+    }
+
     public function test_getStandAndEndDate()
     {
         $model = new Model();
@@ -316,10 +350,7 @@ class ModelTest extends IntegrationTestCase
 
     public function test_makeLogVisitsQueryString_addsMaxExecutionHintIfConfigured()
     {
-        $config = Config::getInstance();
-        $general = $config->General;
-        $general['live_query_max_execution_time'] = 30;
-        $config->General = $general;
+        $this->setMaxExecutionTime(30);
 
         $model = new Model();
         list($dateStart, $dateEnd) = $model->getStartAndEndDate($idSite = 1, 'month', '2010-01-01');
@@ -337,18 +368,14 @@ class ModelTest extends IntegrationTestCase
         $expectedSql = 'SELECT  /*+ MAX_EXECUTION_TIME(30000) */ 
 				log_visit.*';
 
-        $general['live_query_max_execution_time'] = -1;
-        $config->General = $general;
+        $this->setMaxExecutionTime(-1);
 
         $this->assertStringStartsWith($expectedSql, trim($sql));
     }
 
     public function test_makeLogVisitsQueryString_doesNotAddsMaxExecutionHintForVisitorIds()
     {
-        $config = Config::getInstance();
-        $general = $config->General;
-        $general['live_query_max_execution_time'] = 30;
-        $config->General = $general;
+        $this->setMaxExecutionTime(30);
 
         $model = new Model();
         list($dateStart, $dateEnd) = $model->getStartAndEndDate($idSite = 1, 'month', '2010-01-01');
@@ -366,8 +393,7 @@ class ModelTest extends IntegrationTestCase
         $expectedSql = 'SELECT
 				log_visit.*';
 
-        $general['live_query_max_execution_time'] = -1;
-        $config->General = $general;
+        $this->setMaxExecutionTime(-1);
 
         $this->assertStringStartsWith($expectedSql, trim($sql));
     }
@@ -502,4 +528,27 @@ class ModelTest extends IntegrationTestCase
             'Piwik\Access' => new FakeAccess()
         );
     }
-}
\ No newline at end of file
+
+    private function setLowestMaxExecutionTime(): void
+    {
+        $this->setMaxExecutionTime(0.001);
+    }
+
+    private function setMaxExecutionTime($time): void
+    {
+        $config = Config::getInstance();
+        $general = $config->General;
+        $general['live_query_max_execution_time'] = $time;
+        $config->General = $general;
+    }
+
+    private function trackPageView(): void
+    {
+        // Needed for the tests that may execute a sleep() to test max execution time. Otherwise if the table is empty
+        // the sleep would not be executed making the tests fail randomly
+        $t = Fixture::getTracker(1, Date::now()->getDatetime(), $defaultInit = true);
+        $t->setTokenAuth(Fixture::getTokenAuth());
+        $t->setVisitorId(substr(sha1('X4F66G776HGI'), 0, 16));
+        $t->doTrackPageView('foo');
+    }
+}