fix(shadow): repair UTC sampling and persist v3 diagnostics
This commit is contained in:
81
doc/algorithm-shadow/SHADOW_V32_UPDATE.md
Normal file
81
doc/algorithm-shadow/SHADOW_V32_UPDATE.md
Normal file
@@ -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` 表,保留日志和影子数据用于排查。
|
||||
@@ -9,9 +9,9 @@
|
||||
- 仓库目录:C:\project\FT546WMS-SHANDOW
|
||||
- SQL Server:<SQL_SERVER>
|
||||
- 数据库:<DATABASE>
|
||||
- v3 测试开始 UTC:<V3_START_UTC,例如 2026-09-03T08:00:00>
|
||||
- 本次修复实际启动 UTC:<V3_START_UTC,例如 2026-09-07T02:00:00>
|
||||
- 应用日志目录:<LOG_DIR>
|
||||
- 输出目录:C:\project\FT546WMS-shadow-v3-export
|
||||
- 输出目录:C:\project\FT546WMS-shadow-v3-export(必须为空或不存在;重复导出用新的带时间目录)
|
||||
- 期望分支:test/ft546wms-shadow-v3-20260903
|
||||
- 期望提交:<V3_COMMIT>
|
||||
|
||||
@@ -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 "<SQL_SERVER>" "<DATABASE>" "<V3_START_UTC>" "C:\project\FT546WMS-shadow-v3-export" "<LOG_DIR>"
|
||||
|
||||
必须看到 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;未被新刷新更新的旧行仍可能是旧本地时间。不要清零计数、改写旧时间或自行得出性能无影响的结论。
|
||||
|
||||
不要在回复中粘贴环境变量值、数据库凭据或完整业务数据。不要压缩以外的改写;由现场人员把整个输出目录压缩后交给分析。
|
||||
```
|
||||
|
||||
@@ -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.
|
||||
@@ -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) {
|
||||
|
||||
@@ -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<Instant> {
|
||||
@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"));
|
||||
}
|
||||
}
|
||||
@@ -71,7 +71,28 @@
|
||||
</encoder>
|
||||
</appender>
|
||||
|
||||
<!-- 系统模块日志级别控制 -->
|
||||
<!-- Shadow diagnostics only; business appenders and their filters remain unchanged. -->
|
||||
<appender name="file_shadow" class="ch.qos.logback.core.rolling.RollingFileAppender">
|
||||
<file>${log.path}/shadow-diagnostics.log</file>
|
||||
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
|
||||
<fileNamePattern>${log.path}/shadow-diagnostics.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
|
||||
<maxFileSize>10MB</maxFileSize>
|
||||
<maxHistory>14</maxHistory>
|
||||
<totalSizeCap>100MB</totalSizeCap>
|
||||
</rollingPolicy>
|
||||
<encoder>
|
||||
<charset>UTF-8</charset>
|
||||
<pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC} [%thread] %-5level %logger - %msg%n</pattern>
|
||||
</encoder>
|
||||
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
|
||||
<level>WARN</level>
|
||||
</filter>
|
||||
</appender>
|
||||
<logger name="com.ruoyi.algorithm.shadow">
|
||||
<appender-ref ref="file_shadow"/>
|
||||
</logger>
|
||||
|
||||
<!-- 系统模块日志级别控制 -->
|
||||
<logger name="com.ruoyi" level="info" />
|
||||
<!-- Spring日志级别控制 -->
|
||||
<logger name="org.springframework" level="warn" />
|
||||
|
||||
@@ -89,8 +89,16 @@ PUBLIC "-//mybatis.org//DTD Mapper 3.0//EN"
|
||||
@instance_id = #{instanceId};
|
||||
</update>
|
||||
|
||||
<select id="selectPublishedSnapshot"
|
||||
resultType="com.ruoyi.algorithm.shadow.ShadowSnapshotDescriptor">
|
||||
<resultMap id="publishedSnapshot" type="com.ruoyi.algorithm.shadow.ShadowSnapshotDescriptor">
|
||||
<result property="snapshotGeneration" column="snapshotGeneration"/>
|
||||
<result property="warehouseId" column="warehouseId"/>
|
||||
<result property="snapshotStatus" column="snapshotStatus"/>
|
||||
<result property="synchronizedAt" column="synchronizedAt"
|
||||
typeHandler="com.ruoyi.algorithm.shadow.mapper.ShadowUtcInstantTypeHandler"/>
|
||||
<result property="sourceSignature" column="sourceSignature"/>
|
||||
</resultMap>
|
||||
|
||||
<select id="selectPublishedSnapshot" resultMap="publishedSnapshot">
|
||||
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}
|
||||
</insert>
|
||||
|
||||
@@ -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});
|
||||
</update>
|
||||
</mapper>
|
||||
|
||||
@@ -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");
|
||||
}
|
||||
}
|
||||
@@ -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<String>();
|
||||
var logThread = new java.util.concurrent.atomic.AtomicReference<String>();
|
||||
CountDownLatch warning = new CountDownLatch(1);
|
||||
var appender = new ch.qos.logback.core.AppenderBase<ch.qos.logback.classic.spi.ILoggingEvent>() {
|
||||
@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);
|
||||
|
||||
@@ -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)");
|
||||
|
||||
@@ -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<Instant> 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<String, Object> 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<Instant> 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<Integer> 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<LocalDateTime> boundTimestamps(Configuration configuration, String id,
|
||||
Map<String, Object> values) throws Exception {
|
||||
List<LocalDateTime> 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<Instant> snapshotHandler(Configuration configuration) {
|
||||
return (TypeHandler<Instant>) configuration.getMappedStatement(NAMESPACE + "selectPublishedSnapshot")
|
||||
.getResultMaps().get(0).getResultMappings().stream()
|
||||
.filter(mapping -> "synchronizedAt".equals(mapping.getProperty()))
|
||||
.<TypeHandler<?>>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<? extends Enum> jdbcType = (Class<? extends Enum>) Class.forName("com.microsoft.sqlserver.jdbc.JDBCType");
|
||||
Class<? extends Enum> sqlType = (Class<? extends Enum>) 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);
|
||||
}
|
||||
}
|
||||
@@ -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);
|
||||
}
|
||||
|
||||
|
||||
@@ -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;
|
||||
}
|
||||
}
|
||||
@@ -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
|
||||
|
||||
@@ -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;
|
||||
|
||||
|
||||
Reference in New Issue
Block a user