ops_log_runtime_test.go 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607
  1. package service
  2. import (
  3. "context"
  4. "encoding/json"
  5. "errors"
  6. "testing"
  7. "github.com/Wei-Shaw/sub2api/internal/config"
  8. "github.com/Wei-Shaw/sub2api/internal/pkg/logger"
  9. )
  10. type runtimeSettingRepoStub struct {
  11. values map[string]string
  12. deleted map[string]bool
  13. setCalls int
  14. getValueCalls int
  15. getMultipleCalls int
  16. getValueFn func(key string) (string, error)
  17. setFn func(key, value string) error
  18. deleteFn func(key string) error
  19. }
  20. type runtimeCleanupReloader struct {
  21. calls int
  22. }
  23. func (r *runtimeCleanupReloader) Reload(context.Context) error {
  24. r.calls++
  25. return nil
  26. }
  27. func newRuntimeSettingRepoStub() *runtimeSettingRepoStub {
  28. return &runtimeSettingRepoStub{
  29. values: map[string]string{},
  30. deleted: map[string]bool{},
  31. }
  32. }
  33. func (s *runtimeSettingRepoStub) Get(ctx context.Context, key string) (*Setting, error) {
  34. value, err := s.GetValue(ctx, key)
  35. if err != nil {
  36. return nil, err
  37. }
  38. return &Setting{Key: key, Value: value}, nil
  39. }
  40. func (s *runtimeSettingRepoStub) GetValue(_ context.Context, key string) (string, error) {
  41. s.getValueCalls++
  42. if s.getValueFn != nil {
  43. return s.getValueFn(key)
  44. }
  45. value, ok := s.values[key]
  46. if !ok {
  47. return "", ErrSettingNotFound
  48. }
  49. return value, nil
  50. }
  51. func (s *runtimeSettingRepoStub) Set(_ context.Context, key, value string) error {
  52. if s.setFn != nil {
  53. if err := s.setFn(key, value); err != nil {
  54. return err
  55. }
  56. }
  57. s.values[key] = value
  58. s.setCalls++
  59. return nil
  60. }
  61. func (s *runtimeSettingRepoStub) GetMultiple(_ context.Context, keys []string) (map[string]string, error) {
  62. s.getMultipleCalls++
  63. out := make(map[string]string, len(keys))
  64. for _, key := range keys {
  65. if value, ok := s.values[key]; ok {
  66. out[key] = value
  67. }
  68. }
  69. return out, nil
  70. }
  71. func (s *runtimeSettingRepoStub) SetMultiple(_ context.Context, settings map[string]string) error {
  72. for key, value := range settings {
  73. s.values[key] = value
  74. }
  75. return nil
  76. }
  77. func (s *runtimeSettingRepoStub) GetAll(_ context.Context) (map[string]string, error) {
  78. out := make(map[string]string, len(s.values))
  79. for key, value := range s.values {
  80. out[key] = value
  81. }
  82. return out, nil
  83. }
  84. func (s *runtimeSettingRepoStub) Delete(_ context.Context, key string) error {
  85. if s.deleteFn != nil {
  86. if err := s.deleteFn(key); err != nil {
  87. return err
  88. }
  89. }
  90. if _, ok := s.values[key]; !ok {
  91. return ErrSettingNotFound
  92. }
  93. delete(s.values, key)
  94. s.deleted[key] = true
  95. return nil
  96. }
  97. func TestUpdateRuntimeLogConfig_InvalidConfigShouldNotApply(t *testing.T) {
  98. repo := newRuntimeSettingRepoStub()
  99. svc := &OpsService{
  100. settingRepo: repo,
  101. cfg: &config.Config{
  102. Log: config.LogConfig{
  103. Level: "info",
  104. Caller: true,
  105. StacktraceLevel: "error",
  106. Sampling: config.LogSamplingConfig{
  107. Enabled: false,
  108. Initial: 100,
  109. Thereafter: 100,
  110. },
  111. },
  112. },
  113. }
  114. if err := logger.Init(logger.InitOptions{
  115. Level: "info",
  116. Format: "json",
  117. ServiceName: "sub2api",
  118. Environment: "test",
  119. Output: logger.OutputOptions{
  120. ToStdout: true,
  121. ToFile: false,
  122. },
  123. }); err != nil {
  124. t.Fatalf("init logger: %v", err)
  125. }
  126. _, err := svc.UpdateRuntimeLogConfig(context.Background(), &OpsRuntimeLogConfig{
  127. Level: "trace",
  128. EnableSampling: true,
  129. SamplingInitial: 100,
  130. SamplingNext: 100,
  131. Caller: true,
  132. StacktraceLevel: "error",
  133. RetentionDays: 30,
  134. }, 1)
  135. if err == nil {
  136. t.Fatalf("expected validation error")
  137. }
  138. if logger.CurrentLevel() != "info" {
  139. t.Fatalf("logger level changed unexpectedly: %s", logger.CurrentLevel())
  140. }
  141. if repo.setCalls != 1 {
  142. // GetRuntimeLogConfig() 会在 key 缺失时写入默认值,此处应只有这一次持久化。
  143. t.Fatalf("unexpected set calls: %d", repo.setCalls)
  144. }
  145. }
  146. func TestResetRuntimeLogConfig_ShouldFallbackToBaseline(t *testing.T) {
  147. repo := newRuntimeSettingRepoStub()
  148. existing := &OpsRuntimeLogConfig{
  149. Level: "debug",
  150. EnableSampling: true,
  151. SamplingInitial: 50,
  152. SamplingNext: 50,
  153. Caller: true,
  154. StacktraceLevel: "error",
  155. RetentionDays: 60,
  156. Source: "runtime_setting",
  157. }
  158. raw, _ := json.Marshal(existing)
  159. repo.values[SettingKeyOpsRuntimeLogConfig] = string(raw)
  160. svc := &OpsService{
  161. settingRepo: repo,
  162. cfg: &config.Config{
  163. Log: config.LogConfig{
  164. Level: "warn",
  165. Caller: false,
  166. StacktraceLevel: "fatal",
  167. Sampling: config.LogSamplingConfig{
  168. Enabled: false,
  169. Initial: 100,
  170. Thereafter: 100,
  171. },
  172. },
  173. Ops: config.OpsConfig{
  174. Cleanup: config.OpsCleanupConfig{
  175. ErrorLogRetentionDays: 7,
  176. SystemLogRetentionDays: 45,
  177. },
  178. },
  179. },
  180. }
  181. if err := logger.Init(logger.InitOptions{
  182. Level: "debug",
  183. Format: "json",
  184. ServiceName: "sub2api",
  185. Environment: "test",
  186. Output: logger.OutputOptions{
  187. ToStdout: true,
  188. ToFile: false,
  189. },
  190. }); err != nil {
  191. t.Fatalf("init logger: %v", err)
  192. }
  193. resetCfg, err := svc.ResetRuntimeLogConfig(context.Background(), 9)
  194. if err != nil {
  195. t.Fatalf("ResetRuntimeLogConfig() error: %v", err)
  196. }
  197. if resetCfg.Source != "baseline" {
  198. t.Fatalf("source = %q, want baseline", resetCfg.Source)
  199. }
  200. if resetCfg.Level != "warn" {
  201. t.Fatalf("level = %q, want warn", resetCfg.Level)
  202. }
  203. if resetCfg.RetentionDays != 45 {
  204. t.Fatalf("retention_days = %d, want 45", resetCfg.RetentionDays)
  205. }
  206. if logger.CurrentLevel() != "warn" {
  207. t.Fatalf("logger level = %q, want warn", logger.CurrentLevel())
  208. }
  209. if !repo.deleted[SettingKeyOpsRuntimeLogConfig] {
  210. t.Fatalf("runtime setting key should be deleted")
  211. }
  212. }
  213. func TestResetRuntimeLogConfig_InvalidOperator(t *testing.T) {
  214. svc := &OpsService{settingRepo: newRuntimeSettingRepoStub()}
  215. _, err := svc.ResetRuntimeLogConfig(context.Background(), 0)
  216. if err == nil {
  217. t.Fatalf("expected invalid operator error")
  218. }
  219. if err.Error() != "invalid operator id" {
  220. t.Fatalf("unexpected error: %v", err)
  221. }
  222. }
  223. func TestGetRuntimeLogConfig_InvalidJSONFallback(t *testing.T) {
  224. repo := newRuntimeSettingRepoStub()
  225. repo.values[SettingKeyOpsRuntimeLogConfig] = `{invalid-json}`
  226. svc := &OpsService{
  227. settingRepo: repo,
  228. cfg: &config.Config{
  229. Log: config.LogConfig{
  230. Level: "warn",
  231. Caller: true,
  232. StacktraceLevel: "error",
  233. Sampling: config.LogSamplingConfig{
  234. Enabled: false,
  235. Initial: 100,
  236. Thereafter: 100,
  237. },
  238. },
  239. },
  240. }
  241. got, err := svc.GetRuntimeLogConfig(context.Background())
  242. if err != nil {
  243. t.Fatalf("GetRuntimeLogConfig() error: %v", err)
  244. }
  245. if got.Level != "warn" {
  246. t.Fatalf("level = %q, want warn", got.Level)
  247. }
  248. }
  249. func TestUpdateRuntimeLogConfig_PersistFailureRollback(t *testing.T) {
  250. repo := newRuntimeSettingRepoStub()
  251. oldCfg := &OpsRuntimeLogConfig{
  252. Level: "info",
  253. EnableSampling: false,
  254. SamplingInitial: 100,
  255. SamplingNext: 100,
  256. Caller: true,
  257. StacktraceLevel: "error",
  258. RetentionDays: 30,
  259. }
  260. raw, _ := json.Marshal(oldCfg)
  261. repo.values[SettingKeyOpsRuntimeLogConfig] = string(raw)
  262. repo.setFn = func(key, value string) error {
  263. if key == SettingKeyOpsRuntimeLogConfig {
  264. return errors.New("db down")
  265. }
  266. return nil
  267. }
  268. svc := &OpsService{
  269. settingRepo: repo,
  270. systemLogSink: &OpsSystemLogSink{},
  271. cfg: &config.Config{
  272. Log: config.LogConfig{
  273. Level: "info",
  274. Caller: true,
  275. StacktraceLevel: "error",
  276. Sampling: config.LogSamplingConfig{
  277. Enabled: false,
  278. Initial: 100,
  279. Thereafter: 100,
  280. },
  281. },
  282. },
  283. }
  284. if err := logger.Init(logger.InitOptions{
  285. Level: "info",
  286. Format: "json",
  287. ServiceName: "sub2api",
  288. Environment: "test",
  289. Output: logger.OutputOptions{
  290. ToStdout: true,
  291. ToFile: false,
  292. },
  293. }); err != nil {
  294. t.Fatalf("init logger: %v", err)
  295. }
  296. _, err := svc.UpdateRuntimeLogConfig(context.Background(), &OpsRuntimeLogConfig{
  297. Level: "debug",
  298. PersistAccessLogs: true,
  299. EnableSampling: false,
  300. SamplingInitial: 100,
  301. SamplingNext: 100,
  302. Caller: true,
  303. StacktraceLevel: "error",
  304. RetentionDays: 30,
  305. }, 5)
  306. if err == nil {
  307. t.Fatalf("expected persist error")
  308. }
  309. // Persist failure should rollback runtime level back to old effective level.
  310. if logger.CurrentLevel() != "info" {
  311. t.Fatalf("logger level should rollback to info, got %s", logger.CurrentLevel())
  312. }
  313. if svc.systemLogSink.persistAccessLogs.Load() {
  314. t.Fatal("access-log persistence should rollback after setting write failure")
  315. }
  316. }
  317. func TestApplyRuntimeLogConfigOnStartup(t *testing.T) {
  318. repo := newRuntimeSettingRepoStub()
  319. cfgRaw := `{"level":"debug","persist_access_logs":true,"enable_sampling":false,"sampling_initial":100,"sampling_thereafter":100,"caller":true,"stacktrace_level":"error","retention_days":30}`
  320. repo.values[SettingKeyOpsRuntimeLogConfig] = cfgRaw
  321. svc := &OpsService{
  322. settingRepo: repo,
  323. systemLogSink: &OpsSystemLogSink{},
  324. cfg: &config.Config{
  325. Log: config.LogConfig{
  326. Level: "info",
  327. Caller: true,
  328. StacktraceLevel: "error",
  329. Sampling: config.LogSamplingConfig{
  330. Enabled: false,
  331. Initial: 100,
  332. Thereafter: 100,
  333. },
  334. },
  335. },
  336. }
  337. if err := logger.Init(logger.InitOptions{
  338. Level: "info",
  339. Format: "json",
  340. ServiceName: "sub2api",
  341. Environment: "test",
  342. Output: logger.OutputOptions{
  343. ToStdout: true,
  344. ToFile: false,
  345. },
  346. }); err != nil {
  347. t.Fatalf("init logger: %v", err)
  348. }
  349. svc.applyRuntimeLogConfigOnStartup(context.Background())
  350. if logger.CurrentLevel() != "debug" {
  351. t.Fatalf("expected startup apply debug, got %s", logger.CurrentLevel())
  352. }
  353. if !svc.systemLogSink.persistAccessLogs.Load() {
  354. t.Fatal("startup config did not enable access-log persistence")
  355. }
  356. }
  357. func TestDefaultNormalizeAndValidateRuntimeLogConfig(t *testing.T) {
  358. defaults := defaultOpsRuntimeLogConfig(&config.Config{
  359. Log: config.LogConfig{
  360. Level: "DEBUG",
  361. Caller: false,
  362. StacktraceLevel: "FATAL",
  363. Sampling: config.LogSamplingConfig{
  364. Enabled: true,
  365. Initial: 50,
  366. Thereafter: 20,
  367. },
  368. },
  369. Ops: config.OpsConfig{
  370. Cleanup: config.OpsCleanupConfig{
  371. ErrorLogRetentionDays: 7,
  372. SystemLogRetentionDays: 14,
  373. },
  374. },
  375. })
  376. if defaults.Level != "debug" || defaults.StacktraceLevel != "fatal" || defaults.RetentionDays != 14 {
  377. t.Fatalf("unexpected defaults: %+v", defaults)
  378. }
  379. if defaults.PersistAccessLogs {
  380. t.Fatal("access-log persistence should be disabled by default")
  381. }
  382. cfg := &OpsRuntimeLogConfig{
  383. Level: " ",
  384. EnableSampling: true,
  385. SamplingInitial: 0,
  386. SamplingNext: -1,
  387. Caller: true,
  388. StacktraceLevel: "",
  389. RetentionDays: 0,
  390. }
  391. normalizeOpsRuntimeLogConfig(cfg, defaults)
  392. if cfg.Level != "debug" || cfg.StacktraceLevel != "fatal" {
  393. t.Fatalf("normalize level/stacktrace failed: %+v", cfg)
  394. }
  395. if cfg.SamplingInitial != 50 || cfg.SamplingNext != 20 || cfg.RetentionDays != 14 {
  396. t.Fatalf("normalize numeric defaults failed: %+v", cfg)
  397. }
  398. if err := validateOpsRuntimeLogConfig(cfg); err != nil {
  399. t.Fatalf("validate normalized config should pass: %v", err)
  400. }
  401. }
  402. func TestValidateRuntimeLogConfigErrors(t *testing.T) {
  403. cases := []struct {
  404. name string
  405. cfg *OpsRuntimeLogConfig
  406. }{
  407. {name: "nil", cfg: nil},
  408. {name: "bad level", cfg: &OpsRuntimeLogConfig{Level: "trace", StacktraceLevel: "error", SamplingInitial: 1, SamplingNext: 1, RetentionDays: 1}},
  409. {name: "bad stack", cfg: &OpsRuntimeLogConfig{Level: "info", StacktraceLevel: "warn", SamplingInitial: 1, SamplingNext: 1, RetentionDays: 1}},
  410. {name: "bad initial", cfg: &OpsRuntimeLogConfig{Level: "info", StacktraceLevel: "error", SamplingInitial: 0, SamplingNext: 1, RetentionDays: 1}},
  411. {name: "bad next", cfg: &OpsRuntimeLogConfig{Level: "info", StacktraceLevel: "error", SamplingInitial: 1, SamplingNext: 0, RetentionDays: 1}},
  412. {name: "bad retention", cfg: &OpsRuntimeLogConfig{Level: "info", StacktraceLevel: "error", SamplingInitial: 1, SamplingNext: 1, RetentionDays: 0}},
  413. }
  414. for _, tc := range cases {
  415. t.Run(tc.name, func(t *testing.T) {
  416. if err := validateOpsRuntimeLogConfig(tc.cfg); err == nil {
  417. t.Fatalf("expected validation error")
  418. }
  419. })
  420. }
  421. }
  422. func TestGetRuntimeLogConfigFallbackAndErrors(t *testing.T) {
  423. var nilSvc *OpsService
  424. cfg, err := nilSvc.GetRuntimeLogConfig(context.Background())
  425. if err != nil {
  426. t.Fatalf("nil svc should fallback default: %v", err)
  427. }
  428. if cfg.Level != "info" {
  429. t.Fatalf("unexpected nil svc default level: %s", cfg.Level)
  430. }
  431. repo := newRuntimeSettingRepoStub()
  432. repo.getValueFn = func(key string) (string, error) {
  433. return "", errors.New("boom")
  434. }
  435. svc := &OpsService{
  436. settingRepo: repo,
  437. cfg: &config.Config{
  438. Log: config.LogConfig{
  439. Level: "warn",
  440. Caller: true,
  441. StacktraceLevel: "error",
  442. Sampling: config.LogSamplingConfig{
  443. Enabled: false,
  444. Initial: 100,
  445. Thereafter: 100,
  446. },
  447. },
  448. },
  449. }
  450. if _, err := svc.GetRuntimeLogConfig(context.Background()); err == nil {
  451. t.Fatalf("expected get value error")
  452. }
  453. }
  454. func TestUpdateRuntimeLogConfig_PreconditionErrors(t *testing.T) {
  455. svc := &OpsService{}
  456. if _, err := svc.UpdateRuntimeLogConfig(context.Background(), &OpsRuntimeLogConfig{}, 1); err == nil {
  457. t.Fatalf("expected setting repo not initialized")
  458. }
  459. svc = &OpsService{settingRepo: newRuntimeSettingRepoStub()}
  460. if _, err := svc.UpdateRuntimeLogConfig(context.Background(), nil, 1); err == nil {
  461. t.Fatalf("expected invalid config")
  462. }
  463. if _, err := svc.UpdateRuntimeLogConfig(context.Background(), &OpsRuntimeLogConfig{
  464. Level: "info",
  465. StacktraceLevel: "error",
  466. SamplingInitial: 1,
  467. SamplingNext: 1,
  468. RetentionDays: 1,
  469. }, 0); err == nil {
  470. t.Fatalf("expected invalid operator")
  471. }
  472. }
  473. func TestUpdateRuntimeLogConfig_Success(t *testing.T) {
  474. repo := newRuntimeSettingRepoStub()
  475. reloader := &runtimeCleanupReloader{}
  476. svc := &OpsService{
  477. settingRepo: repo,
  478. systemLogSink: &OpsSystemLogSink{},
  479. cleanupReloader: reloader,
  480. cfg: &config.Config{
  481. Log: config.LogConfig{
  482. Level: "info",
  483. Caller: true,
  484. StacktraceLevel: "error",
  485. Sampling: config.LogSamplingConfig{
  486. Enabled: false,
  487. Initial: 100,
  488. Thereafter: 100,
  489. },
  490. },
  491. },
  492. }
  493. if err := logger.Init(logger.InitOptions{
  494. Level: "info",
  495. Format: "json",
  496. ServiceName: "sub2api",
  497. Environment: "test",
  498. Output: logger.OutputOptions{
  499. ToStdout: true,
  500. ToFile: false,
  501. },
  502. }); err != nil {
  503. t.Fatalf("init logger: %v", err)
  504. }
  505. next, err := svc.UpdateRuntimeLogConfig(context.Background(), &OpsRuntimeLogConfig{
  506. Level: "debug",
  507. PersistAccessLogs: true,
  508. EnableSampling: false,
  509. SamplingInitial: 100,
  510. SamplingNext: 100,
  511. Caller: true,
  512. StacktraceLevel: "error",
  513. RetentionDays: 30,
  514. }, 2)
  515. if err != nil {
  516. t.Fatalf("UpdateRuntimeLogConfig() error: %v", err)
  517. }
  518. if next.Source != "runtime_setting" || next.UpdatedByUserID != 2 || next.UpdatedAt == "" {
  519. t.Fatalf("unexpected metadata: %+v", next)
  520. }
  521. if logger.CurrentLevel() != "debug" {
  522. t.Fatalf("expected applied level debug, got %s", logger.CurrentLevel())
  523. }
  524. if !svc.systemLogSink.persistAccessLogs.Load() {
  525. t.Fatal("runtime update did not enable access-log persistence")
  526. }
  527. if reloader.calls != 1 {
  528. t.Fatalf("cleanup reload calls = %d, want 1", reloader.calls)
  529. }
  530. }
  531. func TestResetRuntimeLogConfig_IgnoreNotFoundDelete(t *testing.T) {
  532. repo := newRuntimeSettingRepoStub()
  533. repo.deleteFn = func(key string) error { return ErrSettingNotFound }
  534. svc := &OpsService{
  535. settingRepo: repo,
  536. cfg: &config.Config{
  537. Log: config.LogConfig{
  538. Level: "info",
  539. Caller: true,
  540. StacktraceLevel: "error",
  541. Sampling: config.LogSamplingConfig{
  542. Enabled: false,
  543. Initial: 100,
  544. Thereafter: 100,
  545. },
  546. },
  547. },
  548. }
  549. if _, err := svc.ResetRuntimeLogConfig(context.Background(), 1); err != nil {
  550. t.Fatalf("reset should ignore ErrSettingNotFound: %v", err)
  551. }
  552. }
  553. func TestApplyRuntimeLogConfigHelpers(t *testing.T) {
  554. if err := applyOpsRuntimeLogConfig(nil); err == nil {
  555. t.Fatalf("expected nil config error")
  556. }
  557. normalizeOpsRuntimeLogConfig(nil, &OpsRuntimeLogConfig{Level: "info"})
  558. normalizeOpsRuntimeLogConfig(&OpsRuntimeLogConfig{Level: "debug"}, nil)
  559. var nilSvc *OpsService
  560. nilSvc.applyRuntimeLogConfigOnStartup(context.Background())
  561. }