Add auto-refresh functionality to log page (#963)

Add auto-refresh functionality to log page

Fixes: #957

---------

Co-authored-by: Pēteris Caune <cuu508@gmail.com>

hc/front/forms.py

@@ -384,14 +384,18 @@ class SearchForm(forms.Form):
 
 class SeekForm(forms.Form):
     # min_value is 2010-01-01, max_value is 2030-01-01
-    start = forms.IntegerField(min_value=1262296800, max_value=1893448800)
-    end = forms.IntegerField(min_value=1262296800, max_value=1893448800)
+    start = forms.FloatField(min_value=1262296800, max_value=1893448800, required=False)
+    end = forms.FloatField(min_value=1262296800, max_value=1893448800, required=False)
 
-    def clean_start(self) -> datetime:
-        return datetime.fromtimestamp(self.cleaned_data["start"], tz=timezone.utc)
+    def clean_start(self) -> datetime | None:
+        if self.cleaned_data["start"]:
+            return datetime.fromtimestamp(self.cleaned_data["start"], tz=timezone.utc)
+        return None
 
-    def clean_end(self) -> datetime:
-        return datetime.fromtimestamp(self.cleaned_data["end"], tz=timezone.utc)
+    def clean_end(self) -> datetime | None:
+        if self.cleaned_data["end"]:
+            return datetime.fromtimestamp(self.cleaned_data["end"], tz=timezone.utc)
+        return None
 
 
 class TransferForm(forms.Form):

hc/front/templatetags/hc_extras.py

@@ -185,8 +185,8 @@ def now_isoformat() -> str:
 
 
 @register.filter
-def timestamp(dt: datetime) -> int:
-    return int(dt.timestamp())
+def timestamp(dt: datetime) -> float:
+    return dt.timestamp()
 
 
 @register.filter

hc/front/tests/test_log.py

@@ -1,7 +1,9 @@
 from __future__ import annotations
 
 import json
+from datetime import datetime
 from datetime import timedelta as td
+from datetime import timezone
 from unittest.mock import Mock, patch
 
 from django.utils.timezone import now
@@ -23,7 +25,7 @@ class LogTestCase(BaseTestCase):
         self.ping.created = "2000-01-01T00:00:00+00:00"
         self.ping.save()
 
-        self.url = "/checks/%s/log/" % self.check.code
+        self.url = f"/checks/{self.check.code}/log/"
 
     def test_it_works(self) -> None:
         self.client.login(username="alice@example.org", password="password")
@@ -127,11 +129,6 @@ class LogTestCase(BaseTestCase):
         r = self.client.get(self.url)
         self.assertContains(r, "Called webhook foo/$NAME", status_code=200)
 
-    def test_it_allows_cross_team_access(self) -> None:
-        self.client.login(username="bob@example.org", password="password")
-        r = self.client.get(self.url)
-        self.assertEqual(r.status_code, 200)
-
     def test_it_shows_ignored_nonzero_exitstatus(self) -> None:
         self.ping.kind = "ign"
         self.ping.exitstatus = 123
@@ -189,3 +186,28 @@ class LogTestCase(BaseTestCase):
         # The notification should not show up in the log as it is
         # older than the oldest visible ping:
         self.assertNotContains(r, "Sent email to alice@example.org", status_code=200)
+
+    def test_it_accepts_start_query_parameter(self) -> None:
+        dt = datetime(2020, 1, 1, tzinfo=timezone.utc)
+        ts = str(dt.timestamp())
+
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(self.url + "?start=" + ts)
+        self.assertContains(r, f'data-start="{ts}"', status_code=200)
+
+    def test_it_accepts_end_query_parameter(self) -> None:
+        dt = datetime(2020, 1, 1, tzinfo=timezone.utc)
+        ts = str(dt.timestamp())
+
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(self.url + "?end=" + ts)
+        self.assertContains(r, f'data-end="{ts}"', status_code=200)
+
+    def test_it_ignores_bad_time_filter(self) -> None:
+        self.ping.refresh_from_db()
+        smin = str(self.ping.created.timestamp())
+
+        for sample in ["surprise", "0"]:
+            self.client.login(username="alice@example.org", password="password")
+            r = self.client.get(self.url + "?start=" + sample)
+            self.assertContains(r, f'data-start="{smin}"', status_code=200)

hc/front/tests/test_log_events.py

@@ -0,0 +1,69 @@
+from __future__ import annotations
+
+from django.utils.timezone import now
+
+from hc.api.models import Check, Ping
+from hc.test import BaseTestCase
+
+
+class LogTestCase(BaseTestCase):
+    def setUp(self) -> None:
+        super().setUp()
+        self.check = Check.objects.create(project=self.project)
+        self.check.created = "2000-01-01T00:00:00+00:00"
+        self.check.save()
+
+        self.ping = Ping.objects.create(owner=self.check, n=1)
+        self.ping.body_raw = b"hello world"
+
+        # Older MySQL versions don't store microseconds. This makes sure
+        # the ping is older than any notifications we may create later:
+        self.ping.created = "2000-01-01T00:00:00+00:00"
+        self.ping.save()
+
+        self.url = f"/checks/{self.check.code}/log_events/"
+
+    def test_it_works(self) -> None:
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(self.url)
+        self.assertContains(r, "hello world")
+
+    def test_team_access_works(self) -> None:
+        # Logging in as bob, not alice. Bob has team access so this
+        # should work.
+        self.client.login(username="bob@example.org", password="password")
+        r = self.client.get(self.url)
+        self.assertEqual(r.status_code, 200)
+
+    def test_it_handles_bad_uuid(self) -> None:
+        url = "/checks/not-uuid/log_events/"
+
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(url)
+        self.assertEqual(r.status_code, 404)
+
+    def test_it_handles_missing_uuid(self) -> None:
+        # Valid UUID but there is no check for it:
+        url = "/checks/6837d6ec-fc08-4da5-a67f-08a9ed1ccf62/log_events/"
+
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(url)
+        self.assertEqual(r.status_code, 404)
+
+    def test_it_checks_ownership(self) -> None:
+        self.client.login(username="charlie@example.org", password="password")
+        r = self.client.get(self.url)
+        self.assertEqual(r.status_code, 404)
+
+    def test_it_accepts_start_parameter(self) -> None:
+        ts = str(now().timestamp())
+        self.client.login(username="alice@example.org", password="password")
+        r = self.client.get(self.url + "?start=" + ts)
+        self.assertNotContains(r, "hello world")
+
+    def test_it_rejects_bad_start_parameter(self) -> None:
+        self.client.login(username="alice@example.org", password="password")
+
+        for sample in ["surprise", "100000000000000000"]:
+            r = self.client.get(self.url + "?start=" + sample)
+            self.assertEqual(r.status_code, 400)

hc/front/urls.py

@@ -14,6 +14,7 @@ check_urls = [
     path("remove/", views.remove_check, name="hc-remove-check"),
     path("clear_events/", views.clear_events, name="hc-clear-events"),
     path("log/", views.log, name="hc-log"),
+    path("log_events/", views.log_events, name="hc-log-events"),
     path("status/", views.status_single, name="hc-status-single"),
     path("last_ping/", views.ping_details, name="hc-last-ping"),
     path("transfer/", views.transfer, name="hc-transfer"),

hc/front/views.py

@@ -11,6 +11,7 @@ from collections import Counter, defaultdict
 from collections.abc import Iterable
 from datetime import datetime
 from datetime import timedelta as td
+from datetime import timezone
 from email.message import EmailMessage
 from secrets import token_urlsafe
 from typing import Literal, TypedDict, cast
@@ -75,6 +76,7 @@ STATUS_TEXT_TMPL = get_template("front/log_status_text.html")
 LAST_PING_TMPL = get_template("front/last_ping_cell.html")
 EVENTS_TMPL = get_template("front/details_events.html")
 DOWNTIMES_TMPL = get_template("front/details_downtimes.html")
+LOGS_TMPL = get_template("front/log_row.html")
 
 
 def _tags_counts(checks: Iterable[Check]) -> tuple[list[tuple[str, str, str]], int]:
@@ -207,6 +209,7 @@ def _get_referer_qs(request: HttpRequest) -> str:
         return "?" + parsed.query
     return ""
 
+
 @login_required
 def checks(request: AuthenticatedHttpRequest, code: UUID) -> HttpResponse:
     _refresh_last_active_date(request.profile)
@@ -918,11 +921,12 @@ def log(request: AuthenticatedHttpRequest, code: UUID) -> HttpResponse:
     smin = smin.replace(minute=0, second=0)
 
     form = forms.SeekForm(request.GET)
+    start, end = smin, smax
     if form.is_valid():
-        start = form.cleaned_data["start"]
-        end = form.cleaned_data["end"]
-    else:
-        start, end = smin, smax
+        if form.cleaned_data["start"]:
+            start = form.cleaned_data["start"]
+        if form.cleaned_data["end"]:
+            end = form.cleaned_data["end"]
 
     # Clamp the _get_events start argument to the date of the oldest visible ping
     get_events_start = start
@@ -2729,4 +2733,24 @@ def verify_signal_number(request: AuthenticatedHttpRequest) -> HttpResponse:
     return render_result(None)
 
 
+@login_required
+def log_events(request: AuthenticatedHttpRequest, code: UUID) -> HttpResponse:
+    check, rw = _get_check_for_user(request, code, preload_owner_profile=True)
+
+    form = forms.SeekForm(request.GET)
+    if not form.is_valid():
+        return HttpResponseBadRequest()
+
+    if form.cleaned_data["start"]:
+        start = form.cleaned_data["start"] + td(microseconds=1)
+    else:
+        start = check.created
+
+    html = ""
+    for event in _get_events(check, 1000, start=start, end=now()):
+        html += LOGS_TMPL.render({"event": event, "describe_body": True})
+
+    return JsonResponse({"max": now().timestamp(), "events": html})
+
+
 # Forks: add custom views after this line

static/css/log.css

@@ -7,6 +7,10 @@
     font-size: 13px;
 }
 
+#log tbody {
+    border: 0;
+}
+
 #log td {
     position: relative;
     border: 0;
