mirror of
https://github.com/ZoneMinder/zoneminder.git
synced 2026-10-06 09:22:04 -04:00
fix: schedule ONVIF subscription renewal for short and unreported lifetimes (#5181)
* fix: schedule ONVIF subscription renewal for short and unreported lifetimes refs #5179 The Beward camera from #5165 grants a 60 second subscription and its RenewResponse carries no TerminationTime. Three things combined so that ZM renewed after every PullMessages that returned messages (61 renewals in 74 seconds of the reporter's log): - The renewal was scheduled a fixed ONVIF_RENEWAL_ADVANCE_SECONDS (60) before termination, which for a 60 second subscription is its creation time. ONVIFNextRenewalTime() now uses the smaller of that advance and half the remaining lifetime. - Renew() only logged a missing TerminationTime and left next_renewal_time in the past. assume_renewal_times() now schedules from the lifetime we asked for, capped at what the camera last granted (ONVIFAssumedLifetime()), so this camera renews every 30 seconds. - IsRenewalNeeded() was only checked after a response carrying messages, so a camera quiet for longer than its subscription was never renewed. It is now also checked after an empty (SOAP_EOF) poll. Since renewal is now checked after every poll, a camera that answers Renew with ActionNotSupported has renewal disabled rather than being asked again on each poll, matching the existing handling of unusable TerminationTimes. Tests cover the renewal time for long, short and very short subscriptions, and the assumed lifetime with no, smaller and larger previously granted lifetimes. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> * fix: only disable ONVIF renewal for ActionNotSupported, keep sub-second grants refs #5179 Review follow-ups on the renewal scheduling change: - Renew() treated soap->error == 12 as ActionNotSupported, but 12 is gSOAP's generic SOAP_FAULT. With renewal now disabled on that path, a NotAuthorized or InvalidArgVal fault from Renew would have stopped renewal for good while marking the subscription healthy. ONVIFIsActionNotSupported() checks the fault subcode and string for ActionNotSupported (wsa: or ter:); any other fault now takes the existing cleanup and re-subscribe path. - granted_lifetime truncated the remaining time to whole seconds. A termination less than a second away stored 0, which reads as "never reported", so the next Renew without a TerminationTime assumed the full requested 300 seconds. ONVIFGrantedLifetime() rounds up instead. Tests cover ActionNotSupported subcodes and strings against other faults and non-fault results, and the granted lifetime for whole, fractional and sub-second remainders. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> * fix: count an assumed ONVIF renewal lifetime from the request, not the response refs #5179 When a RenewResponse has no TerminationTime, assume_renewal_times() started the assumed lifetime when the response arrived, but the camera counts it from when it received the request. A slow response pushed the deadline and the next renewal later by the response time: with subscription_timeout=10 and a 6 second response, the camera's deadline was request+10 but the renewal was scheduled for request+11. In absolute renewal mode it also ignored the exact deadline that was sent. Renew() now records the time just before building the request and the deadline it asks for: request time plus subscription_timeout, or the absolute whole-second time it sends. ONVIFAssumedTermination() replaces ONVIFAssumedLifetime() and returns that deadline, capped at request time plus the lifetime the camera last granted. The renewal is scheduled from the request time; if the response arrived after it, it is already due and the next poll renews. Tests cover no, smaller and larger previous grants, an absolute deadline kept exactly, and the slow-response case from review. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
1 parent
222b4d7c9e
commit
82901ac1fb
3 files changed
+199
-6
No files matched your search
@@ -129,6 +129,29 @@ namespace {
|
||||
}
|
||||
}
|
||||
|
||||
SystemTimePoint ONVIFNextRenewalTime(const SystemTimePoint &now, const SystemTimePoint &termination) {
|
||||
auto advance = std::min<SystemTimePoint::duration>(std::chrono::seconds(ONVIF_RENEWAL_ADVANCE_SECONDS),
|
||||
(termination - now) / 2);
|
||||
return termination - advance;
|
||||
}
|
||||
|
||||
SystemTimePoint ONVIFAssumedTermination(const SystemTimePoint &request_time,
|
||||
const SystemTimePoint &requested_termination,
|
||||
std::chrono::seconds last_granted) {
|
||||
if (last_granted.count() <= 0) return requested_termination;
|
||||
return std::min(requested_termination, request_time + last_granted);
|
||||
}
|
||||
|
||||
std::chrono::seconds ONVIFGrantedLifetime(const SystemTimePoint &now, const SystemTimePoint &termination) {
|
||||
return std::chrono::ceil<std::chrono::seconds>(termination - now);
|
||||
}
|
||||
|
||||
bool ONVIFIsActionNotSupported(int result, const char *subcode, const char *fault_string) {
|
||||
if (result != SOAP_FAULT) return false;
|
||||
return (subcode and std::strstr(subcode, "ActionNotSupported")) or
|
||||
(fault_string and std::strstr(fault_string, "ActionNotSupported"));
|
||||
}
|
||||
|
||||
ONVIF::ONVIF(Monitor *parent_) :
|
||||
parent(parent_)
|
||||
,alarmed_(false)
|
||||
@@ -146,6 +169,7 @@ ONVIF::ONVIF(Monitor *parent_) :
|
||||
,soap_log_fd(nullptr)
|
||||
,subscription_termination_time()
|
||||
,next_renewal_time()
|
||||
,granted_lifetime(0)
|
||||
,use_absolute_time_for_renewal(false)
|
||||
,renewal_enabled(true)
|
||||
,camera_clock_offset(0)
|
||||
@@ -587,6 +611,10 @@ void ONVIF::WaitForMessage() {
|
||||
std::unique_lock<std::mutex> lck(alarms_mutex);
|
||||
expire_stale_alarms(std::chrono::system_clock::now());
|
||||
}
|
||||
|
||||
// A camera with no events for longer than its subscription lifetime
|
||||
// only ever reaches this branch, so renew from here too.
|
||||
if (IsRenewalNeeded()) Renew();
|
||||
}
|
||||
} else {
|
||||
// Success - reset retry count and warning flags
|
||||
@@ -1100,12 +1128,23 @@ void ONVIF::update_renewal_times(time_t camera_current_time, time_t termination_
|
||||
return;
|
||||
}
|
||||
|
||||
// Calculate renewal time: N seconds before termination
|
||||
next_renewal_time = subscription_termination_time - std::chrono::seconds(ONVIF_RENEWAL_ADVANCE_SECONDS);
|
||||
granted_lifetime = ONVIFGrantedLifetime(now, subscription_termination_time);
|
||||
next_renewal_time = ONVIFNextRenewalTime(now, subscription_termination_time);
|
||||
|
||||
log_subscription_timing("Updated subscription");
|
||||
} // end void ONVIF::update_renewal_times(time_t camera_current_time, time_t termination_time)
|
||||
|
||||
// Schedule the next renewal after a Renew whose response did not say when the
|
||||
// subscription now ends. Without this next_renewal_time stays in the past and
|
||||
// every PullMessages is followed by another Renew.
|
||||
void ONVIF::assume_renewal_times(const SystemTimePoint &request_time, const SystemTimePoint &requested_termination) {
|
||||
subscription_termination_time = ONVIFAssumedTermination(request_time, requested_termination, granted_lifetime);
|
||||
// If the response was slow this can already be past, and the next poll renews
|
||||
next_renewal_time = ONVIFNextRenewalTime(request_time, subscription_termination_time);
|
||||
Debug(1, "ONVIF: No TerminationTime in RenewResponse, assuming the subscription ends at %s",
|
||||
SystemTimePointToString(subscription_termination_time).c_str());
|
||||
}
|
||||
|
||||
// Check if renewal tracking has been initialized
|
||||
// Returns false if tracking times are at epoch (uninitialized), true otherwise
|
||||
bool ONVIF::is_renewal_tracking_initialized() const {
|
||||
@@ -1151,11 +1190,16 @@ bool ONVIF::Renew() {
|
||||
_wsnt__RenewResponse wsnt__RenewResponse;
|
||||
|
||||
std::string termination_time_str;
|
||||
// When the request goes out and the deadline it asks for, in case the
|
||||
// response does not say when the subscription now ends
|
||||
SystemTimePoint request_time = std::chrono::system_clock::now();
|
||||
SystemTimePoint requested_termination = request_time + std::chrono::seconds(subscription_timeout_seconds);
|
||||
|
||||
if (use_absolute_time_for_renewal) {
|
||||
// Calculate absolute termination time: current time + subscription duration
|
||||
time_t now = time(nullptr);
|
||||
time_t now = std::chrono::system_clock::to_time_t(request_time);
|
||||
time_t absolute_termination = now + subscription_timeout_seconds;
|
||||
requested_termination = std::chrono::system_clock::from_time_t(absolute_termination);
|
||||
termination_time_str = format_absolute_time_iso8601(absolute_termination);
|
||||
|
||||
if (termination_time_str.empty()) {
|
||||
@@ -1184,8 +1228,11 @@ bool ONVIF::Renew() {
|
||||
|
||||
if (proxyEvent.Renew(subscription_address_.c_str(), nullptr, &wsnt__Renew, wsnt__RenewResponse) != SOAP_OK) {
|
||||
Debug(1, "ONVIF: Couldn't do Renew! Error %i %s, %s", soap->error, soap_fault_string(soap), soap_fault_detail(soap));
|
||||
if (soap->error == 12) { // ActionNotSupported
|
||||
Debug(2, "ONVIF: Renew not supported by device, continuing without renewal");
|
||||
if (ONVIFIsActionNotSupported(soap->error, soap_fault_subcode(soap), soap_fault_string(soap))) {
|
||||
// Renewal is checked after every PullMessages, so keep asking and every
|
||||
// poll would carry a doomed Renew.
|
||||
Debug(2, "ONVIF: Renew not supported by device, disabling renewal - will re-subscribe when subscription expires");
|
||||
renewal_enabled = false;
|
||||
setHealthy(true);
|
||||
soap_destroy(soap);
|
||||
soap_end(soap);
|
||||
@@ -1211,7 +1258,8 @@ bool ONVIF::Renew() {
|
||||
update_renewal_times(current_time, wsnt__RenewResponse.TerminationTime);
|
||||
log_subscription_timing("renewed");
|
||||
} else {
|
||||
Debug(1, "No TerminationTime in RenewResponse");
|
||||
assume_renewal_times(request_time, requested_termination);
|
||||
log_subscription_timing("renewed");
|
||||
}
|
||||
|
||||
// Clean up gSOAP allocated memory from Renew response
|
||||
|
||||
@@ -64,6 +64,33 @@ std::chrono::milliseconds ONVIFEarlyPollWait(std::chrono::steady_clock::duration
|
||||
// same pass that raised it.
|
||||
bool ONVIFAlarmTermination(time_t termination_time, time_t camera_current_time, const SystemTimePoint &now,
|
||||
time_t &clock_offset, SystemTimePoint &termination);
|
||||
|
||||
// When to renew a subscription that ends at termination, given that we learnt
|
||||
// of it at now: ONVIF_RENEWAL_ADVANCE_SECONDS before the end, or halfway
|
||||
// through for a subscription shorter than twice that. A fixed advance put the
|
||||
// renewal of a 60 second subscription at its creation time, so it was always
|
||||
// due.
|
||||
SystemTimePoint ONVIFNextRenewalTime(const SystemTimePoint &now, const SystemTimePoint &termination);
|
||||
|
||||
// Termination to assume after a Renew whose response carries no
|
||||
// TerminationTime: the deadline we asked for (requested_termination), but no
|
||||
// later than request_time plus what the camera last granted (last_granted,
|
||||
// zero when it never said). Counted from when the request was sent, not when
|
||||
// the response arrived, so a slow response cannot move the deadline later.
|
||||
SystemTimePoint ONVIFAssumedTermination(const SystemTimePoint &request_time,
|
||||
const SystemTimePoint &requested_termination,
|
||||
std::chrono::seconds last_granted);
|
||||
|
||||
// Lifetime the camera granted, from a termination after now, in whole seconds
|
||||
// rounded up. Termination times have one-second precision and now does not,
|
||||
// so truncating would turn a short grant into zero, which means unknown.
|
||||
std::chrono::seconds ONVIFGrantedLifetime(const SystemTimePoint &now, const SystemTimePoint &termination);
|
||||
|
||||
// Whether a failed Renew means the camera does not support renewal. gSOAP
|
||||
// reports every SOAP fault as SOAP_FAULT; the reason is in the subcode
|
||||
// (wsa:ActionNotSupported, ter:ActionNotSupported) or the fault string.
|
||||
// subcode and fault_string may be null.
|
||||
bool ONVIFIsActionNotSupported(int result, const char *subcode, const char *fault_string);
|
||||
#endif
|
||||
|
||||
// Forward declaration
|
||||
@@ -126,6 +153,7 @@ class ONVIF {
|
||||
// Subscription renewal tracking
|
||||
SystemTimePoint subscription_termination_time;
|
||||
SystemTimePoint next_renewal_time;
|
||||
std::chrono::seconds granted_lifetime; // Lifetime the camera last reported granting, 0 if never
|
||||
bool use_absolute_time_for_renewal;
|
||||
bool renewal_enabled;
|
||||
time_t camera_clock_offset; // Offset in seconds: our_time - camera_time
|
||||
@@ -159,6 +187,7 @@ class ONVIF {
|
||||
void parse_onvif_options();
|
||||
int get_retry_delay();
|
||||
void update_renewal_times(time_t camera_current_time, time_t termination_time);
|
||||
void assume_renewal_times(const SystemTimePoint &request_time, const SystemTimePoint &requested_termination);
|
||||
bool is_renewal_tracking_initialized() const;
|
||||
void log_subscription_timing(const char* context);
|
||||
bool Renew();
|
||||
|
||||
@@ -16,6 +16,7 @@
|
||||
*/
|
||||
|
||||
#include "zm_catch2.h"
|
||||
#include "zm_monitor_onvif.h"
|
||||
#include "zm_time.h"
|
||||
#include <chrono>
|
||||
#include <string>
|
||||
@@ -352,3 +353,118 @@ TEST_CASE("ONVIF Per-Topic Alarm Expiry") {
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
#ifdef WITH_GSOAP
|
||||
|
||||
TEST_CASE("ONVIFNextRenewalTime", "[onvif]") {
|
||||
const SystemTimePoint now = std::chrono::system_clock::from_time_t(1790880716);
|
||||
|
||||
SECTION("Long subscription renews 60 seconds before it ends") {
|
||||
SystemTimePoint termination = now + std::chrono::seconds(300);
|
||||
REQUIRE(ONVIFNextRenewalTime(now, termination) == now + std::chrono::seconds(240));
|
||||
}
|
||||
|
||||
SECTION("Subscription no longer than the advance renews halfway through") {
|
||||
// The #5179 Beward grants 60 seconds. A fixed 60 second advance put the
|
||||
// renewal at the creation time, so it was due immediately.
|
||||
SystemTimePoint termination = now + std::chrono::seconds(60);
|
||||
REQUIRE(ONVIFNextRenewalTime(now, termination) == now + std::chrono::seconds(30));
|
||||
|
||||
termination = now + std::chrono::seconds(10);
|
||||
REQUIRE(ONVIFNextRenewalTime(now, termination) == now + std::chrono::seconds(5));
|
||||
}
|
||||
|
||||
SECTION("Renewal is always strictly in the future for a future termination") {
|
||||
SystemTimePoint termination = now + std::chrono::seconds(1);
|
||||
REQUIRE(ONVIFNextRenewalTime(now, termination) > now);
|
||||
}
|
||||
}
|
||||
|
||||
TEST_CASE("ONVIFAssumedTermination", "[onvif]") {
|
||||
using std::chrono::seconds;
|
||||
// The moment Renew() sent the request
|
||||
const SystemTimePoint request_time = std::chrono::system_clock::from_time_t(1790880716);
|
||||
const SystemTimePoint requested = request_time + seconds(300);
|
||||
|
||||
SECTION("Camera never reported a lifetime: assume the deadline we asked for") {
|
||||
REQUIRE(ONVIFAssumedTermination(request_time, requested, seconds(0)) == requested);
|
||||
}
|
||||
|
||||
SECTION("Camera granted less than we asked for before: assume it does so again") {
|
||||
// The #5179 Beward granted 60 seconds on Subscribe and sends no
|
||||
// TerminationTime on Renew.
|
||||
REQUIRE(ONVIFAssumedTermination(request_time, requested, seconds(60)) == request_time + seconds(60));
|
||||
}
|
||||
|
||||
SECTION("Camera granted more than we asked for: assume only what we asked for") {
|
||||
REQUIRE(ONVIFAssumedTermination(request_time, requested, seconds(3600)) == requested);
|
||||
}
|
||||
|
||||
SECTION("An absolute deadline we sent is kept exactly") {
|
||||
// Absolute renewal requests a whole-second time, which can be slightly
|
||||
// less than request_time + subscription_timeout.
|
||||
const SystemTimePoint absolute = std::chrono::system_clock::from_time_t(1790880716 + 10);
|
||||
REQUIRE(ONVIFAssumedTermination(request_time + std::chrono::milliseconds(700), absolute, seconds(0)) == absolute);
|
||||
}
|
||||
|
||||
SECTION("A slow response does not push the deadline or renewal later") {
|
||||
// subscription_timeout=10 and the response arrives 6 seconds after the
|
||||
// request. Counting from the response put the renewal at request+11,
|
||||
// after the camera's deadline at request+10.
|
||||
const SystemTimePoint deadline = request_time + seconds(10);
|
||||
const SystemTimePoint response_time = request_time + seconds(6);
|
||||
SystemTimePoint termination = ONVIFAssumedTermination(request_time, deadline, seconds(0));
|
||||
REQUIRE(termination == deadline);
|
||||
SystemTimePoint renewal = ONVIFNextRenewalTime(request_time, termination);
|
||||
REQUIRE(renewal < termination);
|
||||
// Already due when the response arrives, so the next poll renews
|
||||
REQUIRE(renewal <= response_time);
|
||||
}
|
||||
}
|
||||
|
||||
TEST_CASE("ONVIFGrantedLifetime", "[onvif]") {
|
||||
// Termination times have whole-second precision; now does not.
|
||||
const SystemTimePoint termination = std::chrono::system_clock::from_time_t(1790880776);
|
||||
|
||||
SECTION("Whole seconds are kept") {
|
||||
REQUIRE(ONVIFGrantedLifetime(termination - std::chrono::seconds(60), termination) == std::chrono::seconds(60));
|
||||
}
|
||||
|
||||
SECTION("A fraction of a second rounds up, not down") {
|
||||
REQUIRE(ONVIFGrantedLifetime(termination - std::chrono::milliseconds(59200), termination) == std::chrono::seconds(60));
|
||||
}
|
||||
|
||||
SECTION("Less than a second left is still a known, positive lifetime") {
|
||||
// Truncating to zero would read as "never reported" and make the next
|
||||
// TerminationTime-less Renew assume the full requested lifetime.
|
||||
REQUIRE(ONVIFGrantedLifetime(termination - std::chrono::milliseconds(300), termination) == std::chrono::seconds(1));
|
||||
const SystemTimePoint request_time = termination - std::chrono::milliseconds(300);
|
||||
REQUIRE(ONVIFAssumedTermination(request_time, request_time + std::chrono::seconds(300),
|
||||
ONVIFGrantedLifetime(request_time, termination))
|
||||
== request_time + std::chrono::seconds(1));
|
||||
}
|
||||
}
|
||||
|
||||
TEST_CASE("ONVIFIsActionNotSupported", "[onvif]") {
|
||||
SECTION("WS-Addressing and ONVIF ActionNotSupported faults") {
|
||||
REQUIRE(ONVIFIsActionNotSupported(SOAP_FAULT, "wsa:ActionNotSupported", nullptr));
|
||||
REQUIRE(ONVIFIsActionNotSupported(SOAP_FAULT, "wsa5:ActionNotSupported", nullptr));
|
||||
REQUIRE(ONVIFIsActionNotSupported(SOAP_FAULT, "ter:ActionNotSupported", "Optional Action Not Implemented"));
|
||||
REQUIRE(ONVIFIsActionNotSupported(SOAP_FAULT, nullptr, "ActionNotSupported"));
|
||||
}
|
||||
|
||||
SECTION("Other SOAP faults are not ActionNotSupported") {
|
||||
// SOAP_FAULT (12) covers every fault. Treating them all as unsupported
|
||||
// disabled renewal for good after e.g. an authorization failure.
|
||||
REQUIRE_FALSE(ONVIFIsActionNotSupported(SOAP_FAULT, "ter:NotAuthorized", "Sender not authorized"));
|
||||
REQUIRE_FALSE(ONVIFIsActionNotSupported(SOAP_FAULT, "ter:InvalidArgVal", nullptr));
|
||||
REQUIRE_FALSE(ONVIFIsActionNotSupported(SOAP_FAULT, nullptr, nullptr));
|
||||
}
|
||||
|
||||
SECTION("Non-fault results are never ActionNotSupported") {
|
||||
REQUIRE_FALSE(ONVIFIsActionNotSupported(SOAP_EOF, "wsa:ActionNotSupported", nullptr));
|
||||
REQUIRE_FALSE(ONVIFIsActionNotSupported(401, nullptr, "ActionNotSupported"));
|
||||
}
|
||||
}
|
||||
|
||||
#endif // WITH_GSOAP
|
||||
Reference in new issue
Block a user