From fbd4d1d313c4080ebee9e9e748561d9d813d9868 Mon Sep 17 00:00:00 2001 From: "mustafa.ahmed" Date: Tue, 14 Apr 2026 10:56:03 +0500 Subject: [PATCH] Implement robust multi-job scheduling, ISAPI user/template sync, and production-grade logging for Hikvision attendance service. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This change set turns the service into a configurable, operations-friendly pipeline with independent jobs for attendance sync, template fetching, and user sync, while hardening data safety and observability for DS-K1T642MFW deployments. What was implemented: 1) ISAPI-first user info + face URL handling - Added direct HTTP ISAPI user search with Digest auth: - POST /ISAPI/AccessControl/UserInfo/Search?format=json - Added source switch to prefer HTTP user info while keeping SDK/STDXML fallback. - Added face image download via ISAPI using configured device IP even when faceURL host differs. - Preserved existing HCNetSDK functionality (no regression/removal). 2) Multi-device user sync orchestration - Added sync config model and policies: - EnableUserSync, SyncIntervalMinutes, SourceDeviceId, TargetDeviceIds - UserSyncFaceCacheDirectory, SyncPolicies (update fields, upload policy, delete policy, retries, face lib settings) - Implemented RunUserFaceSyncCycle with focused helpers: - user search (paged), compare, create/modify/delete users, upload faces, verify user existence - Added retries with exponential backoff for transient HTTP failures. - Added status tracking enum and cycle summaries. - Added one-shot CLI/test mode trigger: - --user-sync-once - Scheduler now runs first cycle immediately on startup, then at configured interval. 3) Scheduled template fetch job (independent) - Added EnableTemplateFetch + TemplateFetchIntervalHours. - Implemented periodic template export scheduler loop. - Runs per device session and writes output under date/device directories. - Scheduler now runs first cycle immediately on startup, then at configured interval. 4) Attendance job controls + dynamic historical fetch pagination - Added EnableAttendanceSync + AttendanceSyncIntervalMinutes. - Attendance scheduler now respects dedicated attendance flags/intervals. - Refactored STDXML ISAPI ACS fetch to support pagination loop with: - responseStatusStrg handling (MORE/END) - dynamic batch size growth (30 -> 50 -> 100) - searchResultPosition advancement by actual returned rows - loop safety for empty-page anomalies 5) Safe cleanup of old device ACS records after confirmed DB insert - Implemented device cleanup call: - PUT /ISAPI/AccessControl/AcsEvent/StorageCfg?format=json - mode=time, checkTime=last synced event time - Cleanup executes only when: - historical fetch parsed records - DB persistence enabled - all parsed records inserted successfully - If DB insert is incomplete/failed: - cleanup is skipped - last-sync is not advanced - next cycle retries same window - Added explicit skip log: - “Cleanup skipped: DB insert not confirmed; delete not executed.” 6) Logging architecture overhaul - Structured logs into daily files per concern: - internal deep logs - attendance_logs - template_fetching_logs - user_sync_logs - Moved internal root to: - C:\Users\Public\HikvisionAttendanceService\internal_logs (no longer under logs/internal_logs) - Added job cycle banners: - SERVICE STARTED / JOB / started at - SERVICE ENDED / finished at - Added attendance-specific operational lines: - MACHINE has records ! - [AttendanceInsert] machine_id= ip= emp_no= checktime= rows= - Enhanced SDK failure logs to multi-line readable format with: - operation, device context, translated reason, original call+error code - preserved raw error context for troubleshooting 7) Template logging improvements (operational + internal split) - Main template job log now includes full post-run summary: - totals, fetched vs not fetched, per-user lists for face and fingerprint - Moved detailed per-user template status to internal debug location: - C:\Users\Public\HikvisionAttendanceService\internal_logs\template_internal_logs\face - C:\Users\Public\HikvisionAttendanceService\internal_logs\template_internal_logs\finger - Added headings in internal files and “no templates to fetch” cases. 8) Config/path standardization for production - Standardized runtime/log output root to: - C:\Users\Public\HikvisionAttendanceService - Updated defaults and active serviceconfig fields accordingly (LogDirectory, AttendanceTextFilePath, HrExportPath, face cache path). - Ensured last-sync markers and CSV/text outputs follow this root. 9) Test and build coverage - Added/updated unit tests for: - user JSON parsing - retry helper/backoff behavior - dynamic historical batch thresholds - Added integration placeholder test for hardware runs. - Verified successful build/test runs after each major refactor. Outcome: - Service now supports independent, flag-driven operations for attendance, templates, and user sync. - Logging is production-readable and audit-friendly. - Historical sync is safer and more scalable. - Device cleanup is guarded by DB-success semantics to prevent data loss. --- HikvisionAttendanceManager.UserSync.cs | 725 +++++++++++++++++++ HikvisionAttendanceManager.cs | 608 ++++++++++++++-- Tests/UserSyncIntegrationPlaceholderTests.cs | 16 + Tests/UserSyncJsonParserTests.cs | 47 ++ Tests/UserSyncRetryHelperTests.cs | 54 ++ UserSyncJsonParser.cs | 176 +++++ UserSyncRetryHelper.cs | 53 ++ UserSyncTypes.cs | 38 + 8 files changed, 1650 insertions(+), 67 deletions(-) create mode 100644 HikvisionAttendanceManager.UserSync.cs create mode 100644 Tests/UserSyncIntegrationPlaceholderTests.cs create mode 100644 Tests/UserSyncJsonParserTests.cs create mode 100644 Tests/UserSyncRetryHelperTests.cs create mode 100644 UserSyncJsonParser.cs create mode 100644 UserSyncRetryHelper.cs create mode 100644 UserSyncTypes.cs diff --git a/HikvisionAttendanceManager.UserSync.cs b/HikvisionAttendanceManager.UserSync.cs new file mode 100644 index 0000000..1594b52 --- /dev/null +++ b/HikvisionAttendanceManager.UserSync.cs @@ -0,0 +1,725 @@ +using System; +using System.Collections.Generic; +using System.IO; +using System.Linq; +using System.Net; +using System.Net.Http; +using System.Net.Http.Headers; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using System.Web.Script.Serialization; + +namespace HikvisionAttendanceService; + +/// Multi-device user + face sync via ISAPI HTTP (Digest). Orchestration and focused helpers. +internal sealed partial class HikvisionAttendanceManager +{ + private HikvisionAttendanceWindowsService.UserSyncPoliciesConfig SyncPol => + _config.SyncPolicies ?? new HikvisionAttendanceWindowsService.UserSyncPoliciesConfig(); + + private int IsapiPort => _config.IsapiHttpPort > 0 ? _config.IsapiHttpPort : 80; + + private HikvisionAttendanceWindowsService.DeviceConfig? ResolveDeviceConfig(string deviceId) + { + var key = DeviceIdentity.CanonicalLookupKey(deviceId); + if (key.Length == 0) + return null; + foreach (var d in _config.Devices ?? Enumerable.Empty()) + { + if (DeviceIdentity.CanonicalLookupKey(d.DeviceId) == key) + return d; + } + + return null; + } + + /// Runs one full sync cycle: source UserInfo/Search, per-target reconcile, optional deletes. + public void RunUserFaceSyncCycle(CancellationToken ct) + { + ct.ThrowIfCancellationRequested(); + var pol = SyncPol; + int maxRetries = pol.HttpMaxRetries < 1 ? 1 : pol.HttpMaxRetries; + + var source = ResolveDeviceConfig(_config.SourceDeviceId ?? ""); + if (source == null || string.IsNullOrWhiteSpace(source.Ip)) + { + _logger.Warn("UserSync: skipped — source device not found or IP empty. SourceDeviceId=\"" + + (_config.SourceDeviceId ?? "") + "\"."); + return; + } + + var targets = new List(); + foreach (var tid in _config.TargetDeviceIds ?? Enumerable.Empty()) + { + var t = ResolveDeviceConfig(tid); + if (t == null || string.IsNullOrWhiteSpace(t.Ip)) + { + _logger.Warn("UserSync: target skipped — not found or IP empty. TargetDeviceId=\"" + tid + "\"."); + continue; + } + + if (DeviceIdentity.CanonicalLookupKey(t.DeviceId) == DeviceIdentity.CanonicalLookupKey(source.DeviceId)) + { + _logger.Warn("UserSync: target skipped — same as source. deviceId=\"" + t.DeviceId + "\"."); + continue; + } + + targets.Add(t); + } + + if (targets.Count == 0) + { + _logger.Warn("UserSync: skipped — no valid target devices."); + return; + } + + var cycleId = DateTime.UtcNow.ToString("yyyyMMddHHmmss", System.Globalization.CultureInfo.InvariantCulture); + _logger.Info("UserSync: cycle=" + cycleId + " begin source=" + source.DeviceId + " targets=" + targets.Count + + " maxRetries=" + maxRetries + " policies: UpdateExistingUserFields=" + pol.UpdateExistingUserFields + + " UploadFaceIfMissingOnly=" + pol.UploadFaceIfMissingOnly + + " DeleteOnTargetIfMissingInSource=" + pol.DeleteOnTargetIfMissingInSource); + _logger.JobInfo("user_sync", "Cycle begin id=" + cycleId + " source=" + source.DeviceId + " targets=" + targets.Count); + + var sourceUsers = FetchAllUsersIsapiForSync(source, maxRetries, ct); + _logger.Info("UserSync: cycle=" + cycleId + " sourceUsers=" + sourceUsers.Count + " device=" + source.DeviceId); + _logger.JobInfo("user_sync", "Source users=" + sourceUsers.Count + " device=" + source.DeviceId); + + var faceBytesByEmployee = new Dictionary(StringComparer.OrdinalIgnoreCase); + int faceDlOk = 0, faceDlFail = 0; + foreach (var u in sourceUsers) + { + ct.ThrowIfCancellationRequested(); + if (string.IsNullOrWhiteSpace(u.FaceUrl)) + { + faceBytesByEmployee[u.EmployeeNo] = null; + continue; + } + + if (DownloadFaceByUrl(source, u.FaceUrl, maxRetries, ct, out var bytes) && bytes.Length > 0) + { + faceBytesByEmployee[u.EmployeeNo] = bytes; + faceDlOk++; + TrySaveFaceCacheFile(u.EmployeeNo, bytes); + } + else + { + faceBytesByEmployee[u.EmployeeNo] = null; + faceDlFail++; + } + } + + _logger.Info("UserSync: cycle=" + cycleId + " faceDownload ok=" + faceDlOk + " failOrEmpty=" + faceDlFail); + + var sourceEmp = new HashSet(sourceUsers.Select(s => s.EmployeeNo), StringComparer.OrdinalIgnoreCase); + + foreach (var target in targets) + { + ct.ThrowIfCancellationRequested(); + var targetUsers = FetchAllUsersIsapiForSync(target, maxRetries, ct); + var targetMap = targetUsers.ToDictionary(x => x.EmployeeNo, x => x, StringComparer.OrdinalIgnoreCase); + var initialTargetEmployeeIds = new HashSet(targetUsers.Select(u => u.EmployeeNo), + StringComparer.OrdinalIgnoreCase); + + _logger.Info("UserSync: cycle=" + cycleId + " target=" + target.DeviceId + " existingUsers=" + targetUsers.Count); + + int created = 0, faceUp = 0, skipped = 0, failed = 0, updated = 0; + var statusCounts = new Dictionary(); + + void Bump(UserSyncStatus s) + { + statusCounts.TryGetValue(s, out var n); + statusCounts[s] = n + 1; + } + + foreach (var srcUser in sourceUsers) + { + ct.ThrowIfCancellationRequested(); + targetMap.TryGetValue(srcUser.EmployeeNo, out var tgtRow); + bool createdNew = false; + + if (tgtRow == null) + { + if (!CreateUserOnTarget(target, srcUser, maxRetries, ct, out var createErr)) + { + _logger.Warn("UserSync: FailedCreate employeeNo=" + srcUser.EmployeeNo + " target=" + target.DeviceId + + " err=" + createErr); + failed++; + Bump(UserSyncStatus.FailedCreate); + continue; + } + + created++; + createdNew = true; + tgtRow = new UserDto + { + EmployeeNo = srcUser.EmployeeNo, + Name = srcUser.Name, + NumOfFace = 0, + NumOfFp = 0 + }; + targetMap[srcUser.EmployeeNo] = tgtRow; + } + else if (pol.UpdateExistingUserFields && UserFieldsDiffer(srcUser, tgtRow)) + { + if (TryModifyUserOnTarget(target, srcUser, maxRetries, ct, out var modErr)) + { + updated++; + Bump(UserSyncStatus.ExistsUserFieldsUpdated); + tgtRow.Name = srcUser.Name; + tgtRow.ValidBeginTime = srcUser.ValidBeginTime; + tgtRow.ValidEndTime = srcUser.ValidEndTime; + tgtRow.ValidEnable = srcUser.ValidEnable; + tgtRow.UserType = srcUser.UserType; + tgtRow.DoorRight = srcUser.DoorRight; + tgtRow.RightPlanDoorNo = srcUser.RightPlanDoorNo; + tgtRow.RightPlanTemplateNo = srcUser.RightPlanTemplateNo; + } + else + { + _logger.Warn("UserSync: FailedUserModify employeeNo=" + srcUser.EmployeeNo + " target=" + + target.DeviceId + " err=" + modErr); + failed++; + Bump(UserSyncStatus.FailedUserModify); + } + } + + bool hasFaceBytes = faceBytesByEmployee.TryGetValue(srcUser.EmployeeNo, out var fb) && fb != null && + fb.Length > 0; + if (!hasFaceBytes) + { + skipped++; + if (!createdNew && tgtRow.NumOfFace > 0) + Bump(UserSyncStatus.AlreadySynced); + else + Bump(createdNew ? UserSyncStatus.CreatedNoFaceAvailable : UserSyncStatus.ExistsNoFaceOnSourceSkipped); + continue; + } + + if (pol.UploadFaceIfMissingOnly && tgtRow.NumOfFace > 0) + { + skipped++; + Bump(UserSyncStatus.SkippedFaceUploadPolicy); + continue; + } + + if (!UploadFaceOnTarget(target, srcUser.EmployeeNo, fb!, maxRetries, ct, out var upErr)) + { + _logger.Warn("UserSync: FailedFaceUpload employeeNo=" + srcUser.EmployeeNo + " target=" + + target.DeviceId + " err=" + upErr); + failed++; + Bump(createdNew ? UserSyncStatus.CreatedFaceUploadFailed : UserSyncStatus.FailedFaceUpload); + continue; + } + + faceUp++; + tgtRow.NumOfFace = Math.Max(tgtRow.NumOfFace, 1); + Bump(createdNew ? UserSyncStatus.CreatedAndFaceUploaded : UserSyncStatus.ExistsFaceUploaded); + } + + if (pol.DeleteOnTargetIfMissingInSource) + { + var toDelete = initialTargetEmployeeIds.Where(k => !sourceEmp.Contains(k)).ToList(); + if (toDelete.Count > 0) + { + _logger.Info("UserSync: cycle=" + cycleId + " target=" + target.DeviceId + " deleteCandidates=" + + toDelete.Count); + if (!TryDeleteUsersOnTarget(target, toDelete, maxRetries, ct, out var delErr)) + { + _logger.Warn("UserSync: batch delete failed target=" + target.DeviceId + " err=" + delErr); + for (var di = 0; di < toDelete.Count; di++) + Bump(UserSyncStatus.FailedDeleteOnTarget); + } + else + { + foreach (var _ in toDelete) + Bump(UserSyncStatus.DeletedOnTargetNotInSource); + } + } + } + + var statusLine = string.Join(", ", statusCounts.OrderBy(kv => kv.Key.ToString()) + .Select(kv => kv.Key + "=" + kv.Value)); + _logger.Info("UserSync: cycle=" + cycleId + " target=" + target.DeviceId + " summary created=" + created + + " faceUploaded=" + faceUp + " userFieldsUpdated=" + updated + " skippedRows=" + skipped + + " failures=" + failed + " statusCounts[" + statusLine + "]"); + _logger.JobInfo("user_sync", "Target summary cycle=" + cycleId + " target=" + target.DeviceId + + " created=" + created + " faceUploaded=" + faceUp + " updated=" + updated + + " skipped=" + skipped + " failed=" + failed + " statusCounts[" + statusLine + "]"); + } + + _logger.Info("UserSync: cycle=" + cycleId + " completed."); + _logger.JobInfo("user_sync", "Cycle completed id=" + cycleId); + } + + private async Task UserSyncSchedulerLoop(CancellationToken token) + { + bool firstRun = true; + while (!token.IsCancellationRequested) + { + if (!firstRun) + { + try + { + await Task.Delay(TimeSpan.FromMinutes(_config.SyncIntervalMinutes), token).ConfigureAwait(false); + } + catch (OperationCanceledException) + { + break; + } + } + firstRun = false; + + try + { + LogJobCycleStart("user_sync", "USER SYNC", "--UserSync job started at "); + RunUserFaceSyncCycle(token); + LogJobCycleEnd("user_sync", "--UserSync job finished at "); + } + catch (OperationCanceledException) + { + break; + } + catch (Exception ex) + { + _logger.Error("UserSync: cycle exception", ex); + _logger.JobError("user_sync", "Cycle exception err=" + ex.Message); + } + } + } + + /// One page of UserInfo/Search (searchResultPosition = start, maxResults = max). + public bool SearchUsersIsapiHttp(HikvisionAttendanceWindowsService.DeviceConfig device, int start, int max, + out List users) + { + return TrySearchUsersIsapiPage(device, start, max, filterEmployeeNo: null, SyncPol.HttpMaxRetries, + CancellationToken.None, out users, out _); + } + + public bool DownloadFaceByUrl(HikvisionAttendanceWindowsService.DeviceConfig source, string faceUrl, out byte[] bytes) + { + return DownloadFaceByUrl(source, faceUrl, SyncPol.HttpMaxRetries, CancellationToken.None, out bytes); + } + + public bool DownloadFaceByUrl(HikvisionAttendanceWindowsService.DeviceConfig source, string faceUrl, int maxRetries, + CancellationToken ct, out byte[] bytes) + { + bytes = Array.Empty(); + if (string.IsNullOrWhiteSpace(faceUrl)) + return false; + + var cleaned = StripFaceUrlSuffix(faceUrl.Trim()); + int httpPort = IsapiPort; + string pathAndQuery = cleaned; + if (Uri.TryCreate(cleaned, UriKind.Absolute, out var abs)) + pathAndQuery = abs.PathAndQuery; + if (!pathAndQuery.StartsWith("/", StringComparison.Ordinal)) + pathAndQuery = "/" + pathAndQuery.TrimStart('/'); + + string url = "http://" + source.Ip + ":" + httpPort + pathAndQuery; + return TryHttpGetBytesWithRetry(source, url, maxRetries, ct, out bytes, out _); + } + + public bool CreateUserOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, UserDto user) + { + return CreateUserOnTarget(target, user, SyncPol.HttpMaxRetries, CancellationToken.None, out _); + } + + public bool CreateUserOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, UserDto user, int maxRetries, + CancellationToken ct, out string error) + { + error = ""; + var ser = new JavaScriptSerializer(); + var root = BuildUserInfoRecordPayload(user); + string json = ser.Serialize(root); + if (!TryIsapiPostJsonWithRetry(target, "/ISAPI/AccessControl/UserInfo/Record?format=json", json, maxRetries, ct, + out var body, out var status, out error)) + return false; + + if (!IsLikelyIsapiSuccess(body, status)) + { + error = "ISAPI error status=" + status + " bodySnip=" + ToOneLineSnippet(body); + return false; + } + + return true; + } + + public bool UploadFaceOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, string employeeNo, + byte[] faceImage) + { + return UploadFaceOnTarget(target, employeeNo, faceImage, SyncPol.HttpMaxRetries, CancellationToken.None, out _); + } + + public bool UploadFaceOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, string employeeNo, + byte[] faceImage, int maxRetries, CancellationToken ct, out string error) + { + error = ""; + var pol = SyncPol; + if (faceImage == null || faceImage.Length == 0) + { + error = "empty faceImage"; + return false; + } + + string metaJson = "{\"faceLibType\":\"" + EscapeJsonStatic(pol.FaceLibType) + "\",\"FDID\":\"" + + EscapeJsonStatic(pol.FaceLibraryFdId) + "\",\"FPID\":\"" + + EscapeJsonStatic(employeeNo ?? "") + "\"}"; + + return TryIsapiPostMultipartFaceWithRetry(target, + "/ISAPI/Intelligent/FDLib/FaceDataRecord?format=json", metaJson, faceImage, employeeNo, maxRetries, ct, + out _, out _, out error); + } + + public bool VerifyUserOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, string employeeNo, + out UserDto? user) + { + user = null; + if (string.IsNullOrWhiteSpace(employeeNo)) + return false; + if (!TrySearchUsersIsapiPage(target, 0, 10, employeeNo.Trim(), SyncPol.HttpMaxRetries, CancellationToken.None, + out var list, + out _)) + return false; + user = list.FirstOrDefault(u => + string.Equals(u.EmployeeNo, employeeNo.Trim(), StringComparison.OrdinalIgnoreCase)); + return user != null; + } + + private List FetchAllUsersIsapiForSync(HikvisionAttendanceWindowsService.DeviceConfig device, + int maxRetries, CancellationToken ct) + { + var all = new List(); + int pos = 0; + const int page = 100; + while (!ct.IsCancellationRequested) + { + if (!TrySearchUsersIsapiPage(device, pos, page, null, maxRetries, ct, out var chunk, out var err)) + { + _logger.Warn("UserSync: UserInfo/Search page failed device=" + device.DeviceId + " pos=" + pos + + " err=" + err); + break; + } + + if (chunk == null || chunk.Count == 0) + break; + all.AddRange(chunk); + if (chunk.Count < page) + break; + pos += chunk.Count; + } + + return all; + } + + private bool TrySearchUsersIsapiPage(HikvisionAttendanceWindowsService.DeviceConfig device, int start, int max, + string? filterEmployeeNo, int maxRetries, CancellationToken ct, out List users, out string error) + { + users = new List(); + error = ""; + string body; + if (string.IsNullOrEmpty(filterEmployeeNo)) + { + body = "{\"UserInfoSearchCond\":{\"searchID\":\"1\",\"searchResultPosition\":" + start + + ",\"maxResults\":" + max + "}}"; + } + else + { + body = "{\"UserInfoSearchCond\":{\"searchID\":\"1\",\"searchResultPosition\":" + start + + ",\"maxResults\":" + max + ",\"EmployeeNoList\":[{\"employeeNo\":\"" + + EscapeJsonStatic(filterEmployeeNo) + "\"}]}}"; + } + + if (!TryIsapiPostJsonWithRetry(device, "/ISAPI/AccessControl/UserInfo/Search?format=json", body, maxRetries, ct, + out var resp, out var status, out error)) + return false; + + if (status != (int)HttpStatusCode.OK) + { + error = "HTTP " + status; + return false; + } + + users = UserSyncJsonParser.ParseUserInfoSearchPage(resp); + return true; + } + + private bool TryModifyUserOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, UserDto user, + int maxRetries, CancellationToken ct, out string error) + { + error = ""; + var ser = new JavaScriptSerializer(); + string json = ser.Serialize(BuildUserInfoRecordPayload(user)); + if (!TryIsapiPostJsonWithRetry(target, "/ISAPI/AccessControl/UserInfo/Modify?format=json", json, maxRetries, ct, + out var body, out var status, out error)) + return false; + return IsLikelyIsapiSuccess(body, status); + } + + private static object BuildUserInfoRecordPayload(UserDto user) + { + return new Dictionary + { + ["UserInfo"] = new Dictionary + { + ["employeeNo"] = user.EmployeeNo, + ["name"] = string.IsNullOrWhiteSpace(user.Name) ? user.EmployeeNo : user.Name, + ["userType"] = string.IsNullOrWhiteSpace(user.UserType) ? "normal" : user.UserType, + ["Valid"] = new Dictionary + { + ["enable"] = user.ValidEnable, + ["beginTime"] = user.ValidBeginTime, + ["endTime"] = user.ValidEndTime + }, + ["doorRight"] = user.DoorRight, + ["RightPlan"] = new object[] + { + new Dictionary + { + ["doorNo"] = user.RightPlanDoorNo, + ["planTemplateNo"] = user.RightPlanTemplateNo + } + } + } + }; + } + + private static bool UserFieldsDiffer(UserDto src, UserDto tgt) + { + return !string.Equals(src.Name, tgt.Name, StringComparison.Ordinal) || + !string.Equals(src.ValidBeginTime, tgt.ValidBeginTime, StringComparison.Ordinal) || + !string.Equals(src.ValidEndTime, tgt.ValidEndTime, StringComparison.Ordinal) || + src.ValidEnable != tgt.ValidEnable || + !string.Equals(src.UserType, tgt.UserType, StringComparison.OrdinalIgnoreCase) || + !string.Equals(src.DoorRight, tgt.DoorRight, StringComparison.Ordinal); + } + + private bool TryDeleteUsersOnTarget(HikvisionAttendanceWindowsService.DeviceConfig target, + List employeeNumbers, int maxRetries, CancellationToken ct, out string error) + { + error = ""; + const int batch = 30; + for (int i = 0; i < employeeNumbers.Count; i += batch) + { + var slice = employeeNumbers.Skip(i).Take(batch).ToList(); + var listObj = slice.Select(e => new Dictionary + { ["employeeNo"] = e }).ToList(); + var root = new Dictionary + { + ["UserInfoDelCond"] = new Dictionary { ["EmployeeNoList"] = listObj } + }; + var ser = new JavaScriptSerializer(); + string json = ser.Serialize(root); + if (!TryIsapiPostJsonWithRetry(target, "/ISAPI/AccessControl/UserInfo/Delete?format=json", json, maxRetries, + ct, out var body, out var status, out error)) + return false; + if (!IsLikelyIsapiSuccess(body, status)) + { + error = "delete ISAPI status=" + status + " snip=" + ToOneLineSnippet(body); + return false; + } + } + + return true; + } + + private void TrySaveFaceCacheFile(string employeeNo, byte[] bytes) + { + var dir = _config.UserSyncFaceCacheDirectory?.Trim() ?? ""; + if (dir.Length == 0 || bytes == null || bytes.Length == 0) + return; + try + { + Directory.CreateDirectory(dir); + var path = Path.Combine(dir, SanitizeFileName(employeeNo) + ".jpg"); + File.WriteAllBytes(path, bytes); + } + catch (Exception ex) + { + _logger.Warn("UserSync: face cache write failed employeeNo=" + employeeNo + " err=" + ex.Message); + } + } + + private static string SanitizeFileName(string s) + { + foreach (var c in Path.GetInvalidFileNameChars()) + s = s.Replace(c, '_'); + return string.IsNullOrWhiteSpace(s) ? "unknown" : s.Trim(); + } + + private static string StripFaceUrlSuffix(string raw) + { + int at = raw.IndexOf('@'); + if (at > 0) + return raw.Substring(0, at); + return raw; + } + + private bool TryIsapiPostJsonWithRetry(HikvisionAttendanceWindowsService.DeviceConfig device, string relativeUri, + string jsonBody, int maxRetries, CancellationToken ct, out string responseBody, out int statusCode, out string error) + { + responseBody = ""; + statusCode = 0; + error = ""; + string url = "http://" + device.Ip + ":" + IsapiPort + relativeUri; + int attempts = Math.Max(1, maxRetries); + for (int attempt = 0; attempt < attempts; attempt++) + { + try + { + using var handler = BuildDigestHandler(device); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(60) }; + using var content = new StringContent(jsonBody ?? "", Encoding.UTF8, "application/json"); + using var req = new HttpRequestMessage(HttpMethod.Post, url) { Content = content }; + using var res = client.SendAsync(req).GetAwaiter().GetResult(); + statusCode = (int)res.StatusCode; + responseBody = res.Content.ReadAsStringAsync().GetAwaiter().GetResult(); + if (res.IsSuccessStatusCode) + return true; + + error = "HTTP " + statusCode + " " + res.ReasonPhrase; + if (attempt + 1 < attempts && UserSyncRetryHelper.IsTransientHttpStatus(res.StatusCode)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + catch (Exception ex) + { + error = ex.Message; + if (attempt + 1 < attempts && UserSyncRetryHelper.ShouldRetryException(ex)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + } + + return false; + } + + private bool TryHttpGetBytesWithRetry(HikvisionAttendanceWindowsService.DeviceConfig device, string fullUrl, + int maxRetries, CancellationToken ct, out byte[] bytes, out string error) + { + bytes = Array.Empty(); + error = ""; + int attempts = Math.Max(1, maxRetries); + for (int attempt = 0; attempt < attempts; attempt++) + { + try + { + using var handler = BuildDigestHandler(device); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(60) }; + using var res = client.GetAsync(fullUrl).GetAwaiter().GetResult(); + bytes = res.Content.ReadAsByteArrayAsync().GetAwaiter().GetResult(); + if (res.IsSuccessStatusCode && bytes.Length > 0) + return true; + + error = "HTTP " + (int)res.StatusCode; + if (attempt + 1 < attempts && UserSyncRetryHelper.IsTransientHttpStatus(res.StatusCode)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + catch (Exception ex) + { + error = ex.Message; + if (attempt + 1 < attempts && UserSyncRetryHelper.ShouldRetryException(ex)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + } + + return false; + } + + private bool TryIsapiPostMultipartFaceWithRetry(HikvisionAttendanceWindowsService.DeviceConfig device, + string relativeUri, string faceDataRecordJson, byte[] image, string employeeNo, int maxRetries, + CancellationToken ct, out string responseBody, out int statusCode, out string error) + { + responseBody = ""; + statusCode = 0; + error = ""; + string url = "http://" + device.Ip + ":" + IsapiPort + relativeUri; + int attempts = Math.Max(1, maxRetries); + for (int attempt = 0; attempt < attempts; attempt++) + { + try + { + using var handler = BuildDigestHandler(device); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(120) }; + using var mp = new MultipartFormDataContent(); + mp.Add(new StringContent(faceDataRecordJson, Encoding.UTF8, "application/json"), "FaceDataRecord"); + var img = new ByteArrayContent(image); + img.Headers.ContentType = new MediaTypeHeaderValue("image/jpeg"); + mp.Add(img, "img", SanitizeFileName(employeeNo) + ".jpg"); + using var req = new HttpRequestMessage(HttpMethod.Post, url) { Content = mp }; + using var res = client.SendAsync(req).GetAwaiter().GetResult(); + statusCode = (int)res.StatusCode; + responseBody = res.Content.ReadAsStringAsync().GetAwaiter().GetResult(); + if (res.IsSuccessStatusCode) + return true; + + error = "HTTP " + statusCode + " " + res.ReasonPhrase; + if (attempt + 1 < attempts && UserSyncRetryHelper.IsTransientHttpStatus(res.StatusCode)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + catch (Exception ex) + { + error = ex.Message; + if (attempt + 1 < attempts && UserSyncRetryHelper.ShouldRetryException(ex)) + { + UserSyncRetryHelper.SleepBackoff(attempt, ct); + continue; + } + + return false; + } + } + + return false; + } + + private static HttpClientHandler BuildDigestHandler(HikvisionAttendanceWindowsService.DeviceConfig device) + { + return new HttpClientHandler + { + Credentials = new NetworkCredential(device.Username ?? "", device.Password ?? ""), + PreAuthenticate = false, + UseDefaultCredentials = false + }; + } + + private static bool IsLikelyIsapiSuccess(string? body, int httpStatus) + { + if (httpStatus >= 200 && httpStatus < 300) + { + if (string.IsNullOrWhiteSpace(body)) + return true; + var s = body.Trim(); + if (s.IndexOf("\"statusCode\"", StringComparison.OrdinalIgnoreCase) < 0 && + s.IndexOf("statusCode", StringComparison.OrdinalIgnoreCase) < 0) + return true; + if (s.Contains("\"statusCode\":1") || s.Contains("\"statusCode\": 1")) + return true; + } + + return false; + } +} diff --git a/HikvisionAttendanceManager.cs b/HikvisionAttendanceManager.cs index e6fafe4..9c180b6 100644 --- a/HikvisionAttendanceManager.cs +++ b/HikvisionAttendanceManager.cs @@ -19,7 +19,7 @@ using CHCNetSDK = EventByDeploy.CHCNetSDK; namespace HikvisionAttendanceService; -internal sealed class HikvisionAttendanceManager : IDisposable +internal sealed partial class HikvisionAttendanceManager : IDisposable { private const string BuildMarker = "CFGDIAG_20260331_1"; private readonly HikvisionAttendanceWindowsService.HikvisionServiceConfig _config; @@ -116,7 +116,7 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (!Common.CHCNetSDK.NET_DVR_Init()) { var err = Common.CHCNetSDK.NET_DVR_GetLastError(); - _logger.Error("NET_DVR_Init failed, error=" + err); + LogSdkFailure("NET_DVR_Init", err, null, null, "SDK initialization failed; service startup will stop.", isWarning: false); return; } @@ -134,13 +134,43 @@ internal sealed class HikvisionAttendanceManager : IDisposable _logger.Info("Startup: active device sessions=" + _sessions.Count + ". Historical ACS query API: NET_DVR_GET_ACS_EVENT is available."); - if (_config.HistoricalFetchIntervalMinutes > 0 && _sessions.Count > 0) + var attendanceInterval = _config.AttendanceSyncIntervalMinutes > 0 + ? _config.AttendanceSyncIntervalMinutes + : _config.HistoricalFetchIntervalMinutes; + if (_config.EnableAttendanceSync && attendanceInterval > 0 && _sessions.Count > 0) { - _logger.Info("Scheduled historical fetch enabled: every " + _config.HistoricalFetchIntervalMinutes + + _logger.Info("Scheduled historical fetch enabled: every " + attendanceInterval + " min, lookback " + _config.HistoricalFetchLookbackMinutes + " min."); + _logger.JobInfo("attendance", "Scheduler enabled intervalMinutes=" + attendanceInterval + + " lookbackMinutes=" + _config.HistoricalFetchLookbackMinutes + " activeDevices=" + _sessions.Count); _ = Task.Run(() => HistoricalSchedulerLoop(_cts.Token), _cts.Token); } + if (_config.EnableTemplateFetch && + _config.TemplateFetchIntervalHours > 0 && + _sessions.Count > 0) + { + _logger.Info("Template fetch scheduler enabled: every " + _config.TemplateFetchIntervalHours + + " hour(s), active devices=" + _sessions.Count + "."); + _logger.JobInfo("template_fetch", "Scheduler enabled intervalHours=" + _config.TemplateFetchIntervalHours + + " activeDevices=" + _sessions.Count); + _ = Task.Run(() => TemplateFetchSchedulerLoop(_cts.Token), _cts.Token); + } + + if (_config.EnableUserSync && + _config.SyncIntervalMinutes > 0 && + !string.IsNullOrWhiteSpace(_config.SourceDeviceId) && + _config.TargetDeviceIds != null && + _config.TargetDeviceIds.Count > 0) + { + _logger.Info("User sync scheduler enabled: every " + _config.SyncIntervalMinutes + " min, source=\"" + + _config.SourceDeviceId + "\", targetCount=" + _config.TargetDeviceIds.Count + ", isapiHttpPort=" + + _config.IsapiHttpPort + "."); + _logger.JobInfo("user_sync", "Scheduler enabled intervalMinutes=" + _config.SyncIntervalMinutes + + " source=" + _config.SourceDeviceId + " targetCount=" + _config.TargetDeviceIds.Count); + _ = Task.Run(() => UserSyncSchedulerLoop(_cts.Token), _cts.Token); + } + await Task.Delay(Timeout.Infinite, _cts.Token).ConfigureAwait(false); } catch (OperationCanceledException) @@ -165,7 +195,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable return Task.Run(() => { DateTime? lastEventTimestamp; - int n = FetchAttendanceRecordsCore(deviceId, fromLocal, toLocal, cancellationToken, out lastEventTimestamp); + bool dbInsertAllSucceeded; + int n = FetchAttendanceRecordsCore(deviceId, fromLocal, toLocal, cancellationToken, out lastEventTimestamp, out dbInsertAllSucceeded); // CLI/manual fetches should also advance the last-sync cursor, // otherwise incremental sync won't work until the scheduled loop runs. @@ -174,12 +205,19 @@ internal sealed class HikvisionAttendanceManager : IDisposable ", lastEventTimestamp=" + (lastEventTimestamp.HasValue ? lastEventTimestamp.Value.ToString("yyyy-MM-dd HH:mm:ss") : "(null)") + ", filePath=" + filePath); - if (n > 0 && lastEventTimestamp.HasValue) + if (n > 0 && lastEventTimestamp.HasValue && + (!_config.EnableDatabasePersistence || dbInsertAllSucceeded)) { WriteLastSyncTimestamp(deviceId, lastEventTimestamp.Value); _logger.Info("LastSync updated (CLI/manual fetch): device=" + deviceId + ", lastEventTimestamp=" + lastEventTimestamp.Value.ToString("yyyy-MM-dd HH:mm:ss")); } + else if (n > 0 && lastEventTimestamp.HasValue && _config.EnableDatabasePersistence && !dbInsertAllSucceeded) + { + _logger.Warn("LastSync NOT updated (CLI/manual fetch): DB insert did not fully succeed; will retry same window."); + _logger.JobWarn("attendance", "Cleanup skipped: DB insert not confirmed; delete not executed."); + } + _logger.JobInfo("attendance", "MACHINE " + deviceId + " has " + n + " records !"); return n; }, cancellationToken); } @@ -757,6 +795,10 @@ internal sealed class HikvisionAttendanceManager : IDisposable var faceLogPath = Path.Combine(dir, "face_templates_log.txt"); var fingerprintLogPath = Path.Combine(dir, "fingerprint_templates_log.txt"); + var templateJobLogsDir = Path.Combine(_config.LogDirectory, "logs", "template_fetching_logs"); + Directory.CreateDirectory(templateJobLogsDir); + var templateFaceStatusLogPath = Path.Combine(templateJobLogsDir, "face_templates_fetch_" + DateTime.Now.ToString("yyyy-MM-dd") + ".txt"); + var templateFingerStatusLogPath = Path.Combine(templateJobLogsDir, "finger_templates_fetch_" + DateTime.Now.ToString("yyyy-MM-dd") + ".txt"); var root = new AllUsersTemplateExportPayload { @@ -1072,7 +1114,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (!cbOk) { var err = Common.CHCNetSDK.NET_DVR_GetLastError(); - _logger.Error("NET_DVR_SetDVRMessageCallBack_V50 failed (Common), err=" + err + " (3=NET_DVR_NOINIT if wrong DLL instance)."); + LogSdkFailure("NET_DVR_SetDVRMessageCallBack_V50", err, null, null, + "Failed to register alarm callback delegate (Common SDK module).", isWarning: false); } else { @@ -1116,7 +1159,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (userId < 0) { var err = Common.CHCNetSDK.NET_DVR_GetLastError(); - _logger.Error("NET_DVR_Login_V30 failed for " + device.DeviceId + " (" + device.Ip + ":" + device.Port + "), err=" + err); + LogSdkFailure("NET_DVR_Login_V30", err, device.DeviceId, device.Ip, + "Device login failed on port " + device.Port + ". Check device IP/network/credentials.", isWarning: false); continue; } @@ -1153,7 +1197,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (alarmHandle < 0) { var err = Common.CHCNetSDK.NET_DVR_GetLastError(); - _logger.Error("NET_DVR_SetupAlarmChan_V50 failed for " + device.DeviceId + ", err=" + err + ". Session still recorded for login-only APIs (e.g. historical fetch)."); + LogSdkFailure("NET_DVR_SetupAlarmChan_V50", err, device.DeviceId, device.Ip, + "Alarm channel setup failed; session will still be kept for login-only APIs (historical fetch, template APIs).", isWarning: true); } else { @@ -1176,8 +1221,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable { if (!Common.CHCNetSDK.NET_DVR_CloseAlarmChan_V30(s.AlarmHandle)) { - _logger.Warn("NET_DVR_CloseAlarmChan_V30 failed for " + s.Device.DeviceId + ", err=" + - Common.CHCNetSDK.NET_DVR_GetLastError()); + LogSdkFailure("NET_DVR_CloseAlarmChan_V30", Common.CHCNetSDK.NET_DVR_GetLastError(), + s.Device.DeviceId, s.Device.Ip, "Alarm channel close failed during shutdown.", isWarning: true); } else { @@ -1208,17 +1253,24 @@ internal sealed class HikvisionAttendanceManager : IDisposable private async Task HistoricalSchedulerLoop(CancellationToken token) { + var intervalMinutes = _config.AttendanceSyncIntervalMinutes > 0 + ? _config.AttendanceSyncIntervalMinutes + : _config.HistoricalFetchIntervalMinutes; + if (intervalMinutes <= 0) + intervalMinutes = 5; + while (!token.IsCancellationRequested) { try { - await Task.Delay(TimeSpan.FromMinutes(_config.HistoricalFetchIntervalMinutes), token).ConfigureAwait(false); + await Task.Delay(TimeSpan.FromMinutes(intervalMinutes), token).ConfigureAwait(false); } catch (OperationCanceledException) { break; } + LogJobCycleStart("attendance", "ATTENDANCE", "--Attendance job started at "); var to = DateTime.Now; // Fallback window used only for the first sync (when last-sync file is missing) or if last-sync is unreadable. var fallbackFrom = to.AddMinutes(-_config.HistoricalFetchLookbackMinutes); @@ -1246,25 +1298,181 @@ internal sealed class HikvisionAttendanceManager : IDisposable } DateTime? lastEventTimestamp; - int n = FetchAttendanceRecordsCore(s.Device.DeviceId, from, to, token, out lastEventTimestamp); + bool dbInsertAllSucceeded; + int n = FetchAttendanceRecordsCore(s.Device.DeviceId, from, to, token, out lastEventTimestamp, out dbInsertAllSucceeded); _logger.Info("Scheduled historical ACS fetch completed: device=" + s.Device.DeviceId + ", records=" + n + ", window=" + from.ToString("yyyy-MM-dd HH:mm:ss") + " .. " + to.ToString("yyyy-MM-dd HH:mm:ss") + ", lastSync=" + (lastSync.HasValue ? lastSync.Value.ToString("yyyy-MM-dd HH:mm:ss") : "(none)") + (string.IsNullOrEmpty(lastSyncReadReason) ? "" : ", lastSyncReason=" + lastSyncReadReason) + ", lastEventTimestamp=" + (lastEventTimestamp.HasValue ? lastEventTimestamp.Value.ToString("yyyy-MM-dd HH:mm:ss") : "(null)")); + _logger.JobInfo("attendance", "Scheduled fetch device=" + s.Device.DeviceId + " records=" + n + + " window=" + from.ToString("yyyy-MM-dd HH:mm:ss") + ".." + to.ToString("yyyy-MM-dd HH:mm:ss")); + _logger.JobInfo("attendance", "MACHINE " + s.Device.DeviceId + " has " + n + " records !"); // Update last sync only when we actually parsed at least one event and we have a usable event timestamp. - if (n > 0 && lastEventTimestamp.HasValue) + if (n > 0 && lastEventTimestamp.HasValue && + (!_config.EnableDatabasePersistence || dbInsertAllSucceeded)) + { WriteLastSyncTimestamp(s.Device.DeviceId, lastEventTimestamp.Value); + if (_config.EnableDatabasePersistence && dbInsertAllSucceeded) + { + if (TryCleanupDeviceAttendanceStorage(s, lastEventTimestamp.Value, out var cleanupErr)) + { + _logger.JobInfo("attendance", "Device cleanup OK: machine=" + s.Device.DeviceId + + " ip=" + (s.Device.Ip ?? "") + + " checkTime=" + lastEventTimestamp.Value.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture)); + } + else + { + _logger.JobWarn("attendance", "Device cleanup FAILED: machine=" + s.Device.DeviceId + + " ip=" + (s.Device.Ip ?? "") + + " checkTime=" + lastEventTimestamp.Value.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + + " err=" + cleanupErr); + } + } + } + else if (n > 0 && lastEventTimestamp.HasValue && _config.EnableDatabasePersistence && !dbInsertAllSucceeded) + { + _logger.JobWarn("attendance", "LastSync NOT updated for machine=" + s.Device.DeviceId + + " because DB insert failed; same data window will be retried."); + _logger.JobWarn("attendance", "Cleanup skipped: DB insert not confirmed; delete not executed. machine=" + s.Device.DeviceId); + } } catch (Exception ex) { _logger.Error("Scheduled historical fetch failed for " + s.Device.DeviceId, ex); + _logger.JobError("attendance", "Scheduled fetch FAILED device=" + s.Device.DeviceId + " err=" + ex.Message); } } + LogJobCycleEnd("attendance", "--Attendance job finished at "); } } + private async Task TemplateFetchSchedulerLoop(CancellationToken token) + { + bool firstRun = true; + while (!token.IsCancellationRequested) + { + if (!firstRun) + { + try + { + await Task.Delay(TimeSpan.FromHours(_config.TemplateFetchIntervalHours), token).ConfigureAwait(false); + } + catch (OperationCanceledException) + { + break; + } + } + firstRun = false; + + LogJobCycleStart("template_fetch", "TEMPLATE", "--Template job started at "); + foreach (var s in _sessions.ToArray()) + { + if (token.IsCancellationRequested) + break; + + try + { + var outDir = Path.Combine(_config.LogDirectory, "template_fetch", DateTime.Now.ToString("yyyy-MM-dd"), s.Device.DeviceId); + _logger.JobInfo("template_fetch", "Start device=" + s.Device.DeviceId + " outDir=\"" + outDir + "\""); + + string jsonPath; + string err; + bool ok = TryExportAllUsersTemplatesToIsapiFile( + s.Device.DeviceId, + outDir, + 30, + 5000, + token, + out jsonPath, + out err); + + if (ok) + _logger.JobInfo("template_fetch", "DONE device=" + s.Device.DeviceId + " jsonPath=\"" + jsonPath + "\""); + else + _logger.JobError("template_fetch", "FAILED device=" + s.Device.DeviceId + " err=" + err); + } + catch (Exception ex) + { + _logger.JobError("template_fetch", "EXCEPTION device=" + s.Device.DeviceId + " err=" + ex.Message); + } + } + LogJobCycleEnd("template_fetch", "--Template job finished at "); + } + } + + private void LogJobCycleStart(string jobKey, string jobTitle, string startedLinePrefix) + { + var now = DateTime.Now; + _logger.JobInfo(jobKey, "========================================================"); + _logger.JobInfo(jobKey, "SERVICE STARTED"); + _logger.JobInfo(jobKey, "Time: " + now.ToString("M/d/yyyy h:mm:ss tt", CultureInfo.InvariantCulture)); + _logger.JobInfo(jobKey, "JOB: " + jobTitle); + _logger.JobInfo(jobKey, "========================="); + _logger.JobInfo(jobKey, startedLinePrefix + now.ToString("M/d/yyyy h:mm:ss tt", CultureInfo.InvariantCulture)); + } + + private void LogJobCycleEnd(string jobKey, string finishedLinePrefix) + { + var now = DateTime.Now; + _logger.JobInfo(jobKey, finishedLinePrefix + now.ToString("M/d/yyyy h:mm:ss tt", CultureInfo.InvariantCulture)); + _logger.JobInfo(jobKey, "SERVICE ENDED"); + _logger.JobInfo(jobKey, "Time: " + now.ToString("M/d/yyyy h:mm:ss tt", CultureInfo.InvariantCulture)); + _logger.JobInfo(jobKey, "========================================================"); + } + + private bool PersistHistoricalAttendanceEvent(AttendanceEvent ev, out bool dbInserted) + { + dbInserted = false; + if (ev == null) + return false; + + if (!_dedupeKeys.TryAdd(ev.DedupeKey, 1)) + return false; + + if (_dedupeKeys.Count > DedupeMaxEntries) + { + _dedupeKeys.Clear(); + _dedupeKeys.TryAdd(ev.DedupeKey, 1); + } + + lock (_csvWriteLock) + { + File.AppendAllText(_csvPath, ToCsvLine(ev) + Environment.NewLine, Encoding.UTF8); + } + + AppendAttendanceToTextFileSafely(ev); + dbInserted = WriteAttendanceToDatabase(ev); + return true; + } + + private bool TryCleanupDeviceAttendanceStorage(DeviceSession session, DateTime checkTimeLocal, out string error) + { + error = ""; + var body = "{ \"EventStorageCfg\": { " + + "\"mode\": \"time\", " + + "\"checkTime\": \"" + checkTimeLocal.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + "\"" + + " } }"; + var raw = StdXmlCall(session.UserId, "PUT", "/ISAPI/AccessControl/AcsEvent/StorageCfg?format=json", body, out var sdkErr); + var status = ExtractIsapiStatusSummary(raw); + if (!string.IsNullOrWhiteSpace(sdkErr)) + { + error = sdkErr + " ; " + status; + return false; + } + + if (status.IndexOf("statusCode=1", StringComparison.OrdinalIgnoreCase) >= 0 || + status.IndexOf("statusString=OK", StringComparison.OrdinalIgnoreCase) >= 0) + return true; + + if (string.IsNullOrWhiteSpace(raw)) + return true; + + error = "cleanup status not confirmed: " + status; + return false; + } + private string GetLastSyncFilePath(string deviceId) { var key = DeviceIdentity.CanonicalLookupKey(deviceId); @@ -1328,9 +1536,11 @@ internal sealed class HikvisionAttendanceManager : IDisposable DateTime fromLocal, DateTime toLocal, CancellationToken cancellationToken, - out DateTime? lastEventTimestamp) + out DateTime? lastEventTimestamp, + out bool dbInsertAllSucceeded) { lastEventTimestamp = null; + dbInsertAllSucceeded = true; var canonicalKey = DeviceIdentity.CanonicalLookupKey(deviceId); _logger.Info("FetchAttendanceRecordsCore: enter historical fetch; requestedDeviceId=" + deviceId + " canonicalKey=" + (canonicalKey.Length == 0 ? "(empty)" : canonicalKey)); @@ -1355,6 +1565,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable _logger.Info("Historical ACS fetch START device=" + deviceId + " userId=" + session.UserId + " (session from login only; alarm channel not required) from=" + fromLocal.ToString("yyyy-MM-dd HH:mm:ss") + " to=" + toLocal.ToString("yyyy-MM-dd HH:mm:ss")); + _logger.JobInfo("attendance", "Fetch START device=" + deviceId + " from=" + + fromLocal.ToString("yyyy-MM-dd HH:mm:ss") + " to=" + toLocal.ToString("yyyy-MM-dd HH:mm:ss")); // Prioritize the officially documented STDXMLConfig + ISAPI AccessControl path for DS-K1T642MFW. // If anything fails (SDK call error, parse error, unexpected response), we fall back to NET_DVR_GET_ACS_EVENT. @@ -1368,7 +1580,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable toLocal, cancellationToken, out attemptedStdXml, - out stdLastEventTs); + out stdLastEventTs, + out dbInsertAllSucceeded); if (attemptedStdXml) { lastEventTimestamp = stdLastEventTs; @@ -1410,7 +1623,8 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (handle < 0) { - _logger.Error("NET_DVR_StartRemoteConfig(NET_DVR_GET_ACS_EVENT, Common) failed, err=" + Common.CHCNetSDK.NET_DVR_GetLastError()); + LogSdkFailure("NET_DVR_StartRemoteConfig(NET_DVR_GET_ACS_EVENT)", Common.CHCNetSDK.NET_DVR_GetLastError(), + session.Device.DeviceId, session.Device.Ip, "Historical fetch remote-config session creation failed.", isWarning: false); return 0; } @@ -1430,8 +1644,12 @@ internal sealed class HikvisionAttendanceManager : IDisposable total++; if (TryBuildAttendanceFromAcsCfg(session, ref cfg, out var ev)) { - EnqueueAttendance(ev, "Historical fetch parsed"); - parsedOk++; + if (PersistHistoricalAttendanceEvent(ev, out var dbInserted)) + { + parsedOk++; + if (_config.EnableDatabasePersistence && !dbInserted) + dbInsertAllSucceeded = false; + } if (ev != null) { @@ -1462,13 +1680,16 @@ internal sealed class HikvisionAttendanceManager : IDisposable if (status == (int)Common.CHCNetSDK.NET_SDK_GET_NEXT_STATUS.NET_SDK_GET_NEXT_STATUS_FAILED) { - _logger.Error("NET_DVR_GetNextRemoteConfig failed status, err=" + Common.CHCNetSDK.NET_DVR_GetLastError()); + LogSdkFailure("NET_DVR_GetNextRemoteConfig", Common.CHCNetSDK.NET_DVR_GetLastError(), + session.Device.DeviceId, session.Device.Ip, "Historical fetch remote-config read failed.", isWarning: false); Common.CHCNetSDK.NET_DVR_StopRemoteConfig(handle); handle = -1; break; } - _logger.Warn("NET_DVR_GetNextRemoteConfig unknown status=" + status + ", err=" + Common.CHCNetSDK.NET_DVR_GetLastError()); + LogSdkFailure("NET_DVR_GetNextRemoteConfig", Common.CHCNetSDK.NET_DVR_GetLastError(), + session.Device.DeviceId, session.Device.Ip, + "Historical fetch returned unexpected SDK status=" + status + ".", isWarning: true); Common.CHCNetSDK.NET_DVR_StopRemoteConfig(handle); handle = -1; break; @@ -1493,6 +1714,7 @@ internal sealed class HikvisionAttendanceManager : IDisposable } _logger.Info("Historical ACS fetch DONE device=" + deviceId + " rawRows=" + total + ", parsedOk=" + parsedOk + ", parseSkipped=" + parseFail); + _logger.JobInfo("attendance", "Fetch DONE device=" + deviceId + " rawRows=" + total + " parsedOk=" + parsedOk + " parseSkipped=" + parseFail); lastEventTimestamp = maxEventTs; return parsedOk; } @@ -1528,10 +1750,12 @@ internal sealed class HikvisionAttendanceManager : IDisposable DateTime toLocal, CancellationToken cancellationToken, out bool attemptedStdXml, - out DateTime? lastEventTimestamp) + out DateTime? lastEventTimestamp, + out bool dbInsertAllSucceeded) { attemptedStdXml = false; lastEventTimestamp = null; + dbInsertAllSucceeded = true; try { @@ -1553,26 +1777,26 @@ internal sealed class HikvisionAttendanceManager : IDisposable var searchId = "1"; int searchResultPosition = 0; - int maxResults = 30; + int maxResults = 30; // dynamic (see loop) string r1 = StdXmlCall(session.UserId, "GET", "/ISAPI/AccessControl/capabilities?format=json", null, out var e1); _logger.Info("STDXMLConfig step1 rawResponse: " + TruncateForLog(r1, 120_000)); if (!string.IsNullOrEmpty(e1)) - _logger.Warn("STDXMLConfig step1 SDK error: " + e1); + LogSdkFailureFromText("NET_DVR_STDXMLConfig step1 GET /ISAPI/AccessControl/capabilities", e1, session.Device.DeviceId, session.Device.Ip, isWarning: true); cancellationToken.ThrowIfCancellationRequested(); string r2 = StdXmlCall(session.UserId, "GET", "/ISAPI/AccessControl/AcsEvent/capabilities?format=json", null, out var e2); _logger.Info("STDXMLConfig step2 rawResponse: " + TruncateForLog(r2, 120_000)); if (!string.IsNullOrEmpty(e2)) - _logger.Warn("STDXMLConfig step2 SDK error: " + e2); + LogSdkFailureFromText("NET_DVR_STDXMLConfig step2 GET /ISAPI/AccessControl/AcsEvent/capabilities", e2, session.Device.DeviceId, session.Device.Ip, isWarning: true); cancellationToken.ThrowIfCancellationRequested(); string r3 = StdXmlCall(session.UserId, "GET", "/ISAPI/AccessControl/AcsEventTotalNum/capabilities?format=json", null, out var e3); _logger.Info("STDXMLConfig step3 rawResponse: " + TruncateForLog(r3, 120_000)); if (!string.IsNullOrEmpty(e3)) - _logger.Warn("STDXMLConfig step3 SDK error: " + e3); + LogSdkFailureFromText("NET_DVR_STDXMLConfig step3 GET /ISAPI/AccessControl/AcsEventTotalNum/capabilities", e3, session.Device.DeviceId, session.Device.Ip, isWarning: true); // Step 5: build JSON_AcsEventTotalNumCond and POST. string jsonTotalNumCond = BuildJsonAcsEventTotalNumCond(searchId, major, minor, startTime, endTime); @@ -1583,61 +1807,102 @@ internal sealed class HikvisionAttendanceManager : IDisposable string rTotalNum = StdXmlCall(session.UserId, "POST", totalNumUri, jsonTotalNumCond, out var eTotalNum); _logger.Info("STDXMLConfig step5 rawResponse: " + TruncateForLog(rTotalNum, 120_000)); if (!string.IsNullOrEmpty(eTotalNum)) - _logger.Warn("STDXMLConfig step5 SDK error: " + eTotalNum); + LogSdkFailureFromText("NET_DVR_STDXMLConfig step5 POST /ISAPI/AccessControl/AcsEventTotalNum", eTotalNum, session.Device.DeviceId, session.Device.Ip, isWarning: true); _logger.Info("STDXMLConfig step5 parsedResponseStatus: " + ParseStdXmlResponseStatus(rTotalNum)); cancellationToken.ThrowIfCancellationRequested(); - // Step 6: build JSON_AcsEventCond and POST. - string jsonAcsEventCond = BuildJsonAcsEventCond(searchId, searchResultPosition, maxResults, major, minor, startTime, endTime); + // Step 6: build JSON_AcsEventCond and POST (paged), stopping when responseStatusStrg == END. + // Dynamic batch size: start with 30; after we fetch enough rows, increase batch to reduce round-trips. string acsEventUri = "/ISAPI/AccessControl/AcsEvent?format=json"; - string acsEventRequestUrl = "POST " + acsEventUri; - _logger.Info("STDXMLConfig step6 requestUrl=" + acsEventRequestUrl + " requestBody=" + TruncateForLog(jsonAcsEventCond, 120_000)); - - string rAcsEvent = StdXmlCall(session.UserId, "POST", acsEventUri, jsonAcsEventCond, out var eAcsEvent); - _logger.Info("STDXMLConfig step6 rawResponse: " + TruncateForLog(rAcsEvent, 120_000)); - if (!string.IsNullOrEmpty(eAcsEvent)) - _logger.Warn("STDXMLConfig step6 SDK error: " + eAcsEvent); - _logger.Info("STDXMLConfig step6 parsedResponseStatus: " + ParseStdXmlResponseStatus(rAcsEvent)); - - cancellationToken.ThrowIfCancellationRequested(); - - // Step 10 (goal): map returned fields into our attendance pipeline. - var acsEventInfoList = ExtractAcsEventInfoList(rAcsEvent); - _logger.Info("STDXMLConfig extracted events: " + acsEventInfoList.Count); - - string eventName = MapAcsEventName(major, minor); - if (string.IsNullOrWhiteSpace(eventName)) - eventName = "MAJOR_" + major + "_MINOR_" + minor; - string eventType = AcsAttendanceParser.MapMajorCategory(major) + "/" + minor.ToString("X"); - - // Keep success inference consistent with existing pipeline rules. - bool isSuccessByMinorRule = AcsAttendanceParser.ResolveIsSuccess(major, minor, eventName); - int total = 0; int parsedOk = 0; int parseFail = 0; DateTime? maxEventTs = null; - foreach (var info in acsEventInfoList) + int? totalMatches = TryExtractTotalMatchesFromAcsTotalNum(rTotalNum); + if (totalMatches.HasValue) + _logger.Info("STDXMLConfig step5 totalMatches=" + totalMatches.Value); + + while (!cancellationToken.IsCancellationRequested) { - total++; - if (!TryBuildAttendanceFromStdAcsInfo(session.Device, info, major, minor, eventName, eventType, isSuccessByMinorRule, out var ev)) + maxResults = DetermineDynamicAcsBatchSize(parsedOk, maxResults); + string jsonAcsEventCond = BuildJsonAcsEventCond(searchId, searchResultPosition, maxResults, major, minor, startTime, endTime); + string acsEventRequestUrl = "POST " + acsEventUri; + _logger.Info("STDXMLConfig step6 requestUrl=" + acsEventRequestUrl + + " searchResultPosition=" + searchResultPosition + + " maxResults=" + maxResults + + " requestBody=" + TruncateForLog(jsonAcsEventCond, 120_000)); + + string rAcsEvent = StdXmlCall(session.UserId, "POST", acsEventUri, jsonAcsEventCond, out var eAcsEvent); + _logger.Info("STDXMLConfig step6 rawResponse: " + TruncateForLog(rAcsEvent, 120_000)); + if (!string.IsNullOrEmpty(eAcsEvent)) + LogSdkFailureFromText("NET_DVR_STDXMLConfig step6 POST /ISAPI/AccessControl/AcsEvent", eAcsEvent, session.Device.DeviceId, session.Device.Ip, isWarning: true); + + string statusStr = ParseStdXmlResponseStatus(rAcsEvent); + _logger.Info("STDXMLConfig step6 parsedResponseStatus: " + statusStr); + cancellationToken.ThrowIfCancellationRequested(); + + var acsEventInfoList = ExtractAcsEventInfoList(rAcsEvent); + _logger.Info("STDXMLConfig extracted events: " + acsEventInfoList.Count); + + // Step 10 (goal): map returned fields into our attendance pipeline. + string eventName = MapAcsEventName(major, minor); + if (string.IsNullOrWhiteSpace(eventName)) + eventName = "MAJOR_" + major + "_MINOR_" + minor; + string eventType = AcsAttendanceParser.MapMajorCategory(major) + "/" + minor.ToString("X"); + bool isSuccessByMinorRule = AcsAttendanceParser.ResolveIsSuccess(major, minor, eventName); + + int pageParsedOk = 0; + foreach (var info in acsEventInfoList) { - parseFail++; - continue; + total++; + if (!TryBuildAttendanceFromStdAcsInfo(session.Device, info, major, minor, eventName, eventType, + isSuccessByMinorRule, out var ev)) + { + parseFail++; + continue; + } + + if (PersistHistoricalAttendanceEvent(ev, out var dbInserted)) + { + parsedOk++; + pageParsedOk++; + if (_config.EnableDatabasePersistence && !dbInserted) + dbInsertAllSucceeded = false; + } + + if (!maxEventTs.HasValue || ev.Timestamp > maxEventTs.Value) + maxEventTs = ev.Timestamp; } - EnqueueAttendance(ev, "Historical STDXMLConfig parsed"); - parsedOk++; + // Pagination: advance by what the device returned (avoids duplication even if it returns fewer than maxResults). + if (acsEventInfoList.Count > 0) + searchResultPosition += acsEventInfoList.Count; + else + { + // Defensive: if device claims MORE but returns 0, stop to avoid infinite loop. + _logger.Warn("STDXMLConfig paging: got 0 events; stopping to avoid loop. status=" + statusStr + + " pos=" + searchResultPosition + " max=" + maxResults); + break; + } - if (!maxEventTs.HasValue || ev.Timestamp > maxEventTs.Value) - maxEventTs = ev.Timestamp; + // Stop conditions + if (statusStr.IndexOf("END", StringComparison.OrdinalIgnoreCase) >= 0) + break; + if (statusStr.IndexOf("MORE", StringComparison.OrdinalIgnoreCase) >= 0) + continue; + + // Unknown status: stop; caller will treat this attempt as successful if we parsed anything. + _logger.Warn("STDXMLConfig paging: unexpected responseStatusStrg=\"" + statusStr + "\"; stopping."); + break; } _logger.Info("STDXMLConfig fetch DONE device=" + session.Device.DeviceId + " rawRows=" + total + ", parsedOk=" + parsedOk + ", parseSkipped=" + parseFail); - attemptedStdXml = parsedOk > 0; + // Treat the STDXML attempt as authoritative if we reached here without throwing, + // even if the date range has no events (avoid redundant SDK remote-config fetch). + attemptedStdXml = true; if (maxEventTs.HasValue) // STDXML timestamps are parsed as UTC (we parse the device time with offset, then convert to universal). // Convert back to local time so incremental cursor stays consistent with scheduler's local `from`/`to`. @@ -1655,10 +1920,43 @@ internal sealed class HikvisionAttendanceManager : IDisposable _logger.Error("STDXMLConfig diagnostic fetch failed; falling back to NET_DVR_GET_ACS_EVENT", ex); attemptedStdXml = false; lastEventTimestamp = null; + dbInsertAllSucceeded = false; return 0; } } + private static int DetermineDynamicAcsBatchSize(int totalParsedOkSoFar, int currentMaxResults) + { + // Conservative dynamic batching: keep requests small until we know the window is large. + // The AcsEvent ISAPI may return large payloads; this avoids overwhelming the device. + if (totalParsedOkSoFar < 1000) + return 30; + if (totalParsedOkSoFar < 5000) + return 50; + return 100; + } + + private static int? TryExtractTotalMatchesFromAcsTotalNum(string responseJson) + { + if (string.IsNullOrWhiteSpace(responseJson)) + return null; + try + { + var ser = new JavaScriptSerializer(); + object? obj = ser.DeserializeObject(responseJson); + if (obj == null) + return null; + if (TryFindInt(obj, new[] { "totalMatches", "totalMatch", "totalNum", "total", "matchNum" }, out var i)) + return i; + } + catch + { + // ignore + } + + return null; + } + private static string BuildJsonAcsEventTotalNumCond(string searchId, uint major, uint minor, string startTimeUtc, string endTimeUtc) { return "{ \"AcsEventTotalNumCond\": { " + @@ -3421,6 +3719,14 @@ internal sealed class HikvisionAttendanceManager : IDisposable var faceLogPath = Path.Combine(dir, "face_templates_log.txt"); var fingerprintLogPath = Path.Combine(dir, "fingerprint_templates_log.txt"); + var templateInternalRoot = Path.Combine(_config.LogDirectory, "internal_logs", "template_internal_logs"); + var templateFaceInternalDir = Path.Combine(templateInternalRoot, "face"); + var templateFingerInternalDir = Path.Combine(templateInternalRoot, "finger"); + Directory.CreateDirectory(templateFaceInternalDir); + Directory.CreateDirectory(templateFingerInternalDir); + var localDate = DateTime.Now.ToString("yyyy-MM-dd", CultureInfo.InvariantCulture); + var templateFaceStatusLogPath = Path.Combine(templateFaceInternalDir, "face_templates_fetch_" + localDate + ".txt"); + var templateFingerStatusLogPath = Path.Combine(templateFingerInternalDir, "finger_templates_fetch_" + localDate + ".txt"); var perUserDir = Path.Combine(dir, "per_user"); Directory.CreateDirectory(perUserDir); @@ -3437,13 +3743,36 @@ internal sealed class HikvisionAttendanceManager : IDisposable using var faceSw = new StreamWriter(faceLogPath, append: false, encoding: new UTF8Encoding(encoderShouldEmitUTF8Identifier: false)); using var fpSw = new StreamWriter(fingerprintLogPath, append: false, encoding: new UTF8Encoding(encoderShouldEmitUTF8Identifier: false)); + using var templateFaceStatusSw = new StreamWriter(templateFaceStatusLogPath, append: true, encoding: new UTF8Encoding(encoderShouldEmitUTF8Identifier: false)); + using var templateFingerStatusSw = new StreamWriter(templateFingerStatusLogPath, append: true, encoding: new UTF8Encoding(encoderShouldEmitUTF8Identifier: false)); faceSw.WriteLine(DateTime.UtcNow.ToString("o") + " ISAPI export face templates"); fpSw.WriteLine(DateTime.UtcNow.ToString("o") + " ISAPI export fingerprint templates"); + if (new FileInfo(templateFaceStatusLogPath).Length == 0) + { + templateFaceStatusSw.WriteLine("========================================"); + templateFaceStatusSw.WriteLine("FACE TEMPLATE FETCH DETAILS"); + templateFaceStatusSw.WriteLine("Device IP: " + (session.Device.Ip ?? "")); + templateFaceStatusSw.WriteLine("Date: " + localDate); + templateFaceStatusSw.WriteLine("========================================"); + } + if (new FileInfo(templateFingerStatusLogPath).Length == 0) + { + templateFingerStatusSw.WriteLine("========================================"); + templateFingerStatusSw.WriteLine("FINGERPRINT TEMPLATE FETCH DETAILS"); + templateFingerStatusSw.WriteLine("Device IP: " + (session.Device.Ip ?? "")); + templateFingerStatusSw.WriteLine("Date: " + localDate); + templateFingerStatusSw.WriteLine("========================================"); + } _logger.Info("ExportAllTemplates ISAPI: device=" + deviceId + ", discoveredUsers=" + cardNos.Count + ", pageSize=" + pageSize + ", maxUsers=" + maxUsers + ", userListError=" + (string.IsNullOrEmpty(listErr) ? "(none)" : listErr)); + var faceFetched = new List(); + var faceNotFetched = new List(); + var fingerFetched = new List(); + var fingerNotFetched = new List(); + foreach (var cardNo in cardNos) { if (cancellationToken.IsCancellationRequested) @@ -3566,6 +3895,13 @@ internal sealed class HikvisionAttendanceManager : IDisposable faceSw.WriteLine(DateTime.UtcNow.ToString("o") + " device=" + deviceId + " cardNo=" + cardNo + " faceError=" + err); } + templateFaceStatusSw.WriteLine(DateTime.UtcNow.ToString("o") + + " machine_name=" + deviceId + + " machine_ip=" + (session.Device.Ip ?? "") + + " emp_no=" + cardNo.Trim() + + " template=" + (userPayload.face.present ? "fetched" : "not_fetched")); + if (userPayload.face.present) faceFetched.Add(cardNo.Trim()); else faceNotFetched.Add(cardNo.Trim()); + // Fingerprint flow: capability-first, then FingerPrintDownload family. ProbeCapabilityAndLog(session.UserId, "/ISAPI/AccessControl/FingerPrintCfg/capabilities?format=json", "fingerprint.FingerPrintCfg", fpSw); var fpItemsDoc = new List(); @@ -3609,6 +3945,14 @@ internal sealed class HikvisionAttendanceManager : IDisposable " error=" + (string.IsNullOrEmpty(fp.error) ? "-" : fp.error)); } + bool anyFingerprintFetched = userPayload.fingerprints.Any(x => x.present); + templateFingerStatusSw.WriteLine(DateTime.UtcNow.ToString("o") + + " machine_name=" + deviceId + + " machine_ip=" + (session.Device.Ip ?? "") + + " emp_no=" + cardNo.Trim() + + " template=" + (anyFingerprintFetched ? "fetched" : "not_fetched")); + if (anyFingerprintFetched) fingerFetched.Add(cardNo.Trim()); else fingerNotFetched.Add(cardNo.Trim()); + root.users.Add(userPayload); // Per-user JSON file as requested. @@ -3620,6 +3964,45 @@ internal sealed class HikvisionAttendanceManager : IDisposable var json = new JavaScriptSerializer { MaxJsonLength = int.MaxValue }.Serialize(root); File.WriteAllText(writtenJsonPath, json, new UTF8Encoding(encoderShouldEmitUTF8Identifier: false)); _logger.Info("ExportAllTemplates ISAPI: wrote combined json path=" + writtenJsonPath + ", users=" + root.users.Count); + + if (faceFetched.Count == 0) + templateFaceStatusSw.WriteLine("No face templates to fetch for this device."); + if (fingerFetched.Count == 0) + templateFingerStatusSw.WriteLine("No fingerprint templates to fetch for this device."); + + _logger.JobInfo("template_fetch", "========================================"); + _logger.JobInfo("template_fetch", "TEMPLATE FETCH SUMMARY"); + _logger.JobInfo("template_fetch", "========================================"); + _logger.JobInfo("template_fetch", "Device IP: " + (session.Device.Ip ?? "")); + _logger.JobInfo("template_fetch", "Device ID: " + deviceId); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "=== FACE TEMPLATES ==="); + _logger.JobInfo("template_fetch", "Total users processed: " + root.users.Count); + _logger.JobInfo("template_fetch", "Users with face template fetched: " + faceFetched.Count); + _logger.JobInfo("template_fetch", "Users with NO face template: " + faceNotFetched.Count); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "User list with face templates:"); + if (faceFetched.Count == 0) _logger.JobInfo("template_fetch", " - (none)"); + foreach (var emp in faceFetched) _logger.JobInfo("template_fetch", " - " + emp + " (fetched)"); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "User list with NO face templates:"); + if (faceNotFetched.Count == 0) _logger.JobInfo("template_fetch", " - (none)"); + foreach (var emp in faceNotFetched) _logger.JobInfo("template_fetch", " - " + emp); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "=== FINGERPRINT TEMPLATES ==="); + _logger.JobInfo("template_fetch", "Total users processed: " + root.users.Count); + _logger.JobInfo("template_fetch", "Users with fingerprint template fetched: " + fingerFetched.Count); + _logger.JobInfo("template_fetch", "Users with NO fingerprint template: " + fingerNotFetched.Count); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "User list with fingerprint templates:"); + if (fingerFetched.Count == 0) _logger.JobInfo("template_fetch", " - (none)"); + foreach (var emp in fingerFetched) _logger.JobInfo("template_fetch", " - " + emp + " (fetched)"); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "User list with NO fingerprint templates:"); + if (fingerNotFetched.Count == 0) _logger.JobInfo("template_fetch", " - (none)"); + foreach (var emp in fingerNotFetched) _logger.JobInfo("template_fetch", " - " + emp); + _logger.JobInfo("template_fetch", ""); + _logger.JobInfo("template_fetch", "========================================"); return true; } catch (OperationCanceledException) @@ -4546,13 +4929,13 @@ internal sealed class HikvisionAttendanceManager : IDisposable return value; } - private void WriteAttendanceToDatabase(AttendanceEvent ev) + private bool WriteAttendanceToDatabase(AttendanceEvent ev) { if (!_config.EnableDatabasePersistence) - return; + return true; if (string.IsNullOrWhiteSpace(_config.SqlConnectionString)) - return; + return false; try { @@ -4579,13 +4962,21 @@ internal sealed class HikvisionAttendanceManager : IDisposable cmd.Parameters.AddWithValue("@RawMajor", ev.RawMajor); cmd.Parameters.AddWithValue("@RawMinor", ev.RawMinor); cmd.Parameters.AddWithValue("@EventSource", (object)ev.Source ?? DBNull.Value); - cmd.ExecuteNonQuery(); + int rows = cmd.ExecuteNonQuery(); + _logger.Info( + "[AttendanceInsert] machine_id=" + (ev.DeviceId ?? "") + + " ip=" + (ev.DeviceIp ?? "") + + " emp_no=" + (ev.EmployeeNo.HasValue ? ev.EmployeeNo.Value.ToString(CultureInfo.InvariantCulture) : "") + + " checktime=" + ev.Timestamp.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture) + + " rows=" + rows); } } + return true; } catch (Exception ex) { _logger.Error("WriteAttendanceToDatabase failed (extend table: UserIdentifier NVARCHAR, ReaderNo INT, EventSource NVARCHAR)", ex); + return false; } } @@ -4621,7 +5012,7 @@ internal sealed class HikvisionAttendanceManager : IDisposable try { uint err = Common.CHCNetSDK.NET_DVR_GetLastError(); - return operation + " errorCode=" + err; + return operation + " errorCode=" + err + " (" + TranslateSdkErrorCode(err) + ")"; } catch { @@ -4629,6 +5020,89 @@ internal sealed class HikvisionAttendanceManager : IDisposable } } + private void LogSdkFailure(string operation, uint errorCode, string? deviceId, string? ip, string? detail, bool isWarning) + { + var lines = new[] + { + "SDK operation failed", + "Operation: " + operation, + "DeviceId: " + (string.IsNullOrWhiteSpace(deviceId) ? "-" : deviceId), + "IP: " + (string.IsNullOrWhiteSpace(ip) ? "-" : ip), + "Reason: " + TranslateSdkErrorCode(errorCode), + "Original: " + operation + " errorCode=" + errorCode, + "Detail: " + (string.IsNullOrWhiteSpace(detail) ? "-" : detail) + }; + var msg = string.Join(Environment.NewLine, lines); + if (isWarning) + _logger.Warn(msg); + else + _logger.Error(msg); + } + + private void LogSdkFailureFromText(string operation, string sdkErrorText, string? deviceId, string? ip, bool isWarning) + { + if (TryExtractSdkErrorCodeFromText(sdkErrorText, out var code)) + { + LogSdkFailure(operation, code, deviceId, ip, sdkErrorText, isWarning); + return; + } + + var lines = new[] + { + "SDK operation failed", + "Operation: " + operation, + "DeviceId: " + (string.IsNullOrWhiteSpace(deviceId) ? "-" : deviceId), + "IP: " + (string.IsNullOrWhiteSpace(ip) ? "-" : ip), + "Reason: Unable to parse SDK error code", + "Original: " + sdkErrorText, + "Detail: " + sdkErrorText + }; + var msg = string.Join(Environment.NewLine, lines); + if (isWarning) + _logger.Warn(msg); + else + _logger.Error(msg); + } + + private static bool TryExtractSdkErrorCodeFromText(string text, out uint code) + { + code = 0; + if (string.IsNullOrWhiteSpace(text)) + return false; + var m = System.Text.RegularExpressions.Regex.Match(text, @"\berr(orCode)?\s*=?\s*(\d+)\b", System.Text.RegularExpressions.RegexOptions.IgnoreCase); + if (!m.Success) + return false; + return uint.TryParse(m.Groups[2].Value, NumberStyles.Integer, CultureInfo.InvariantCulture, out code); + } + + private static string TranslateSdkErrorCode(uint code) + { + switch (code) + { + case 0: return "No error"; + case 1: return "Password error"; + case 2: return "No sufficient privilege"; + case 3: return "SDK not initialized (NET_DVR_NOINIT)"; + case 4: return "Channel error"; + case 5: return "No such user"; + case 6: return "Version mismatch"; + case 7: return "Connection failed (network/device unreachable)"; + case 8: return "Function not supported"; + case 9: return "Illegal parameter"; + case 10: return "Channel occupied"; + case 11: return "SDK XML config error"; + case 17: return "Parameter error"; + case 23: return "No enough memory"; + case 29: return "No permission"; + case 41: return "Operation timeout"; + case 72: return "Data send failed"; + case 73: return "Data receive failed"; + case 84: return "Create socket failed"; + case 109: return "Network timeout / no response from device"; + default: return "Unknown SDK error"; + } + } + private sealed class DeviceSession { public DeviceSession(HikvisionAttendanceWindowsService.DeviceConfig device, int userId, int alarmHandle) diff --git a/Tests/UserSyncIntegrationPlaceholderTests.cs b/Tests/UserSyncIntegrationPlaceholderTests.cs new file mode 100644 index 0000000..a9a62b7 --- /dev/null +++ b/Tests/UserSyncIntegrationPlaceholderTests.cs @@ -0,0 +1,16 @@ +using Xunit; + +namespace HikvisionAttendanceService.Tests; + +/// +/// Full device-to-device sync requires physical terminals and credentials. +/// Run dotnet test --filter FullyQualifiedName~UserSync_Manual only in a lab with serviceconfig.json configured. +/// +public class UserSyncIntegrationPlaceholderTests +{ + [Fact(Skip = "Integration: enable in lab with two Hikvision devices and valid serviceconfig.json")] + public void UserSync_Manual_two_devices_placeholder() + { + Assert.Fail("Replace with real integration test or run --test --user-sync-once against hardware."); + } +} diff --git a/Tests/UserSyncJsonParserTests.cs b/Tests/UserSyncJsonParserTests.cs new file mode 100644 index 0000000..68d7e68 --- /dev/null +++ b/Tests/UserSyncJsonParserTests.cs @@ -0,0 +1,47 @@ +using System.Linq; +using Xunit; + +namespace HikvisionAttendanceService.Tests; + +public class UserSyncJsonParserTests +{ + [Fact] + public void ParseUserInfoSearchPage_extracts_users_and_face_url() + { + const string json = """ + { + "UserInfoSearch": { + "UserInfo": [ + { + "employeeNo": "0000000001", + "name": "Test User", + "numOfFace": 1, + "numOfFP": 0, + "gender": "male", + "faceURL": "http://192.168.1.10/LOCALS/pic/enrlFace/0/1.jpg@WEB1", + "Valid": { "enable": true, "beginTime": "2026-01-01T00:00:00", "endTime": "2030-12-31T23:59:59" } + } + ] + } + } + """; + + var list = UserSyncJsonParser.ParseUserInfoSearchPage(json); + Assert.Single(list); + var u = list[0]; + Assert.Equal("0000000001", u.EmployeeNo); + Assert.Equal("Test User", u.Name); + Assert.Equal(1, u.NumOfFace); + Assert.Equal(0, u.NumOfFp); + Assert.Contains("enrlFace", u.FaceUrl); + Assert.True(u.ValidEnable); + Assert.Contains("2026-01-01", u.ValidBeginTime); + } + + [Fact] + public void ParseUserInfoSearchPage_empty_json_returns_empty() + { + Assert.Empty(UserSyncJsonParser.ParseUserInfoSearchPage("")); + Assert.Empty(UserSyncJsonParser.ParseUserInfoSearchPage("{}")); + } +} diff --git a/Tests/UserSyncRetryHelperTests.cs b/Tests/UserSyncRetryHelperTests.cs new file mode 100644 index 0000000..9e0571b --- /dev/null +++ b/Tests/UserSyncRetryHelperTests.cs @@ -0,0 +1,54 @@ +using System.Net; +using Xunit; + +namespace HikvisionAttendanceService.Tests; + +public class UserSyncRetryHelperTests +{ + [Theory] + [InlineData(0, 1000)] + [InlineData(1, 2000)] + [InlineData(2, 4000)] + public void GetBackoffDelayMilliseconds_exponential(int attempt, int expectedMs) + { + Assert.Equal(expectedMs, UserSyncRetryHelper.GetBackoffDelayMilliseconds(attempt)); + } + + [Fact] + public void GetBackoffDelayMilliseconds_caps_at_30s() + { + Assert.Equal(30_000, UserSyncRetryHelper.GetBackoffDelayMilliseconds(20)); + } + + [Theory] + [InlineData(503, true)] + [InlineData(502, true)] + [InlineData(429, true)] + [InlineData(408, true)] + [InlineData(401, false)] + [InlineData(404, false)] + [InlineData(200, false)] + public void IsTransientHttpStatus(int code, bool transient) + { + Assert.Equal(transient, UserSyncRetryHelper.IsTransientHttpStatus((HttpStatusCode)code)); + } +} + +public class HistoricalAcsDynamicBatchTests +{ + [Theory] + [InlineData(0, 30)] + [InlineData(999, 30)] + [InlineData(1000, 50)] + [InlineData(4999, 50)] + [InlineData(5000, 100)] + public void DetermineDynamicAcsBatchSize_thresholds(int parsedOk, int expected) + { + // internal method accessed via reflection because it lives inside HikvisionAttendanceManager.cs + var t = typeof(HikvisionAttendanceService.HikvisionAttendanceManager); + var m = t.GetMethod("DetermineDynamicAcsBatchSize", System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Static); + Assert.NotNull(m); + var v = (int)m!.Invoke(null, new object[] { parsedOk, 30 })!; + Assert.Equal(expected, v); + } +} diff --git a/UserSyncJsonParser.cs b/UserSyncJsonParser.cs new file mode 100644 index 0000000..80ed4f1 --- /dev/null +++ b/UserSyncJsonParser.cs @@ -0,0 +1,176 @@ +using System; +using System.Collections.Generic; +using System.Globalization; +using System.Web.Script.Serialization; + +namespace HikvisionAttendanceService; + +/// Parses UserInfo/Search JSON into rows (best-effort, firmware-tolerant). +internal static class UserSyncJsonParser +{ + public static List ParseUserInfoSearchPage(string json) + { + var list = new List(); + if (string.IsNullOrWhiteSpace(json)) + return list; + + try + { + var ser = new JavaScriptSerializer(); + object? root = ser.DeserializeObject(json); + if (root == null) + return list; + + var userInfos = FindUserInfoArray(root); + if (userInfos == null) + return list; + + foreach (var item in userInfos) + { + if (item is Dictionary d) + { + var u = MapUser(d); + if (!string.IsNullOrWhiteSpace(u.EmployeeNo)) + list.Add(u); + } + } + } + catch + { + // caller logs + } + + return list; + } + + private static object[]? FindUserInfoArray(object root) + { + var stack = new Stack(); + stack.Push(root); + while (stack.Count > 0) + { + var cur = stack.Pop(); + if (cur is Dictionary map) + { + if (map.TryGetValue("UserInfo", out var ui) && ui is object[] arr) + return arr; + + foreach (var kv in map) + { + if (kv.Value is Dictionary nd) + stack.Push(nd); + else if (kv.Value is object[] oa) + { + foreach (var it in oa) + if (it != null) + stack.Push(it); + } + } + } + else if (cur is object[] top) + { + foreach (var it in top) + if (it != null) + stack.Push(it); + } + } + + return null; + } + + internal static UserDto MapUser(Dictionary d) + { + var u = new UserDto + { + EmployeeNo = GetString(d, "employeeNo") ?? "", + Name = GetString(d, "name") ?? "", + UserType = GetString(d, "userType") ?? "normal", + NumOfFace = GetInt(d, "numOfFace"), + NumOfFp = GetInt(d, "numOfFP", "numOfFp", "numOfFingerPrint"), + Gender = GetString(d, "gender") ?? "", + FaceUrl = GetString(d, "faceURL", "faceUrl") ?? "" + }; + + if (d.TryGetValue("Valid", out var vObj) && vObj is Dictionary vd) + { + u.ValidEnable = GetBool(vd, "enable", defaultValue: true); + var b = GetString(vd, "beginTime"); + var e = GetString(vd, "endTime"); + if (!string.IsNullOrWhiteSpace(b)) + u.ValidBeginTime = b!; + if (!string.IsNullOrWhiteSpace(e)) + u.ValidEndTime = e!; + } + + u.DoorRight = GetString(d, "doorRight") ?? u.DoorRight; + + if (d.TryGetValue("RightPlan", out var rpObj) && rpObj is object[] rpArr && rpArr.Length > 0 && + rpArr[0] is Dictionary rp0) + { + u.RightPlanDoorNo = GetIntWithDefault(rp0, 1, "doorNo"); + u.RightPlanTemplateNo = GetString(rp0, "planTemplateNo") ?? u.RightPlanTemplateNo; + } + + if (string.IsNullOrWhiteSpace(u.UserType)) + u.UserType = "normal"; + + return u; + } + + private static string? GetString(Dictionary d, params string[] keys) + { + foreach (var k in keys) + { + if (!d.TryGetValue(k, out var v) || v == null) + continue; + var s = v.ToString(); + if (!string.IsNullOrWhiteSpace(s)) + return s.Trim(); + } + + return null; + } + + private static int GetInt(Dictionary d, params string[] keys) + { + return GetIntWithDefault(d, 0, keys); + } + + private static int GetIntWithDefault(Dictionary d, int defaultValue, params string[] keys) + { + foreach (var k in keys) + { + if (!d.TryGetValue(k, out var v) || v == null) + continue; + switch (v) + { + case int i: + return i; + case long l: + return l > int.MaxValue ? int.MaxValue : (int)l; + case double db: + return (int)db; + case string s when int.TryParse(s, NumberStyles.Integer, CultureInfo.InvariantCulture, out var n): + return n; + } + } + + return defaultValue; + } + + private static bool GetBool(Dictionary d, string key, bool defaultValue) + { + if (!d.TryGetValue(key, out var v) || v == null) + return defaultValue; + if (v is bool b) + return b; + var s = v.ToString(); + if (bool.TryParse(s, out var pb)) + return pb; + if (string.Equals(s, "1", StringComparison.Ordinal)) + return true; + if (string.Equals(s, "0", StringComparison.Ordinal)) + return false; + return defaultValue; + } +} diff --git a/UserSyncRetryHelper.cs b/UserSyncRetryHelper.cs new file mode 100644 index 0000000..f2ac7f3 --- /dev/null +++ b/UserSyncRetryHelper.cs @@ -0,0 +1,53 @@ +using System; +using System.Net; +using System.Net.Http; +using System.Threading; +using System.Threading.Tasks; + +namespace HikvisionAttendanceService; + +/// Exponential backoff retries for transient HTTP / network failures. +internal static class UserSyncRetryHelper +{ + /// 0-based attempt index: delays 1s, 2s, 4s, ... capped at 30s. + public static int GetBackoffDelayMilliseconds(int zeroBasedAttemptIndex) + { + if (zeroBasedAttemptIndex < 0) + zeroBasedAttemptIndex = 0; + double seconds = Math.Pow(2, zeroBasedAttemptIndex); + var ms = (int)(seconds * 1000); + return Math.Min(ms, 30_000); + } + + /// Returns true if the HTTP status may succeed on retry. + public static bool IsTransientHttpStatus(HttpStatusCode code) + { + var n = (int)code; + if (n == 408 || n == 429) + return true; + if (n >= 500 && n <= 599) + return true; + return false; + } + + public static bool ShouldRetryException(Exception ex) + { + if (ex is HttpRequestException || ex is TaskCanceledException) + return true; + return false; + } + + public static void SleepBackoff(int zeroBasedAttemptIndex, CancellationToken ct) + { + ct.ThrowIfCancellationRequested(); + var delay = GetBackoffDelayMilliseconds(zeroBasedAttemptIndex); + Thread.Sleep(delay); + ct.ThrowIfCancellationRequested(); + } + + public static async Task DelayBackoffAsync(int zeroBasedAttemptIndex, CancellationToken ct) + { + var delay = GetBackoffDelayMilliseconds(zeroBasedAttemptIndex); + await Task.Delay(delay, ct).ConfigureAwait(false); + } +} diff --git a/UserSyncTypes.cs b/UserSyncTypes.cs new file mode 100644 index 0000000..bb0e2cb --- /dev/null +++ b/UserSyncTypes.cs @@ -0,0 +1,38 @@ +namespace HikvisionAttendanceService; + +/// Outcome of syncing one employee to one target device in a cycle. +internal enum UserSyncStatus +{ + AlreadySynced, + CreatedAndFaceUploaded, + CreatedNoFaceAvailable, + CreatedFaceUploadFailed, + ExistsFaceUploaded, + ExistsNoFaceOnSourceSkipped, + ExistsUserFieldsUpdated, + FailedCreate, + FailedFaceUpload, + FailedUserModify, + FailedDeleteOnTarget, + SkippedFaceUploadPolicy, + DeletedOnTargetNotInSource +} + +/// Normalized user row from ISAPI UserInfo/Search for sync decisions. +internal sealed class UserDto +{ + public string EmployeeNo { get; set; } = ""; + public string Name { get; set; } = ""; + public string UserType { get; set; } = "normal"; + public int NumOfFace { get; set; } + public int NumOfFp { get; set; } + public string Gender { get; set; } = ""; + public string FaceUrl { get; set; } = ""; + public bool ValidEnable { get; set; } = true; + public string ValidBeginTime { get; set; } = "2026-01-01T00:00:00"; + public string ValidEndTime { get; set; } = "2036-12-31T23:59:59"; + public string DoorRight { get; set; } = "1"; + /// Door access plan; default single-door template 1 when source omits it. + public int RightPlanDoorNo { get; set; } = 1; + public string RightPlanTemplateNo { get; set; } = "1"; +}