From 79e0db29f9765dfebc614449f047f6d8d1483625 Mon Sep 17 00:00:00 2001 From: zgw <13623675548@163.com> Date: Mon, 7 Sep 2026 10:12:41 +0800 Subject: [PATCH] fix(shadow): repair UTC sampling and persist v3 diagnostics --- doc/algorithm-shadow/SHADOW_V32_UPDATE.md | 81 ++++++++ .../SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md | 14 +- ...2026-09-07-shadow-v3-observation-repair.md | 61 ++++++ .../shadow/ShadowObservationGateway.java | 28 ++- .../mapper/ShadowUtcInstantTypeHandler.java | 46 +++++ ruoyi-admin/src/main/resources/logback.xml | 25 ++- .../mapper/algorithm/ShadowInputMapper.xml | 18 +- .../shadow/ShadowLogRoutingTest.java | 64 ++++++ .../shadow/ShadowObservationGatewayTest.java | 42 ++++ .../shadow/ShadowPlanningEngineTest.java | 4 +- .../shadow/ShadowUtcMappingTest.java | 186 ++++++++++++++++++ .../shadow/ShadowV3OperationsPackageTest.java | 64 +++++- .../resources/shadow/Sqlcmd13OutputFixture.cs | 32 +++ scripts/shadow-v3-export.cmd | 26 ++- scripts/shadow-v3-export.sql | 21 +- 15 files changed, 678 insertions(+), 34 deletions(-) create mode 100644 doc/algorithm-shadow/SHADOW_V32_UPDATE.md create mode 100644 docs/superpowers/plans/2026-09-07-shadow-v3-observation-repair.md create mode 100644 ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/mapper/ShadowUtcInstantTypeHandler.java create mode 100644 ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowLogRoutingTest.java create mode 100644 ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowUtcMappingTest.java create mode 100644 ruoyi-admin/src/test/resources/shadow/Sqlcmd13OutputFixture.cs diff --git a/doc/algorithm-shadow/SHADOW_V32_UPDATE.md b/doc/algorithm-shadow/SHADOW_V32_UPDATE.md new file mode 100644 index 0000000..e7ccf90 --- /dev/null +++ b/doc/algorithm-shadow/SHADOW_V32_UPDATE.md @@ -0,0 +1,81 @@ +# 影子 V3.2 更新、检查和回滚 + +本次只修复影子 UTC 时间映射、影子告警保存和 CMD 导出。Legacy 仍负责实际业务，不是正式算法切换。本次不需要安装、升级或卸载数据库对象，也不修改全局 JVM 时区。 + +## 第一步：选好短暂停机时间 + +现场由这一份 WMS 程序继续运行 Legacy，重启会短暂中断 WMS 服务。请选业务空闲的维护窗口，不要在作业处理中直接重启。 + +只停止 IDEA 中 `C:\project\FT546WMS-SHANDOW` 对应的 **WMS**。不要停止 WCS、WCS 影子或其他 Java 进程，不使用 `taskkill /IM java.exe`。 + +## 第二步：记录旧版本并更新代码 + +在 CMD 中逐行执行： + +```cmd +cd /d C:\project\FT546WMS-SHANDOW +git branch --show-current +git status --porcelain +git rev-parse HEAD +``` + +分支必须是 `test/ft546wms-shadow-v3-20260903`，第二条 Git 检查必须没有输出。否则停止更新，让服务器 AI 汇报现有改动，不覆盖、不清理文件。 + +确认后，逐行执行；任何命令失败都停止： + +```cmd +git tag backup/ft546wms-before-v32-20260907 HEAD +git fetch origin +git pull --ff-only origin test/ft546wms-shadow-v3-20260903 +git rev-parse HEAD +git status --porcelain +``` + +如果备份标签已存在，不覆盖它，先让服务器 AI 核对。更新后的提交号应与本次交付提交一致，工作区仍应干净。 + +## 第三步：在 IDEA 重新编译并启动 + +保持原 Run Configuration、端口、数据库、许可证和环境变量。不要新开第二个 WMS。执行 Build / Rebuild Project，成功后启动原 WMS 配置。 + +关键变量仍然是： + +```text +FORTUCKY_SHADOW_ENABLED=true +FORTUCKY_ALGORITHM_MODE=SHADOW +FORTUCKY_ALGORITHM_DATABASE_WRITES_ENABLED=true +FORTUCKY_ALGORITHM_WAREHOUSE_ID=01 +FORTUCKY_SHADOW_TIMEOUT_SECONDS=3 +FORTUCKY_SHADOW_SNAPSHOT_MAX_AGE_SECONDS=60 +FORTUCKY_SHADOW_QUIET_INTERVAL_MILLIS=1000 +``` + +其他现有变量原样保留，不把这段当作整份环境变量的替代。不要添加 `-Duser.timezone=UTC`，不要放大快照有效期。 + +## 第四步：先确认采样，再累计测试时间 + +记录这次真正启动成功的北京时间和 UTC 时间。等现场自然发生正常业务，不制造、重放或重复提交出入库请求。让服务器 AI 按 `SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md` 只读导出，将开始时间填为这次 V3.2 启动时间的 UTC 值。 + +检查以下证据： + +- `ADMITTED` 在真实业务后增加；`ADMISSION_US` 只是检查次数，不代表采样成功。 +- `INBOUND_COMPARE` / `OUTBOUND_COMPARE` 开始产生，包含快照时间、代次和输入诊断。没有某类业务时不能要求对应计数增长。 +- `logs\shadow-diagnostics.log` 保存影子 WARN/ERROR，时间明确为 UTC。文件为空只表示本文件没有记录，不能单独证明影子可用。 +- 快照同步时间和新写入的 `flushed_at` 使用 UTC。旧累计指标不清零；旧行在首次新刷新前仍可能保留旧的本地时间，不能把所有历史时间强行减八小时。 + +`EXPORT_OK` 仅表示文件导出成功。`NO_COMPARISONS` 表示本窗口尚无入出库比较，不能批准切换。空闲后第一笔请求因快照超过 60 秒而跳过仍可能正常；不要为增加样本而关闭过期或并发保护。 + +时间映射修复有本地回归测试，但现场还需确认刷新错误、业务频率等其他因素是否影响采样。开始产生有效样本之后再累计观察期，仍按连续七天、至少 100 个有效入库和 100 个有效出库比较及原性能门槛评估，不按程序开了几天直接切换。 + +## 出现问题时回滚 + +如果更新后影响现有使用，先停止这一份 WMS，WCS 不动。只在工作区干净时执行： + +```cmd +cd /d C:\project\FT546WMS-SHANDOW +git status --porcelain +git switch --detach backup/ft546wms-before-v32-20260907 +``` + +在 IDEA Rebuild Project 后，用原配置启动，恢复更新前代码。若有未提交改动或命令报错，停止操作，不用 reset/clean 强制覆盖。 + +另一种隔离方式是在维护窗口将原配置中的 `FORTUCKY_SHADOW_ENABLED` 改为 `false` 后重启 WMS，停止影子观察，Legacy 继续运行。两种方式均不回滚业务数据、不卸载 `alg` 表，保留日志和影子数据用于排查。 diff --git a/doc/algorithm-shadow/SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md b/doc/algorithm-shadow/SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md index 27ecead..85d5272 100644 --- a/doc/algorithm-shadow/SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md +++ b/doc/algorithm-shadow/SHADOW_V3_SERVER_AI_EXPORT_PROMPT.md @@ -9,9 +9,9 @@ - 仓库目录：C:\project\FT546WMS-SHANDOW - SQL Server： - 数据库： -- v3 测试开始 UTC： +- 本次修复实际启动 UTC： - 应用日志目录： -- 输出目录：C:\project\FT546WMS-shadow-v3-export +- 输出目录：C:\project\FT546WMS-shadow-v3-export（必须为空或不存在；重复导出用新的带时间目录） - 期望分支：test/ft546wms-shadow-v3-20260903 - 期望提交： @@ -30,12 +30,13 @@ git rev-parse HEAD git status --porcelain jps -lv | findstr /I "RuoYiApplication FT546WMS" -必须满足：分支等于期望分支，HEAD 等于期望提交，git status 没有输出，相关 JVM 最多一个。否则停止并报告。 +必须满足：分支等于期望分支，HEAD 等于期望提交，git status 没有输出，目标 WMS 正常运行且只有一个实例。结合源码目录和 IDEA 配置辨认，不把 WCS 或 WCS 影子算作 WMS；无法辨认就报告，不停止任何进程。 然后执行仓库自带的只读导出器： call scripts\shadow-v3-export.cmd C:\project\FT546WMS-SHANDOW "" "" "" "C:\project\FT546WMS-shadow-v3-export" "" -必须看到 EXPORT_OK。随后只检查输出文件是否存在，不打开或改写内容： +必须看到 EXPORT_OK。此标记仅表示导出完成，不代表样本合格或可以正式切换。导出器已兼容 sqlcmd 13，无需改写 :out 或单独执行 SQL 文件。 +随后检查输出文件： dir /b C:\project\FT546WMS-shadow-v3-export 期望至少包含： @@ -55,6 +56,11 @@ shadow-warnings.txt - 输出目录； - 文件名和大小； - 任何错误。 +- comparison-detail.txt 汇总中的四项计数及 sample_status；NO_COMPARISONS 表示尚无比较样本，不当成测试通过。 +- 日志目录是否存在 shadow-diagnostics.log；没有报错时允许为空，不人为制造业务异常验证。 +- IDEA 中实际 WMS 启动时间、时区和 Run Configuration 是否可确认；不能确认的写明未知，不从启动 CMD 环境推断运行进程继承情况。 + +runtime-metrics.txt 是累计指标，不受本次开始时间过滤。V3.2 新写入 flushed_at 为 UTC；未被新刷新更新的旧行仍可能是旧本地时间。不要清零计数、改写旧时间或自行得出性能无影响的结论。 不要在回复中粘贴环境变量值、数据库凭据或完整业务数据。不要压缩以外的改写；由现场人员把整个输出目录压缩后交给分析。 ``` diff --git a/docs/superpowers/plans/2026-09-07-shadow-v3-observation-repair.md b/docs/superpowers/plans/2026-09-07-shadow-v3-observation-repair.md new file mode 100644 index 0000000..845074b --- /dev/null +++ b/docs/superpowers/plans/2026-09-07-shadow-v3-observation-repair.md @@ -0,0 +1,61 @@ +# Shadow v3 Observation Repair + +> Execute inline with test-driven-development and verification-before-completion. Subagents explore and review only, per project instructions. + +**Goal:** Restore timezone-independent shadow sampling and exportable diagnostics without changing Legacy. + +**Architecture:** Use a statement-scoped UTC Instant handler, a bounded shadow-only log, and literal sqlcmd output paths. Preserve all scheduling, freshness, transaction and mode guards. + +**Tech Stack:** Java 17, MyBatis 3.5.19, Microsoft JDBC 12.10.1, Logback, Windows CMD, SQL Server 2016 RTM. + +**Spec:** `docs/superpowers/specs/2026-09-03-ft546wms-shadow-v3-design.md`. + +## Constraints + +- No global timezone/type-handler override; no Legacy code or business SQL changes. +- Keep SHADOW mode, 60-second snapshot freshness and existing single-worker coordination. +- Do not restart field processes or migrate SQL objects. Keep historical metric counters. +- Export with Windows integrated authentication, read-only SQL, and no overwriting existing evidence. + +## 1. UTC Mapping + +- [x] Add `ShadowUtcMappingTest` loading the real mapper. Exercise UTC and Asia/Shanghai reads through the actual driver's datetime2 conversion, preserve 100ns precision, and verify fresh/stale coordinator admission. +- [x] Run the test and observe the eight-hour failure. +- [x] Add `mapper/ShadowUtcInstantTypeHandler.java`; use `getTimestamp(..., Calendar.getInstance(TimeZone.getTimeZone("UTC")))` and `setTimestamp(..., Timestamp.from(value), utcCalendar)`. +- [x] Add an explicit snapshot result map and bind the handler only to `snapshotSynchronizedAt` and both `flushedAt` placeholders in `ShadowInputMapper.xml`. +- [x] Verify parameter writes, nulls, both JVM zones, and unchanged default MyBatis handler. + +## 2. Shadow Diagnostics + +- [x] Add an actual Logback routing test: a shadow WARN must reach a file; unrelated business WARN and INFO must not enter it. +- [x] Observe failure with the current configuration. +- [x] Add a shadow-only WARN-and-higher rolling appender with full dates, 10MB files, 14-day history and 100MB archive cap. +- [x] Add bounded exception metadata (cause class, SQL state/vendor code, source frame) without messages, SQL or payloads; keep logging on the existing worker paths. +- [x] Verify routing, error context, and existing caller isolation tests. + +## 3. Export Compatibility + +- [x] Add CMD behavior tests with spaced paths, literal SQL output destinations, success/failure, working-directory restoration and evidence preservation. +- [x] Run and observe the existing output-path failure. Drain test process output without pipe deadlock. +- [x] Run sqlcmd from `OUTPUT_DIR`, use literal `:out` names, balance pushd/popd and check each Git command failure. +- [x] Label local export time honestly; add explicit zero-comparison status using read-only SQL. +- [x] Update server AI instructions and add maintenance-window deployment/rollback steps, with no SQL reinstall. + +## Review Notes + +- UTC read/write and nanosecond mapping reviewed independently; no confirmed defect found. +- Actual Logback configuration test passed with no ERROR status. The existing two root declarations are accepted by the installed Logback; changing them is unnecessary scope expansion. +- Logger additivity intentionally preserves existing console/error behavior. The new file receives only shadow WARN/ERROR, confirmed by file-routing tests. +- SQL diagnostics intentionally select the deepest SQLException within eight cause levels; exception messages and SQL are never logged. The worker test verifies SQLState, code, source and payload exclusion. +- CMD fixture executes the real scripts but does not execute SQL. No live SQL Server or field deployment was performed locally; those remain explicit verification limits. + +## Verification and Delivery + +- [x] Run focused tests, then reactor tests and package with Maven 3.9.11 / JDK 17; run existing Node guards. +- [x] Independent read-only review, address findings, rerun affected tests and `git diff --check`. +- [x] Fetch remote again and verify no concurrent remote commits before preparing delivery. +- [x] Prepare simple CMD update/rollback steps in `doc/algorithm-shadow/SHADOW_V32_UPDATE.md`. + +Final verification: 138 algorithm tests + 78 admin tests = 216 passed, zero failures/errors/skips. Maven reactor `package` succeeded on 2026-09-07; three existing Node scripts passed `node --check`. Existing Lombok/deprecation and JVM test-instrumentation warnings remain. No live SQL Server validation or field restart was performed. + +Delivery: commit and push only `test/ft546wms-shadow-v3-20260903`, verify the remote hash, and report it in the handoff. Do not merge into main or switch to ACTIVE. diff --git a/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/ShadowObservationGateway.java b/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/ShadowObservationGateway.java index 34ee1b1..15a7b72 100644 --- a/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/ShadowObservationGateway.java +++ b/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/ShadowObservationGateway.java @@ -9,6 +9,7 @@ import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Component; +import java.sql.SQLException; import java.time.Clock; import java.time.Duration; import java.time.Instant; @@ -346,9 +347,32 @@ public class ShadowObservationGateway { long elapsedMicros = startedNanos == 0L ? 0L : TimeUnit.NANOSECONDS.toMicros(Math.max(0L, System.nanoTime() - startedNanos)); LOG.warn("shadow_failure requestId={} warehouse={} snapshotGeneration={} stage={} " - + "exceptionClass={} elapsedMicros={}", + + "exceptionClass={} elapsedMicros={} {}", requestId, warehouseId, generation, stage, - failure.getClass().getName(), elapsedMicros); + failure.getClass().getName(), elapsedMicros, diagnosticMetadata(failure)); + } + + private static String diagnosticMetadata(Throwable failure) { + Throwable cause = failure; + SQLException sqlFailure = null; + // Bounded traversal; never log exception messages, SQL text or wrapped business payloads. + for (int depth = 0; depth < 8; depth++) { + if (cause instanceof SQLException sql) { + sqlFailure = sql; + } + if (cause.getCause() == null || cause.getCause() == cause || depth == 7) { + break; + } + cause = cause.getCause(); + } + String sqlState = sqlFailure == null ? null : sqlFailure.getSQLState(); + StackTraceElement[] trace = cause.getStackTrace(); + String source = trace.length == 0 ? "-" + : trace[0].getClassName() + '.' + trace[0].getMethodName() + ':' + trace[0].getLineNumber(); + return "causeClass=" + cause.getClass().getName() + + " sqlState=" + (sqlState != null && sqlState.matches("[A-Za-z0-9]{5}") ? sqlState : "-") + + " sqlCode=" + (sqlFailure == null ? 0 : sqlFailure.getErrorCode()) + + " causeAt=" + source; } private String failureDescription(ShadowFailureStage stage, Throwable failure) { diff --git a/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/mapper/ShadowUtcInstantTypeHandler.java b/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/mapper/ShadowUtcInstantTypeHandler.java new file mode 100644 index 0000000..cce1439 --- /dev/null +++ b/ruoyi-admin/src/main/java/com/ruoyi/algorithm/shadow/mapper/ShadowUtcInstantTypeHandler.java @@ -0,0 +1,46 @@ +package com.ruoyi.algorithm.shadow.mapper; + +import org.apache.ibatis.type.BaseTypeHandler; +import org.apache.ibatis.type.JdbcType; + +import java.sql.CallableStatement; +import java.sql.PreparedStatement; +import java.sql.ResultSet; +import java.sql.SQLException; +import java.sql.Timestamp; +import java.time.Instant; +import java.util.Calendar; +import java.util.TimeZone; + +/** Explicitly referenced only by shadow mappings whose datetime2 values are UTC. */ +public final class ShadowUtcInstantTypeHandler extends BaseTypeHandler { + @Override + public void setNonNullParameter(PreparedStatement statement, int index, Instant value, JdbcType jdbcType) + throws SQLException { + statement.setTimestamp(index, Timestamp.from(value), utcCalendar()); + } + + @Override + public Instant getNullableResult(ResultSet results, String column) throws SQLException { + return instant(results.getTimestamp(column, utcCalendar())); + } + + @Override + public Instant getNullableResult(ResultSet results, int column) throws SQLException { + return instant(results.getTimestamp(column, utcCalendar())); + } + + @Override + public Instant getNullableResult(CallableStatement statement, int column) throws SQLException { + return instant(statement.getTimestamp(column, utcCalendar())); + } + + private static Instant instant(Timestamp timestamp) { + return timestamp == null ? null : timestamp.toInstant(); + } + + private static Calendar utcCalendar() { + // Calendar is mutable and may be modified by a JDBC driver; never share it across calls. + return Calendar.getInstance(TimeZone.getTimeZone("UTC")); + } +} diff --git a/ruoyi-admin/src/main/resources/logback.xml b/ruoyi-admin/src/main/resources/logback.xml index a8c526e..76bf7ca 100644 --- a/ruoyi-admin/src/main/resources/logback.xml +++ b/ruoyi-admin/src/main/resources/logback.xml @@ -71,7 +71,28 @@ - + + + ${log.path}/shadow-diagnostics.log + + ${log.path}/shadow-diagnostics.%d{yyyy-MM-dd}.%i.log + 10MB + 14 + 100MB + + + UTF-8 + %d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC} [%thread] %-5level %logger - %msg%n + + + WARN + + + + + + + @@ -90,4 +111,4 @@ - \ No newline at end of file + diff --git a/ruoyi-admin/src/main/resources/mapper/algorithm/ShadowInputMapper.xml b/ruoyi-admin/src/main/resources/mapper/algorithm/ShadowInputMapper.xml index aab0e9e..5e44a6d 100644 --- a/ruoyi-admin/src/main/resources/mapper/algorithm/ShadowInputMapper.xml +++ b/ruoyi-admin/src/main/resources/mapper/algorithm/ShadowInputMapper.xml @@ -89,8 +89,16 @@ PUBLIC "-//mybatis.org//DTD Mapper 3.0//EN" @instance_id = #{instanceId}; - select state.snapshot_generation as snapshotGeneration, state.warehouse_id as warehouseId, state.snapshot_status as snapshotStatus, @@ -109,7 +117,7 @@ PUBLIC "-//mybatis.org//DTD Mapper 3.0//EN" where state.warehouse_id = #{warehouseId} and state.snapshot_status = 'PUBLISHED' and state.snapshot_generation = #{inputVersion} - and state.synchronized_at = #{snapshotSynchronizedAt} + and state.synchronized_at = #{snapshotSynchronizedAt, jdbcType=TIMESTAMP, typeHandler=com.ruoyi.algorithm.shadow.mapper.ShadowUtcInstantTypeHandler} and convert(varchar(64), state.source_signature, 2) = #{sourceSignature} @@ -126,12 +134,12 @@ PUBLIC "-//mybatis.org//DTD Mapper 3.0//EN" metric_total_micros = target.metric_total_micros + #{metricTotalMicros}, metric_max_micros = case when target.metric_max_micros > #{metricMaxMicros} then target.metric_max_micros else #{metricMaxMicros} end, - flushed_at = #{flushedAt} + flushed_at = #{flushedAt, jdbcType=TIMESTAMP, typeHandler=com.ruoyi.algorithm.shadow.mapper.ShadowUtcInstantTypeHandler} when not matched then insert ( warehouse_id, metric_name, bucket_upper_micros, metric_count, metric_total_micros, metric_max_micros, flushed_at) values ( source.warehouse_id, source.metric_name, source.bucket_upper_micros, - #{metricCount}, #{metricTotalMicros}, #{metricMaxMicros}, #{flushedAt}); + #{metricCount}, #{metricTotalMicros}, #{metricMaxMicros}, #{flushedAt, jdbcType=TIMESTAMP, typeHandler=com.ruoyi.algorithm.shadow.mapper.ShadowUtcInstantTypeHandler}); diff --git a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowLogRoutingTest.java b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowLogRoutingTest.java new file mode 100644 index 0000000..17eb148 --- /dev/null +++ b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowLogRoutingTest.java @@ -0,0 +1,64 @@ +package com.ruoyi.algorithm.shadow; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.joran.JoranConfigurator; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; +import org.w3c.dom.Element; + +import javax.xml.parsers.DocumentBuilderFactory; +import javax.xml.transform.TransformerFactory; +import javax.xml.transform.dom.DOMSource; +import javax.xml.transform.stream.StreamResult; +import java.io.ByteArrayInputStream; +import java.io.ByteArrayOutputStream; +import java.nio.file.Files; +import java.nio.file.Path; + +import static org.assertj.core.api.Assertions.assertThat; + +class ShadowLogRoutingTest { + @TempDir + Path logs; + + @Test + void shadowWarningsArePersistedWithoutChangingBusinessLogRouting() throws Exception { + var factory = DocumentBuilderFactory.newInstance(); + factory.setFeature("http://apache.org/xml/features/disallow-doctype-decl", true); + var document = factory.newDocumentBuilder().parse(getClass().getResourceAsStream("/logback.xml")); + var properties = document.getElementsByTagName("property"); + for (int index = 0; index < properties.getLength(); index++) { + Element property = (Element) properties.item(index); + if ("log.path".equals(property.getAttribute("name"))) { + property.setAttribute("value", logs.toString().replace('\\', '/')); + } + } + var xml = new ByteArrayOutputStream(); + TransformerFactory.newInstance().newTransformer().transform(new DOMSource(document), new StreamResult(xml)); + LoggerContext context = new LoggerContext(); + context.setMDCAdapter(new ch.qos.logback.classic.util.LogbackMDCAdapter()); + try { + JoranConfigurator configurator = new JoranConfigurator(); + configurator.setContext(context); + configurator.doConfigure(new ByteArrayInputStream(xml.toByteArray())); + var shadow = context.getLogger(ShadowObservationGateway.class); + shadow.warn("shadow_failure stage=REFRESH exceptionClass=java.sql.SQLException"); + shadow.error("shadow_error_preserved"); + shadow.info("shadow_info_not_a_warning"); + context.getLogger("com.ruoyi.business.Example").warn("business_warn_not_shadow"); + context.getLogger("com.ruoyi.business.Example").error("business_error_preserved"); + assertThat(context.getStatusManager().getCopyOfStatusList()) + .noneMatch(status -> status.getLevel() == ch.qos.logback.core.status.Status.ERROR); + } finally { + context.stop(); + } + Path shadowLog = logs.resolve("shadow-diagnostics.log"); + assertThat(shadowLog).isRegularFile(); + assertThat(Files.readString(shadowLog)).contains("shadow_failure", "stage=REFRESH", "shadow_error_preserved") + .containsPattern("\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}") + .doesNotContain("shadow_info_not_a_warning", "business_warn_not_shadow", "business_error_preserved"); + assertThat(Files.readString(logs.resolve("sys-error.log"))) + .contains("business_error_preserved", "shadow_error_preserved").doesNotContain("shadow_failure"); + assertThat(Files.readString(logs.resolve("sys-info.log"))).contains("shadow_info_not_a_warning"); + } +} diff --git a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowObservationGatewayTest.java b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowObservationGatewayTest.java index f56cb95..66ea376 100644 --- a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowObservationGatewayTest.java +++ b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowObservationGatewayTest.java @@ -214,6 +214,48 @@ class ShadowObservationGatewayTest { verify(engine, never()).compareInbound(any(), anyString(), anyString()); } + @Test + void workerFailureLogsSqlCauseWithoutExceptionMessagesOrPayloads() throws Exception { + var logger = (ch.qos.logback.classic.Logger) org.slf4j.LoggerFactory.getLogger(ShadowObservationGateway.class); + var logged = new java.util.concurrent.atomic.AtomicReference(); + var logThread = new java.util.concurrent.atomic.AtomicReference(); + CountDownLatch warning = new CountDownLatch(1); + var appender = new ch.qos.logback.core.AppenderBase() { + @Override + protected void append(ch.qos.logback.classic.spi.ILoggingEvent event) { + logged.set(event.getFormattedMessage()); + logThread.set(Thread.currentThread().getName()); + warning.countDown(); + } + }; + appender.setContext(logger.getLoggerContext()); + appender.start(); + logger.addAppender(appender); + try { + ShadowPlanningEngine engine = mock(ShadowPlanningEngine.class); + var sqlFailure = new java.sql.SQLException("password=secret SQL payload", "40001", 1205); + sqlFailure.setStackTrace(new StackTraceElement[]{ + new StackTraceElement("com.microsoft.sqlserver.jdbc.SQLServerException", "makeFromDatabaseError", "SQLServerException.java", 270)}); + when(engine.planInbound(SNAPSHOT, "TASK-LOG", "TRAY-LOG")) + .thenThrow(new IllegalStateException("private wrapper message", sqlFailure)); + ShadowInputMapper mapper = mock(ShadowInputMapper.class); + stubSuccessfulRecovery(engine, mapper, 43L); + ShadowObservationGateway gateway = gateway(engine, mapper, coordinatorWithSnapshot(), + new ShadowRuntimeMetrics(), Clock.fixed(NOW, ZoneOffset.UTC), delay -> { }); + InboundShadowCompletion completion = gateway.observeInbound("TASK-LOG", "TRAY-LOG"); + completion.complete("10", "SPACE-LOG"); + + assertThat(warning.await(2, TimeUnit.SECONDS)).isTrue(); + assertThat(logged.get()).contains("shadow_failure", "stage=PLAN", "java.sql.SQLException", + "sqlState=40001", "sqlCode=1205", "makeFromDatabaseError") + .doesNotContain("password", "secret", "SQL payload", "private wrapper message"); + assertThat(logThread.get()).isNotEqualTo(Thread.currentThread().getName()); + } finally { + logger.detachAppender(appender); + appender.stop(); + } + } + @Test void comparisonFailureIsWorkerOnlyAndRecordedByFixedStage() throws Exception { ShadowPlanningEngine engine = mock(ShadowPlanningEngine.class); diff --git a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowPlanningEngineTest.java b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowPlanningEngineTest.java index 8bf35c7..9b5d63e 100644 --- a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowPlanningEngineTest.java +++ b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowPlanningEngineTest.java @@ -337,8 +337,8 @@ class ShadowPlanningEngineTest { "from alg.shadow_snapshot_state state with (updlock, holdlock)", "state.snapshot_status = 'published'", "state.snapshot_generation = #{inputversion}", - "state.synchronized_at = #{snapshotsynchronizedat}", - "convert(varchar(64), state.source_signature, 2) = #{sourcesignature}"); + "convert(varchar(64), state.source_signature, 2) = #{sourcesignature}") + .containsPattern("state\\.synchronized_at = #\\{snapshotsynchronizedat(?:,[^}]+)?}"); assertThat(statements.get("selectPublishedSnapshot")) .contains("alg.shadow_snapshot_state", "convert(varchar(64),", "source_signature", ", 2)"); diff --git a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowUtcMappingTest.java b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowUtcMappingTest.java new file mode 100644 index 0000000..6a03221 --- /dev/null +++ b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowUtcMappingTest.java @@ -0,0 +1,186 @@ +package com.ruoyi.algorithm.shadow; + +import org.apache.ibatis.builder.xml.XMLMapperBuilder; +import org.apache.ibatis.mapping.MappedStatement; +import org.apache.ibatis.scripting.defaults.DefaultParameterHandler; +import org.apache.ibatis.session.Configuration; +import org.apache.ibatis.type.InstantTypeHandler; +import org.apache.ibatis.type.TypeHandler; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.parallel.ResourceLock; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.ValueSource; + +import java.io.InputStream; +import java.lang.reflect.Method; +import java.lang.reflect.Proxy; +import java.sql.CallableStatement; +import java.sql.PreparedStatement; +import java.sql.ResultSet; +import java.sql.Timestamp; +import java.time.Clock; +import java.time.Duration; +import java.time.Instant; +import java.time.LocalDate; +import java.time.LocalDateTime; +import java.time.ZoneOffset; +import java.time.temporal.ChronoUnit; +import java.util.ArrayList; +import java.util.Calendar; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.TimeZone; + +import static org.assertj.core.api.Assertions.assertThat; + +@ResourceLock("default-time-zone") +class ShadowUtcMappingTest { + private static final String NAMESPACE = "com.ruoyi.algorithm.shadow.mapper.ShadowInputMapper."; + private static final Instant SNAPSHOT_TIME = Instant.parse("2026-09-07T01:31:00.1623685Z"); + private static final LocalDateTime SQL_TIME = LocalDateTime.parse("2026-09-07T01:31:00.1623685"); + + @ParameterizedTest + @ValueSource(strings = {"UTC", "Asia/Shanghai"}) + void publishedUtcDatetime2RemainsFreshAndRetainsPrecision(String zone) throws Exception { + TimeZone previous = TimeZone.getDefault(); + try { + TimeZone.setDefault(TimeZone.getTimeZone(zone)); + TypeHandler handler = snapshotHandler(configuration()); + ResultSet row = (ResultSet) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{ResultSet.class}, (proxy, method, args) -> { + if (method.getName().equals("getTimestamp")) { + return driverTimestamp(args.length == 2 ? (Calendar) args[1] : null); + } + throw new UnsupportedOperationException(method.getName()); + }); + Instant decoded = handler.getResult(row, "synchronizedAt"); + assertThat(decoded).isEqualTo(SNAPSHOT_TIME); + assertThat(handler.getResult(row, 1)).isEqualTo(SNAPSHOT_TIME); + CallableStatement call = (CallableStatement) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{CallableStatement.class}, (proxy, method, args) -> { + if (method.getName().equals("getTimestamp")) { + return driverTimestamp(args.length == 2 ? (Calendar) args[1] : null); + } + throw new UnsupportedOperationException(method.getName()); + }); + assertThat(handler.getResult(call, 1)).isEqualTo(SNAPSHOT_TIME); + Instant now = Instant.parse("2026-09-07T01:31:01Z"); + assertThat(admission(decoded, now).accepted()).isTrue(); + assertThat(admission(decoded, SNAPSHOT_TIME.plusSeconds(61)).skipReason()) + .isEqualTo(ShadowSkipReason.STALE); + } finally { + TimeZone.setDefault(previous); + } + } + + @ParameterizedTest + @ValueSource(strings = {"UTC", "Asia/Shanghai"}) + void comparisonAndBothMetricTimestampBindingsWriteUtc(String zone) throws Exception { + TimeZone previous = TimeZone.getDefault(); + try { + TimeZone.setDefault(TimeZone.getTimeZone(zone)); + Configuration configuration = configuration(); + Map values = new HashMap<>(); + values.put("snapshotSynchronizedAt", SNAPSHOT_TIME); + values.put("flushedAt", SNAPSHOT_TIME); + assertThat(boundTimestamps(configuration, "insertComparison", values)) + .containsExactly(SQL_TIME); + assertThat(boundTimestamps(configuration, "upsertRuntimeMetric", values)) + .containsExactly(SQL_TIME, SQL_TIME); + assertThat(configuration.getTypeHandlerRegistry().getTypeHandler(Instant.class)) + .isExactlyInstanceOf(InstantTypeHandler.class); + } finally { + TimeZone.setDefault(previous); + } + } + + @Test + void nullableTimestampResultsRemainNull() throws Exception { + TypeHandler handler = snapshotHandler(configuration()); + ResultSet row = (ResultSet) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{ResultSet.class}, (proxy, method, args) -> null); + CallableStatement call = (CallableStatement) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{CallableStatement.class}, (proxy, method, args) -> null); + assertThat(handler.getResult(row, "synchronizedAt")).isNull(); + assertThat(handler.getResult(row, 1)).isNull(); + assertThat(handler.getResult(call, 1)).isNull(); + } + + @Test + void nullInstantBindsAsSqlNullTimestamp() throws Exception { + List nullTypes = new ArrayList<>(); + PreparedStatement statement = (PreparedStatement) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{PreparedStatement.class}, (proxy, method, args) -> { + if (!method.getName().equals("setNull")) { + throw new UnsupportedOperationException(method.getName()); + } + nullTypes.add((Integer) args[1]); + return null; + }); + snapshotHandler(configuration()).setParameter(statement, 1, null, org.apache.ibatis.type.JdbcType.TIMESTAMP); + assertThat(nullTypes).containsExactly(java.sql.Types.TIMESTAMP); + } + + private List boundTimestamps(Configuration configuration, String id, + Map values) throws Exception { + List timestamps = new ArrayList<>(); + PreparedStatement statement = (PreparedStatement) Proxy.newProxyInstance(getClass().getClassLoader(), + new Class[]{PreparedStatement.class}, (proxy, method, args) -> { + if (method.getName().equals("setTimestamp")) { + Calendar calendar = args.length == 3 ? (Calendar) args[2] : Calendar.getInstance(); + timestamps.add(LocalDateTime.ofInstant(((Timestamp) args[1]).toInstant(), + calendar.getTimeZone().toZoneId())); + } else if (!method.getName().startsWith("set")) { + throw new UnsupportedOperationException(method.getName()); + } + return null; + }); + MappedStatement mapped = configuration.getMappedStatement(NAMESPACE + id); + new DefaultParameterHandler(mapped, values, mapped.getBoundSql(values)).setParameters(statement); + return timestamps; + } + + @SuppressWarnings("unchecked") + private TypeHandler snapshotHandler(Configuration configuration) { + return (TypeHandler) configuration.getMappedStatement(NAMESPACE + "selectPublishedSnapshot") + .getResultMaps().get(0).getResultMappings().stream() + .filter(mapping -> "synchronizedAt".equals(mapping.getProperty())) + .>map(mapping -> mapping.getTypeHandler()).findFirst() + .orElse(configuration.getTypeHandlerRegistry().getTypeHandler(Instant.class)); + } + + private Configuration configuration() throws Exception { + Configuration configuration = new Configuration(); + String resource = "mapper/algorithm/ShadowInputMapper.xml"; + try (InputStream stream = getClass().getClassLoader().getResourceAsStream(resource)) { + new XMLMapperBuilder(stream, configuration, resource, configuration.getSqlFragments()).parse(); + } + return configuration; + } + + private ShadowSnapshotCoordinator.Admission admission(Instant time, Instant now) { + ShadowSnapshotCoordinator coordinator = new ShadowSnapshotCoordinator("01", Duration.ofSeconds(60), + Clock.fixed(now, ZoneOffset.UTC)); + var ticket = coordinator.tryBeginRefresh(now).orElseThrow(); + assertThat(coordinator.publish(ticket, new PublishedShadowSnapshot(453L, "01", time, "ABC"), now)) + .isTrue(); + return coordinator.enter(now); + } + + @SuppressWarnings({"rawtypes", "unchecked"}) + private Timestamp driverTimestamp(Calendar calendar) throws Exception { + Class jdbcType = (Class) Class.forName("com.microsoft.sqlserver.jdbc.JDBCType"); + Class sqlType = (Class) Class.forName("com.microsoft.sqlserver.jdbc.SSType"); + Class connection = Class.forName("com.microsoft.sqlserver.jdbc.SQLServerConnection"); + // The real driver's Calendar-aware datetime2 decoder, without opening a database connection. + Method conversion = Class.forName("com.microsoft.sqlserver.jdbc.DDC").getDeclaredMethod( + "convertTemporalToObject", connection, jdbcType, sqlType, Calendar.class, + int.class, long.class, int.class); + conversion.setAccessible(true); + return (Timestamp) conversion.invoke(null, null, Enum.valueOf(jdbcType, "TIMESTAMP"), + Enum.valueOf(sqlType, "DATETIME2"), calendar, + (int) ChronoUnit.DAYS.between(LocalDate.of(1, 1, 1), SQL_TIME.toLocalDate()), + SQL_TIME.toLocalTime().toNanoOfDay(), 7); + } +} diff --git a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowV3OperationsPackageTest.java b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowV3OperationsPackageTest.java index 479c620..fac5d25 100644 --- a/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowV3OperationsPackageTest.java +++ b/ruoyi-admin/src/test/java/com/ruoyi/algorithm/shadow/ShadowV3OperationsPackageTest.java @@ -167,6 +167,30 @@ class ShadowV3OperationsPackageTest { assertThat(export.output()).contains("read-only SQL export failed"); } + @Test + void exportUsesLiteralSqlcmd13OutputPathsAndRestoresCallerDirectory() throws Exception { + Assumptions.assumeTrue(isWindows(), "CMD behavior is verified on Windows"); + Path fixture = Files.createDirectories(tempDir.resolve("sqlcmd13 fixture with spaces")); + Path bin = writeSqlcmd13Fixture(fixture); + Path logDir = Files.createDirectories(fixture.resolve("logs with spaces")); + Files.writeString(logDir.resolve("shadow-diagnostics.log"), + "2026-09-07T01:31:01Z WARN shadow_failure stage=REFRESH sqlCode=1205\n"); + Path output = fixture.resolve("export with spaces"); + CmdResult result = runCmd(root.resolve("scripts/shadow-v3-export.cmd"), bin, + root.toString(), "SQL SERVER WITH SPACE", "FT546 WMS", "2026-09-07T01:00:00Z", + output.toString(), logDir.toString()); + assertThat(result.exitCode()).as(result.output()).isZero(); + assertThat(result.output()).contains("EXPORT_OK"); + for (String filename : new String[]{"sql-diagnostics.txt", "comparison-detail.txt", + "runtime-metrics.txt", "inventory-parity.txt"}) { + assertThat(Files.readString(output.resolve(filename))).contains("read-only SQL output fixture"); + } + assertThat(Path.of(Files.readString(output.resolve("sqlcmd-cwd.txt")))) + .isEqualTo(output); + assertThat(Files.readString(output.resolve("shadow-warnings.txt"))) + .contains("shadow_failure", "sqlCode=1205"); + } + @Test void exportRefusesToOverwriteExistingEvidence() throws Exception { Assumptions.assumeTrue(isWindows(), "CMD behavior is verified on Windows"); @@ -197,6 +221,21 @@ class ShadowV3OperationsPackageTest { return bin; } + private Path writeSqlcmd13Fixture(Path fixture) throws Exception { + Path bin = Files.createDirectories(fixture.resolve("stub tools")); + Path compiler = Path.of(System.getenv("SystemRoot"), "Microsoft.NET", "Framework64", "v4.0.30319", "csc.exe"); + if (!Files.isRegularFile(compiler)) { + compiler = Path.of(System.getenv("SystemRoot"), "Microsoft.NET", "Framework", "v4.0.30319", "csc.exe"); + } + assertThat(compiler).as("Windows .NET Framework compiler for no-database CMD fixture").isRegularFile(); + Path executable = bin.resolve("sqlcmd.exe"); + CmdResult compiled = runProcess(new ProcessBuilder(compiler.toString(), "/nologo", + "/out:" + executable, root.resolve("ruoyi-admin/src/test/resources/shadow/Sqlcmd13OutputFixture.cs").toString()), 30); + assertThat(compiled.exitCode()).as(compiled.output()).isZero(); + Files.copy(executable, bin.resolve("jps.exe")); + return bin; + } + private void cloneRepository(Path destination) throws Exception { CmdResult result = runProcess(new ProcessBuilder( "git", "clone", "--quiet", root.toString(), destination.toString()), 60); @@ -215,23 +254,38 @@ class ShadowV3OperationsPackageTest { for (String argument : arguments) { command.append(' ').append(quote(argument)); } - ProcessBuilder builder = new ProcessBuilder("cmd.exe", "/d", "/c", command.toString()); + Path restored = Files.createTempFile(tempDir, "caller-directory-", ".txt"); + Path wrapper = Files.createTempFile(tempDir, "caller-", ".cmd"); + boolean exportScript = script.getFileName().toString().equals("shadow-v3-export.cmd"); + Path callerDirectory = exportScript ? root : tempDir; + Files.writeString(wrapper, "@echo off\r\n" + + (exportScript ? "pushd " + quote(root.toString()) + "\r\n" : "") + + command + "\r\nset \"RESULT=%errorlevel%\"\r\n" + + "cd > " + quote(restored.toString()) + "\r\n" + + (exportScript ? "popd\r\n" : "") + "exit /b %RESULT%\r\n"); + ProcessBuilder builder = new ProcessBuilder("cmd.exe", "/d", "/c", "call " + quote(wrapper.toString())); + builder.directory(tempDir.toFile()); String inheritedPath = builder.environment().getOrDefault("PATH", ""); builder.environment().put("PATH", stubBin + File.pathSeparator + inheritedPath); builder.environment().put("FORTUCKY_ALGORITHM_WAREHOUSE_ID", "01"); builder.redirectErrorStream(true); - return runProcess(builder, 15); + CmdResult result = runProcess(builder, 15); + assertThat(Path.of(Files.readString(restored).trim())).isEqualTo(callerDirectory); + return result; } private CmdResult runProcess(ProcessBuilder builder, int timeoutSeconds) throws Exception { builder.redirectErrorStream(true); + Path capturedOutput = Files.createTempFile(tempDir, "process-output-", ".txt"); + builder.redirectOutput(capturedOutput.toFile()); Process process = builder.start(); boolean finished = process.waitFor(timeoutSeconds, TimeUnit.SECONDS); if (!finished) { - process.destroyForcibly(); + process.descendants().forEach(ProcessHandle::destroyForcibly); + process.destroyForcibly().waitFor(5, TimeUnit.SECONDS); } - assertThat(finished).as("CMD script completed").isTrue(); - String output = new String(process.getInputStream().readAllBytes(), StandardCharsets.UTF_8); + String output = new String(Files.readAllBytes(capturedOutput), StandardCharsets.UTF_8); + assertThat(finished).as("CMD script completed: %s", output).isTrue(); return new CmdResult(process.exitValue(), output); } diff --git a/ruoyi-admin/src/test/resources/shadow/Sqlcmd13OutputFixture.cs b/ruoyi-admin/src/test/resources/shadow/Sqlcmd13OutputFixture.cs new file mode 100644 index 0000000..c166fc4 --- /dev/null +++ b/ruoyi-admin/src/test/resources/shadow/Sqlcmd13OutputFixture.cs @@ -0,0 +1,32 @@ +using System; +using System.IO; + +// No SQL execution. Model sqlcmd 13's literal :out paths at the process boundary. +class Sqlcmd13OutputFixture +{ + static int Main(string[] args) + { + if (Path.GetFileNameWithoutExtension(Environment.GetCommandLineArgs()[0]) == "jps") + { + Console.WriteLine("123 sun.tools.jps.Jps -lv"); + return 0; + } + int input = Array.IndexOf(args, "-i"); + if (input < 0) return 86; + foreach (string line in File.ReadAllLines(args[input + 1])) + { + if (!line.StartsWith(":out ")) continue; + string destination = line.Substring(5).Trim().Trim('"'); + if (destination == "stdout") continue; + if (destination.Contains("$(")) + { + Console.Error.WriteLine("sqlcmd13 cannot expand :out destination: " + destination); + return 13; + } + File.WriteAllText(destination, "read-only SQL output fixture\r\n"); + } + File.WriteAllText("sqlcmd-cwd.txt", Environment.CurrentDirectory); + Console.WriteLine("EXPORT_SQL_OK"); + return 0; + } +} diff --git a/scripts/shadow-v3-export.cmd b/scripts/shadow-v3-export.cmd index 39ab4cb..0e01ba6 100644 --- a/scripts/shadow-v3-export.cmd +++ b/scripts/shadow-v3-export.cmd @@ -1,5 +1,6 @@ @echo off setlocal EnableExtensions DisableDelayedExpansion +set "PUSHD_ACTIVE=0" if "%~1"=="" goto :usage if "%~2"=="" goto :usage @@ -41,15 +42,20 @@ if exist "%OUTPUT_DIR%" ( pushd "%REPO_ROOT%" >nul if errorlevel 1 (call :fail "cannot enter REPO_ROOT" & exit /b 1) +set "PUSHD_ACTIVE=1" ( - echo export_started_utc=%DATE% %TIME% + echo export_started_local=%DATE% %TIME% echo expected_branch=test/ft546wms-shadow-v3-20260903 - git branch --show-current - git rev-parse HEAD - git status --porcelain ) > "%OUTPUT_DIR%\deployment.txt" 2>&1 +if errorlevel 1 (call :fail "cannot create deployment evidence" & exit /b 1) +git branch --show-current >> "%OUTPUT_DIR%\deployment.txt" 2>&1 +if errorlevel 1 (call :fail "cannot collect Git branch evidence" & exit /b 1) +git rev-parse HEAD >> "%OUTPUT_DIR%\deployment.txt" 2>&1 +if errorlevel 1 (call :fail "cannot collect Git commit evidence" & exit /b 1) +git status --porcelain >> "%OUTPUT_DIR%\deployment.txt" 2>&1 if errorlevel 1 (call :fail "cannot collect Git deployment evidence" & exit /b 1) popd >nul +set "PUSHD_ACTIVE=0" jps -lv > "%OUTPUT_DIR%\runtime-processes.txt" 2>&1 if errorlevel 1 (call :fail "cannot collect JVM process evidence" & exit /b 1) @@ -61,8 +67,14 @@ if errorlevel 1 (call :fail "cannot collect environment variable evidence" & exi call :require_output "environment-variable-names.txt" if errorlevel 1 exit /b 1 -sqlcmd -S "%SQL_SERVER%" -d "%DATABASE%" -E -b -r1 -w 65535 -y 0 -Y 0 -v WarehouseId="%WAREHOUSE_ID%" StartUtc="%START_UTC%" OutputDir="%OUTPUT_DIR%" -i "%SQL_FILE%" +rem sqlcmd 13 does not reliably expand variables in :out paths. Use literal names under OUTPUT_DIR. +pushd "%OUTPUT_DIR%" >nul +if errorlevel 1 (call :fail "cannot enter OUTPUT_DIR" & exit /b 1) +set "PUSHD_ACTIVE=1" +sqlcmd -S "%SQL_SERVER%" -d "%DATABASE%" -E -b -r1 -w 65535 -y 0 -Y 0 -v WarehouseId="%WAREHOUSE_ID%" StartUtc="%START_UTC%" -i "%SQL_FILE%" if errorlevel 1 (call :fail "read-only SQL export failed" & exit /b 1) +popd >nul +set "PUSHD_ACTIVE=0" set "LOG_CANDIDATE=" for /f "delims=" %%L in ('dir /s /b "%LOG_DIR%\*.log" "%LOG_DIR%\*.txt" 2^>nul') do set "LOG_CANDIDATE=%%L" @@ -82,6 +94,7 @@ call :require_output "shadow-warnings.txt" if errorlevel 1 exit /b 1 echo EXPORT_OK output=%OUTPUT_DIR% +echo EXPORT_OK means files were collected, not approval to switch algorithms. exit /b 0 :require_output @@ -94,5 +107,6 @@ exit /b 2 :fail echo EXPORT_FAILED %~1 1>&2 -popd >nul 2>nul +if "%PUSHD_ACTIVE%"=="1" popd >nul 2>nul +set "PUSHD_ACTIVE=0" exit /b 1 diff --git a/scripts/shadow-v3-export.sql b/scripts/shadow-v3-export.sql index ec48586..99ba0bf 100644 --- a/scripts/shadow-v3-export.sql +++ b/scripts/shadow-v3-export.sql @@ -1,6 +1,7 @@ :on error exit -:out "$(OutputDir)\sql-diagnostics.txt" +-- Run via shadow-v3-export.cmd: literal output names are relative to its OUTPUT_DIR. +:out "sql-diagnostics.txt" SET NOCOUNT ON; SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED; @@ -73,7 +74,7 @@ WHERE request.database_id = DB_ID() ORDER BY request.session_id; GO -:out "$(OutputDir)\comparison-detail.txt" +:out "comparison-detail.txt" SET NOCOUNT ON; SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED; @@ -108,19 +109,23 @@ WHERE warehouse_id = '$(WarehouseId)' AND created_at >= CONVERT(datetime2(3), '$(StartUtc)', 127) ORDER BY created_at, decision_id; -SELECT SUM(CASE WHEN decision_type = 'INBOUND' THEN 1 ELSE 0 END) AS inbound_plan_count, - SUM(CASE WHEN decision_type = 'INBOUND_COMPARE' THEN 1 ELSE 0 END) AS inbound_compare_count, - SUM(CASE WHEN decision_type = 'OUTBOUND' THEN 1 ELSE 0 END) AS outbound_plan_count, - SUM(CASE WHEN decision_type = 'OUTBOUND_COMPARE' THEN 1 ELSE 0 END) AS outbound_compare_count +SELECT COUNT_BIG(CASE WHEN decision_type = 'INBOUND' THEN 1 END) AS inbound_plan_count, + COUNT_BIG(CASE WHEN decision_type = 'INBOUND_COMPARE' THEN 1 END) AS inbound_compare_count, + COUNT_BIG(CASE WHEN decision_type = 'OUTBOUND' THEN 1 END) AS outbound_plan_count, + COUNT_BIG(CASE WHEN decision_type = 'OUTBOUND_COMPARE' THEN 1 END) AS outbound_compare_count, + CASE WHEN COUNT_BIG(CASE WHEN decision_type IN ('INBOUND_COMPARE', 'OUTBOUND_COMPARE') THEN 1 END) = 0 + THEN 'NO_COMPARISONS' ELSE 'COMPARISONS_PRESENT_NOT_APPROVED' END AS sample_status FROM alg.decision_log WHERE warehouse_id = '$(WarehouseId)' AND created_at >= CONVERT(datetime2(3), '$(StartUtc)', 127); GO -:out "$(OutputDir)\runtime-metrics.txt" +:out "runtime-metrics.txt" SET NOCOUNT ON; SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED; +SELECT 'Counters are cumulative, not filtered by StartUtc; pre-V3.2 flushed_at may use JVM local time until next flush.' AS metric_scope; + SELECT warehouse_id, metric_name, bucket_upper_micros, metric_count, metric_total_micros, metric_max_micros, flushed_at FROM alg.shadow_runtime_metric @@ -146,7 +151,7 @@ GROUP BY CASE ORDER BY metric_group; GO -:out "$(OutputDir)\inventory-parity.txt" +:out "inventory-parity.txt" SET NOCOUNT ON; SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;