Improve error handling to spare the server log from user's malformed requests and stop trying to parse data from providers if the HTTP status was not 200

This commit is contained in:
Ian Renton
2026-07-25 08:17:17 +01:00
parent 34e3933d5d
commit 2fc9658571
26 changed files with 169 additions and 128 deletions
+13 -8
View File
@@ -41,15 +41,20 @@ class HTTPAlertProvider(AlertProvider):
# Request data from API
logging.debug("Polling " + self.name + " alert API...")
http_response = requests.get(self._url, headers=HTTP_HEADERS, timeout=(5, 30))
# Pass off to the subclass for processing
new_alerts = self._http_response_to_alerts(http_response)
# Submit the new alerts for processing. There might not be any alerts for the less popular programs.
if new_alerts:
self._submit_batch(new_alerts)
# Check response code was good
if http_response.status_code == 200:
# Pass off to the subclass for processing
new_alerts = self._http_response_to_alerts(http_response)
# Submit the new alerts for processing. There might not be any alerts for the less popular programs.
if new_alerts:
self._submit_batch(new_alerts)
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " alert API.")
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " alert API.")
else:
self.status = "Error"
logging.warning(f"{self.name} alert API returned HTTP {http_response.status_code}.")
except Exception:
self.status = "Error"
+4
View File
@@ -215,6 +215,10 @@ allow-spotting: true
# your log quickly on a popular server.
log-web-requests: false
# Minimum severity of log statements to print to the system log. Defaults to INFO, change to DEBUG if you need more
# information.
log-level: INFO
# Options for the web UI.
web-ui-options:
spot-count: [ 10, 25, 50, 100 ]
+1
View File
@@ -22,6 +22,7 @@ WEB_SERVER_PORT = config["web-server-port"]
ALLOW_SPOTTING = config["allow-spotting"]
WEB_UI_OPTIONS = config["web-ui-options"]
API_ONLY_MODE = config.get("api-only-mode", False)
LOG_LEVEL = config.get("log-level", "INFO")
LOG_WEB_REQUESTS = config.get("log-web-requests", False)
# For ease of config, each spot provider owns its own config about whether it should be enabled by default in the web UI
+1 -1
View File
@@ -127,7 +127,7 @@ class APISpotHandler(tornado.web.RequestHandler):
self.set_header("Content-Type", "application/json")
except Exception as e:
logging.error(e)
logging.error("Exception when handling client request to add spot API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
self.set_header("Cache-Control", "no-store")
+1 -2
View File
@@ -59,11 +59,10 @@ class APIAlertsHandler(tornado.web.RequestHandler):
self.write(safe_json_dumps(data))
self.set_status(200)
except ValueError as e:
logging.error(e)
self.write(safe_json_dumps("Bad request - " + str(e)))
self.set_status(400)
except Exception as e:
logging.error(e)
logging.error("Exception when handling client request to alerts API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
self.set_header("Cache-Control", "no-store")
+30 -22
View File
@@ -1,4 +1,5 @@
import json
import logging
from collections import Counter
from datetime import datetime, timedelta
from typing import Any
@@ -9,6 +10,7 @@ from tornado import httputil
from tornado.web import Application
from core.prometheus_metrics_handler import api_requests_counter
from core.utils import safe_json_dumps
CONTINENTS = ["EU", "NA", "SA", "AS", "AF", "OC", "AN"]
BANDS = ["160m", "80m", "60m", "40m", "30m", "20m", "17m", "15m", "12m", "10m", "6m"]
@@ -29,29 +31,35 @@ class APIDxStatsHandler(tornado.web.RequestHandler):
self._web_server_metrics = web_server_metrics
def get(self):
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
try:
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
one_hour_ago = (datetime.now(pytz.UTC) - timedelta(hours=1)).timestamp()
counts = Counter()
one_hour_ago = (datetime.now(pytz.UTC) - timedelta(hours=1)).timestamp()
counts = Counter()
for key in self._spots.iterkeys():
spot = self._spots.get(key)
if spot is None:
continue
if not spot.time or spot.time < one_hour_ago:
continue
if spot.de_continent in CONTINENTS_SET and spot.dx_continent in CONTINENTS_SET and spot.band in BANDS_SET:
counts[spot.de_continent, spot.dx_continent, spot.band] += 1
for key in self._spots.iterkeys():
spot = self._spots.get(key)
if spot is None:
continue
if not spot.time or spot.time < one_hour_ago:
continue
if spot.de_continent in CONTINENTS_SET and spot.dx_continent in CONTINENTS_SET and spot.band in BANDS_SET:
counts[spot.de_continent, spot.dx_continent, spot.band] += 1
result = {
de: {dx: {band: counts[de, dx, band] for band in BANDS} for dx in CONTINENTS}
for de in CONTINENTS
}
result = {
de: {dx: {band: counts[de, dx, band] for band in BANDS} for dx in CONTINENTS}
for de in CONTINENTS
}
self.write(json.dumps(result))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
self.write(json.dumps(result))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
except Exception as e:
logging.error("Exception when handling client request to dx stats API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
+3 -3
View File
@@ -74,7 +74,7 @@ class APILookupCallHandler(tornado.web.RequestHandler):
self.set_status(422)
except Exception as e:
logging.error(e)
logging.error("Exception when handling client request to call lookup API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
@@ -126,7 +126,7 @@ class APILookupSIGRefHandler(tornado.web.RequestHandler):
self.set_status(422)
except Exception as e:
logging.error(e)
logging.error("Exception when handling client request to sig ref lookup API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
@@ -188,7 +188,7 @@ class APILookupGridHandler(tornado.web.RequestHandler):
self.set_status(422)
except Exception as e:
logging.error(e)
logging.error("Exception when handling client request to grid ref lookup API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
+33 -26
View File
@@ -1,3 +1,4 @@
import logging
from datetime import datetime
from typing import Any
@@ -25,31 +26,37 @@ class APIOptionsHandler(tornado.web.RequestHandler):
self._web_server_metrics = web_server_metrics
def get(self):
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
try:
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
options = {"bands": BANDS,
"modes": ALL_MODES,
"mode_types": MODE_TYPES,
"sigs": SIGS,
# Spot/alert sources are filtered for only ones that are enabled in config, no point letting the user toggle things that aren't even available.
"spot_sources": list(
map(lambda p: p["name"], filter(lambda p: p["enabled"], self._status_data["spot_providers"]))),
"alert_sources": list(
map(lambda p: p["name"], filter(lambda p: p["enabled"], self._status_data["alert_providers"]))),
"continents": CONTINENTS,
"propagation_modes": list(PROPAGATION_MODES.values()),
"max_spot_age": MAX_SPOT_AGE,
"spot_allowed": ALLOW_SPOTTING}
# If spotting to this server is enabled, "API" is another valid spot source even though it does not come from
# one of our proviers.
if ALLOW_SPOTTING:
options["spot_sources"].append("API")
options = {"bands": BANDS,
"modes": ALL_MODES,
"mode_types": MODE_TYPES,
"sigs": SIGS,
# Spot/alert sources are filtered for only ones that are enabled in config, no point letting the user toggle things that aren't even available.
"spot_sources": list(
map(lambda p: p["name"], filter(lambda p: p["enabled"], self._status_data["spot_providers"]))),
"alert_sources": list(
map(lambda p: p["name"], filter(lambda p: p["enabled"], self._status_data["alert_providers"]))),
"continents": CONTINENTS,
"propagation_modes": list(PROPAGATION_MODES.values()),
"max_spot_age": MAX_SPOT_AGE,
"spot_allowed": ALLOW_SPOTTING}
# If spotting to this server is enabled, "API" is another valid spot source even though it does not come from
# one of our proviers.
if ALLOW_SPOTTING:
options["spot_sources"].append("API")
self.write(safe_json_dumps(options))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
self.write(safe_json_dumps(options))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
except Exception as e:
logging.error("Exception when handling client request to options API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
+17 -9
View File
@@ -1,3 +1,4 @@
import logging
from datetime import datetime
from typing import Any
@@ -7,6 +8,7 @@ from tornado import httputil
from tornado.web import Application
from core.prometheus_metrics_handler import api_requests_counter
from core.utils import safe_json_dumps
class APISolarConditionsHandler(tornado.web.RequestHandler):
@@ -22,13 +24,19 @@ class APISolarConditionsHandler(tornado.web.RequestHandler):
self._web_server_metrics = web_server_metrics
def get(self):
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
try:
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
self.write(self._solar_conditions.to_json())
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
self.write(self._solar_conditions.to_json())
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
except Exception as e:
logging.error("Exception when handling client request to solar conditions API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
+1 -2
View File
@@ -59,11 +59,10 @@ class APISpotsHandler(tornado.web.RequestHandler):
self.write(safe_json_dumps(data))
self.set_status(200)
except ValueError as e:
logging.error(e)
self.write(safe_json_dumps("Bad request - " + str(e)))
self.set_status(400)
except Exception as e:
logging.error(e)
logging.error("Excedption when handling client request to spots API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
self.set_header("Cache-Control", "no-store")
+16 -9
View File
@@ -1,3 +1,4 @@
import logging
from datetime import datetime
from typing import Any
@@ -23,13 +24,19 @@ class APIStatusHandler(tornado.web.RequestHandler):
self._web_server_metrics = web_server_metrics
def get(self):
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
try:
# Metrics
self._web_server_metrics["last_api_access_time"] = datetime.now(pytz.UTC)
self._web_server_metrics["api_access_counter"] += 1
self._web_server_metrics["status"] = "OK"
api_requests_counter.inc()
self.write(safe_json_dumps(self._status_data))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
self.write(safe_json_dumps(self._status_data))
self.set_status(200)
self.set_header("Cache-Control", "no-store")
self.set_header("Content-Type", "application/json")
except Exception as e:
logging.error("Exception when handling client request to status API: %s", e, exc_info=True)
self.write(safe_json_dumps("Error - an internal server error occurred."))
self.set_status(500)
+4 -3
View File
@@ -127,10 +127,11 @@ class GIROIonosonde(SolarConditionsProvider):
from_str = from_time.strftime("%Y.%m.%d+%H:%M:%S")
to_str = to_time.strftime("%Y.%m.%d+%H:%M:%S")
url = f"{LGDC_URL}?ursiCode={ursi}&charName=foF2,MUFD,fmin&DMUF=3000&fromDate={from_str}&toDate={to_str}"
response = requests.get(url, headers=HTTP_HEADERS, timeout=(5, 15))
if response.status_code != 200:
http_response = requests.get(url, headers=HTTP_HEADERS, timeout=(5, 15))
if http_response.status_code != 200:
logging.warning(f"Giro ionosonde API returned HTTP {http_response.status_code}.")
return None, None, None
return self._parse_all(response.text)
return self._parse_all(http_response.text)
@staticmethod
def _parse_all(text):
-4
View File
@@ -18,10 +18,6 @@ class HamQSL(HTTPSolarConditionsProvider):
super().__init__(provider_config, URL, POLL_INTERVAL)
def _http_response_to_solar_conditions(self, http_response):
if http_response.status_code != 200:
logging.warning("HamQSL solar conditions API returned HTTP " + str(http_response.status_code))
return None
root = ElementTree.fromstring(http_response.text)
sd = root.find("solardata")
if sd is None:
@@ -39,12 +39,17 @@ class HTTPSolarConditionsProvider(SolarConditionsProvider):
try:
logging.debug("Polling " + self.name + " solar conditions API...")
http_response = requests.get(self._url, headers=HTTP_HEADERS, timeout=(5, 30))
new_data = self._http_response_to_solar_conditions(http_response)
self.update_data(new_data)
# Check response code was good
if http_response.status_code == 200:
new_data = self._http_response_to_solar_conditions(http_response)
self.update_data(new_data)
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " solar conditions API.")
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " solar conditions API.")
else:
self.status = "Error"
logging.warning(f"{self.name} solar conditions API returned HTTP {http_response.status_code}.")
except Exception:
self.status = "Error"
+4 -4
View File
@@ -44,9 +44,9 @@ class KC2GProp(SolarConditionsProvider):
def _poll(self):
try:
logging.debug("Polling KC2G ionosonde data...")
response = requests.get(KC2G_URL, headers=HTTP_HEADERS, timeout=(5, 30))
if response.status_code != 200:
logging.warning(f"KC2G ionosonde API returned HTTP {response.status_code}")
http_response = requests.get(KC2G_URL, headers=HTTP_HEADERS, timeout=(5, 30))
if http_response.status_code != 200:
logging.warning(f"KC2G ionosonde API returned HTTP {http_response.status_code}")
return
now = datetime.now(timezone.utc)
@@ -57,7 +57,7 @@ class KC2GProp(SolarConditionsProvider):
ionosonde_data = dict(self._solar_conditions.ionosonde_data or {})
updated_count = 0
for reading in response.json():
for reading in http_response.json():
station = reading.get("station", {})
ursi = station.get("code")
name = station.get("name")
@@ -80,10 +80,6 @@ class NOAA3dayForecast(HTTPSolarConditionsProvider):
return result if result else None
def _http_response_to_solar_conditions(self, http_response):
if http_response.status_code != 200:
logging.warning("NOAA K-index forecast API returned HTTP " + str(http_response.status_code))
return None
lines = http_response.text.splitlines()
# Find the "NOAA Kp index breakdown" section header
+3 -3
View File
@@ -8,7 +8,7 @@ import sys
from diskcache import Cache
from core.cleanup import CleanupTimer
from core.config import config, SERVER_OWNER_CALLSIGN
from core.config import config, SERVER_OWNER_CALLSIGN, LOG_LEVEL
from core.constants import SOFTWARE_VERSION
from core.lookup_helper import lookup_helper
from core.status_reporter import StatusReporter
@@ -84,9 +84,9 @@ def get_solar_conditions_provider_from_config(config_providers_entry):
if __name__ == '__main__':
# Set up logging
root = logging.getLogger()
root.setLevel(logging.INFO)
root.setLevel(LOG_LEVEL)
handler = logging.StreamHandler(sys.stdout)
handler.setLevel(logging.INFO)
handler.setLevel(LOG_LEVEL)
formatter = logging.Formatter("%(levelname)s : %(message)s")
handler.setFormatter(formatter)
root.handlers.clear()
+13 -8
View File
@@ -41,15 +41,20 @@ class HTTPSpotProvider(SpotProvider):
# Request data from API
logging.debug("Polling " + self.name + " spot API...")
http_response = requests.get(self._url, headers=HTTP_HEADERS, timeout=(5, 30))
# Pass off to the subclass for processing
new_spots = self._http_response_to_spots(http_response)
# Submit the new spots for processing. There might not be any spots for the less popular programs.
if new_spots:
self._submit_batch(new_spots)
# Check response code was good
if http_response.status_code == 200:
# Pass off to the subclass for processing
new_spots = self._http_response_to_spots(http_response)
# Submit the new spots for processing. There might not be any spots for the less popular programs.
if new_spots:
self._submit_batch(new_spots)
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " spot API.")
self.status = "OK"
self.last_update_time = datetime.now(pytz.UTC)
logging.debug("Received data from " + self.name + " spot API.")
else:
self.status = "Error"
logging.warning(f"{self.name} spot API returned HTTP {http_response.status_code}.")
except Exception:
self.status = "Error"
+1 -1
View File
@@ -76,7 +76,7 @@
</div>
<script src="/js/add-spot.js?v=1783702256"></script>
<script src="/js/add-spot.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-add-spot").addClass("active");
}); <!-- highlight active page in nav --></script>
+1 -1
View File
@@ -75,7 +75,7 @@
</div>
<script src="/js/alerts.js?v=1783702256"></script>
<script src="/js/alerts.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-alerts").addClass("active");
}); <!-- highlight active page in nav --></script>
+2 -2
View File
@@ -75,8 +75,8 @@
<script>
let spotProvidersEnabledByDefault = {% raw json_encode(web_ui_options["spot-providers-enabled-by-default"]) %};
</script>
<script src="/js/spotsbandsandmap.js?v=1783702256"></script>
<script src="/js/bands.js?v=1783702256"></script>
<script src="/js/spotsbandsandmap.js?v=1784963837"></script>
<script src="/js/bands.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-bands").addClass("active");
}); <!-- highlight active page in nav --></script>
+5 -5
View File
@@ -1,6 +1,6 @@
{% extends "skeleton.html" %}
{% block head_extra %}
<link rel="stylesheet" href="/css/style.css?v=1783702256" type="text/css">
<link rel="stylesheet" href="/css/style.css?v=1784963837" type="text/css">
<link href="/vendor/css/bootstrap-5.3.8.min.css" rel="stylesheet">
<link href="/vendor/css/fontawesome-6.7.2.min.css" rel="stylesheet">
<link href="/vendor/css/solid-6.7.2.min.css" rel="stylesheet">
@@ -10,10 +10,10 @@
<script src="/vendor/js/bootstrap-5.3.8.bundle.min.js"></script>
<script src="/vendor/js/tinycolor2-1.6.0.min.js"></script>
<script src="/js/utils.js?v=1783702256"></script>
<script src="/js/ui-ham.js?v=1783702256"></script>
<script src="/js/geo.js?v=1783702256"></script>
<script src="/js/common.js?v=1783702256"></script>
<script src="/js/utils.js?v=1784963837"></script>
<script src="/js/ui-ham.js?v=1784963837"></script>
<script src="/js/geo.js?v=1784963837"></script>
<script src="/js/common.js?v=1784963837"></script>
{% end %}
{% block body %}
<div class="container">
+1 -1
View File
@@ -284,7 +284,7 @@
</div>
<script src="/vendor/js/chart-4.4.9.umd.min.js"></script>
<script src="/js/conditions.js?v=1783702256"></script>
<script src="/js/conditions.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-conditions").addClass("active");
}); <!-- highlight active page in nav --></script>
+2 -2
View File
@@ -95,8 +95,8 @@
<script>
let spotProvidersEnabledByDefault = {% raw json_encode(web_ui_options["spot-providers-enabled-by-default"]) %};
</script>
<script src="/js/spotsbandsandmap.js?v=1783702255"></script>
<script src="/js/map.js?v=1783702255"></script>
<script src="/js/spotsbandsandmap.js?v=1784963837"></script>
<script src="/js/map.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-map").addClass("active");
}); <!-- highlight active page in nav --></script>
+2 -2
View File
@@ -116,8 +116,8 @@
<script>
let spotProvidersEnabledByDefault = {% raw json_encode(web_ui_options["spot-providers-enabled-by-default"]) %};
</script>
<script src="/js/spotsbandsandmap.js?v=1783702255"></script>
<script src="/js/spots.js?v=1783702255"></script>
<script src="/js/spotsbandsandmap.js?v=1784963837"></script>
<script src="/js/spots.js?v=1784963837"></script>
<script>$(document).ready(function () {
$("#nav-link-spots").addClass("active");
}); <!-- highlight active page in nav --></script>
+1 -1
View File
@@ -59,7 +59,7 @@
</div>
</div>
<script src="/js/status.js?v=1783702256"></script>
<script src="/js/status.js?v=1784963837"></script>
<script>
$(document).ready(function () {
$("#nav-link-status").addClass("active");