@@ -14,6 +18,11 @@
     white-space: nowrap;
 }
 
+#log tbody.new td {
+    background: var(--log-new-row-bg);
+    border-bottom: 1px solid var(--log-new-row-border);
+}
+
 #log .duration {
     white-space: nowrap;
     float: right;
@@ -97,4 +106,4 @@
 #slider-from-formatted,
 #slider-to-formatted {
     font-weight: bold;
-}
+}

static/css/variables.css

@@ -75,6 +75,8 @@
     --text-muted:  #767676;
     --text-success: #3c763d;
     --text-danger: #a94442;
+    --log-new-row-bg: #d9edf7;
+    --log-new-row-border: #bce8f1;
 }
 
 
@@ -155,4 +157,6 @@ body.dark {
     --text-muted: hsl(240, 3%, 55%);
     --text-success: #22bc66;
     --text-danger: #d9534f;
+    --log-new-row-bg: #123051;
+    --log-new-row-border: #163c64;
 }

static/js/log.js

@@ -5,12 +5,6 @@ $(function () {
     var NO_PIP = -1;
 
     var slider = document.getElementById("log-slider");
-    var smin = parseInt(slider.dataset.min);
-    var smax = parseInt(slider.dataset.max);
-    var pixelsPerSecond = slider.clientWidth / (smax - smin);
-    var pixelsPerHour = pixelsPerSecond * 3600;
-    var pixelsPerDay = pixelsPerHour * 24;
-    var dayGap = Math.round(0.5 + 80 / pixelsPerDay);
 
     // Look up the active tz switch to determine the initial display timezone:
     var dateFormat = $(".active", "#format-switcher").data("format");
@@ -20,91 +14,112 @@ $(function () {
         return dt;
     }
 
-    function filterPips(value, type) {
-        var m = fromUnix(value);
-        if (m.minute() != 0)
-            return NO_PIP;
-
-        // Date labels on every day
-        if (pixelsPerDay > 60 && m.hour() == 0)
-            return BIG_LABEL;
-
-        // Date labels every "dayGap" days
-        if (m.hour() == 0 && m.dayOfYear() % dayGap == 0)
-            return BIG_LABEL;
-
-        // Hour labels on every hour:
-        if (pixelsPerHour > 40)
-            return SMALL_LABEL;
-
-        // Hour labels every 3 hours:
-        if (pixelsPerHour > 15 && m.hour() % 3 == 0)
-            return SMALL_LABEL;
-
-        // Hour labels every 6 hours:
-        if (pixelsPerHour > 5 && m.hour() % 6 == 0)
-            return SMALL_LABEL;
-
-        // Pip on every hour
-        if (pixelsPerHour > 5)
-            return PIP;
-
-        // Pip on every day
-        if (pixelsPerDay > 10 && m.hour() == 0)
-            return PIP;
-
-        return NO_PIP;
-    }
-
-    function fmt(ts) {
-        var pipType = filterPips(ts);
-        return fromUnix(ts).format(pipType == 2 ? "HH:mm" : "MMM D");
-    }
-
-    noUiSlider.create(slider, {
-        start: [parseInt(slider.dataset.start), parseInt(slider.dataset.end)],
-        range: {'min': smin, 'max': smax},
-        connect: true,
-        step: 3600,
-        pips: {
-            mode: "steps",
-            density: 3,
-            filter: filterPips,
-            format: {
-                to: fmt,
-                from: function() {}
-            }
-        }
-    });
-
     function updateSliderPreview() {
         var values = slider.noUiSlider.get();
         $("#slider-from-formatted").text(fromUnix(values[0]).format("MMMM D, HH:mm"));
-        $("#slider-to-formatted").text(fromUnix(values[1]).format("MMMM D, HH:mm"));
+
+        var toFormatted = "now";
+        if (values[1] < parseInt(slider.dataset.max)) {
+            toFormatted = fromUnix(values[1]).format("MMMM D, HH:mm");
+        }
+
+        $("#slider-to-formatted").text(toFormatted);
     }
 
+    function setupSlider() {
+        var smin = parseInt(slider.dataset.min);
+        var smax = parseInt(slider.dataset.max);
+        var pixelsPerSecond = slider.clientWidth / (smax - smin);
+        var pixelsPerHour = pixelsPerSecond * 3600;
+        var pixelsPerDay = pixelsPerHour * 24;
+        var dayGap = Math.round(0.5 + 80 / pixelsPerDay);
+
+        function filterPips(value, type) {
+            var m = fromUnix(value);
+            if (m.minute() != 0)
+                return NO_PIP;
+
+            // Date labels on every day
+            if (pixelsPerDay > 60 && m.hour() == 0)
+                return BIG_LABEL;
+
+            // Date labels every "dayGap" days
+            if (m.hour() == 0 && m.dayOfYear() % dayGap == 0)
+                return BIG_LABEL;
+
+            // Hour labels on every hour:
+            if (pixelsPerHour > 40)
+                return SMALL_LABEL;
+
+            // Hour labels every 3 hours:
+            if (pixelsPerHour > 15 && m.hour() % 3 == 0)
+                return SMALL_LABEL;
+
+            // Hour labels every 6 hours:
+            if (pixelsPerHour > 5 && m.hour() % 6 == 0)
+                return SMALL_LABEL;
+
+            // Pip on every hour
+            if (pixelsPerHour > 5)
+                return PIP;
+
+            // Pip on every day
+            if (pixelsPerDay > 10 && m.hour() == 0)
+                return PIP;
+
+            return NO_PIP;
+        }
+
+        function fmt(ts) {
+            var pipType = filterPips(ts);
+            return fromUnix(ts).format(pipType == 2 ? "HH:mm" : "MMM D");
+        }
+
+        if (slider.noUiSlider) {
+            slider.noUiSlider.destroy();
+        }
+        noUiSlider.create(slider, {
+            start: [parseInt(slider.dataset.start), parseInt(slider.dataset.end)],
+            range: {'min': smin, 'max': smax},
+            connect: true,
+            step: 3600,
+            pips: {
+                mode: "steps",
+                density: 3,
+                filter: filterPips,
+                format: {
+                    to: fmt,
+                    from: function() {}
+                }
+            }
+        });
+
+        slider.noUiSlider.on("slide", updateSliderPreview);
+        slider.noUiSlider.on("change", function(a, b, value) {
+            var start = Math.round(value[0]);
+            $("#seek-start").val(start).attr("disabled", start == smin);
+            var end = Math.round(value[1]);
+            $("#seek-end").val(end).attr("disabled", end == smax);
+            $("#seek-form").submit();
+        });
+    }
+
+    setupSlider();
     updateSliderPreview();
-    slider.noUiSlider.on("slide", updateSliderPreview);
 
-    slider.noUiSlider.on("change", function(a, b, value) {
-        $("#seek-start").val(Math.round(value[0]));
-        $("#seek-end").val(Math.round(value[1]));
-        $("#seek-form").submit();
-    });
-
-    $("#log tr.ok").on("click", function() {
+    $("#log").on("click", "tr.ok", function() {
         var n = $("td", this).first().text();
         var tmpl = $("#log").data("url").slice(0, -2);
         loadPingDetails(tmpl + n + "/");
         return false;
     });
 
-    function switchDateFormat(format) {
+    function switchDateFormat(format, rows) {
         dateFormat = format;
         slider.noUiSlider.updateOptions({}, true);
         updateSliderPreview();
 
-        document.querySelectorAll("#log tr").forEach(function(row) {
+        rows.forEach(function(row) {
             var dt = fromUnix(row.dataset.dt);
             row.children[1].textContent = dt.format("MMM D");
             row.children[2].textContent = dt.format("HH:mm");
@@ -113,11 +128,52 @@ $(function () {
 
     $("#format-switcher").click(function(ev) {
         var format = ev.target.dataset.format;
-        switchDateFormat(format);
+        switchDateFormat(format, document.querySelectorAll("#log tr"));
     });
 
-    switchDateFormat(dateFormat);
+    switchDateFormat(dateFormat, document.querySelectorAll("#log tr"));
     // The table is initially hidden to avoid flickering as we convert dates.
     // Once it's ready, set it to visible:
     $("#log").css("visibility", "visible");
+
+    function fetchNewEvents() {
+        var url = document.getElementById("log").dataset.refreshUrl;
+        var firstRow = $("#log tr").get(0);
+        if (firstRow) {
+            url += "?start=" + firstRow.dataset.dt;
+        }
+
+        $.ajax({
+            url: url,
+            dataType: "json",
+            timeout: 2000,
+            success: function(data) {
+                // Has a minute has passed since last slider refresh?
+                if (data.max - slider.dataset.max > 60) {
+                    // If the right handle was all the way to the right,
+                    // make sure it is still all the way to the right after
+                    // the update:
+                    if (slider.dataset.end == slider.dataset.max) {
+                        slider.dataset.end = data.max;
+                    }
+                    slider.dataset.max = data.max;
+                    setupSlider();
+                }
+
+                if (data.events) {
+                    var tbody = document.createElement("tbody");
+                    tbody.setAttribute("class", "new");
+                    tbody.innerHTML = data.events;
+                    switchDateFormat(dateFormat, tbody.querySelectorAll("tr"));
+                    document.getElementById("log").prepend(tbody);
+                    $("#events-count").remove();
+                }
+            }
+        });
+    }
+
+    if (slider.dataset.end == slider.dataset.max) {
+        adaptiveSetInterval(fetchNewEvents, false);
+    }
+
 });

templates/front/log.html

@@ -55,23 +55,37 @@
             <input type="hidden" name="end" id="seek-end">
         </form>
 
-        {% if num_total > 1000 %}
-        <p class="alert alert-info">Found {{ num_total }} ping events, displaying the most recent 1000.</p>
-        {% elif num_total > 0 %}
-        <p class="alert alert-info">Found {{ num_total }} ping event{{ num_total|pluralize }}.</p>
-        {% elif not events and check.n_pings > 0 %}
-        <div class="alert alert-info">The filter parameters matched no events.</div>
-        {% elif check.n_pings == 0 %}
-        <div class="alert alert-info">Log is empty. This check has not received any pings yet.</div>
-        {% endif %}
+        <div class="alert alert-info">
+            <span id="events-count">
+            {% if num_total > 1000 %}
+            Found {{ num_total }} ping events, displaying the most recent 1000.
+            {% elif num_total > 0 %}
+            Found {{ num_total }} ping event{{ num_total|pluralize }}.
+            {% elif not events and check.n_pings > 0 %}
+            The filter parameters matched no events.
+            {% elif check.n_pings == 0 %}
+            Log is empty. This check has not received any pings yet.
+            {% endif %}
+            </span>
+            {% if end == max %}
+            Updating live, new events will load automatically.
+            {% endif %}
+        </div>
 
-        {% if events %}
         <div class="table-responsive">
-        <table class="table" id="log" data-url="{% url 'hc-ping-details' check.code '0' %}">
-        {% for event in events %}{% include "front/log_row.html" with describe_body=True %}{% endfor %}
+        <table
+            class="table"
+            id="log"
+            data-url="{% url 'hc-ping-details' check.code '0' %}"
+            data-refresh-url="{% url 'hc-log-events' check.code %}">
+            <tbody>
+            {% if events %}
+                {% for event in events %}{% include "front/log_row.html" with describe_body=True %}{% endfor %}
+            {% endif %}
+            </tbody>
         </table>
         </div>
-        {% endif %}
+        
     </div>
 </div>
 
@@ -96,5 +110,6 @@
 <script src="{% static 'js/purify.min.js' %}"></script>
 <script src="{% static 'js/ping_details.js' %}"></script>
 <script src="{% static 'js/log.js' %}"></script>
+<script src="{% static 'js/adaptive-setinterval.js' %}"></script>
 {% endcompress %}
 {% endblock %}