prompt_worker.go 12 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350
  1. package securityaudit
  2. import (
  3. "context"
  4. "errors"
  5. "sync"
  6. "sync/atomic"
  7. "time"
  8. )
  9. type WorkerRuntime struct {
  10. active atomic.Int64
  11. processed atomic.Int64
  12. failed atomic.Int64
  13. heartbeatNS atomic.Int64
  14. lastProcessedNS atomic.Int64
  15. lastErrorMu sync.RWMutex
  16. lastErrorCode string
  17. lastErrorMessage string
  18. }
  19. type Runner struct {
  20. config ConfigStore
  21. repo JobRepository
  22. payload PayloadStore
  23. scanner PromptScanner
  24. metrics Metrics
  25. clock Clock
  26. runtime WorkerRuntime
  27. mu sync.Mutex
  28. cancel context.CancelFunc
  29. wg sync.WaitGroup
  30. }
  31. func NewRunner(config ConfigStore, repo JobRepository, payload PayloadStore, scanner PromptScanner, metrics Metrics) *Runner {
  32. return &Runner{config: config, repo: repo, payload: payload, scanner: scanner, metrics: metrics, clock: realClock{}}
  33. }
  34. func (r *Runner) Start(ctx context.Context) error {
  35. if r == nil || r.config == nil || r.repo == nil || r.payload == nil || r.scanner == nil {
  36. return errors.New("prompt audit worker dependencies unavailable")
  37. }
  38. r.mu.Lock()
  39. if r.cancel != nil {
  40. r.mu.Unlock()
  41. return nil
  42. }
  43. runCtx, cancel := context.WithCancel(ctx)
  44. r.cancel = cancel
  45. r.mu.Unlock()
  46. if err := r.payload.Ping(runCtx); err != nil {
  47. r.setLastError("payload_store_unavailable", err.Error())
  48. }
  49. for workerID := 0; workerID < MaxWorkerCount; workerID++ {
  50. r.wg.Add(1)
  51. go r.worker(runCtx, workerID)
  52. }
  53. r.wg.Add(1)
  54. go r.reclaimer(runCtx)
  55. return nil
  56. }
  57. func (r *Runner) Shutdown(ctx context.Context) error {
  58. if r == nil {
  59. return nil
  60. }
  61. r.mu.Lock()
  62. cancel := r.cancel
  63. r.cancel = nil
  64. r.mu.Unlock()
  65. if cancel != nil {
  66. cancel()
  67. }
  68. done := make(chan struct{})
  69. go func() { r.wg.Wait(); close(done) }()
  70. select {
  71. case <-done:
  72. return nil
  73. case <-ctx.Done():
  74. LogWarn(EventProcessFailed, map[string]any{"status": "shutdown_timeout", "error_code": "worker_shutdown_timeout"})
  75. return ctx.Err()
  76. }
  77. }
  78. func (r *Runner) worker(ctx context.Context, workerID int) {
  79. defer r.wg.Done()
  80. ticker := time.NewTicker(500 * time.Millisecond)
  81. defer ticker.Stop()
  82. for {
  83. select {
  84. case <-ctx.Done():
  85. return
  86. case <-ticker.C:
  87. r.runtime.heartbeatNS.Store(r.clock.Now().UnixNano())
  88. cfg, ok := r.config.Active()
  89. if !ok || !cfg.RiskControlEnabled || !cfg.Enabled || workerID >= cfg.WorkerCount {
  90. continue
  91. }
  92. for {
  93. job, claimed, err := r.repo.ClaimNextJob(ctx, r.clock.Now())
  94. if err != nil {
  95. r.setLastError("claim_job_failed", err.Error())
  96. break
  97. }
  98. if !claimed {
  99. break
  100. }
  101. r.runtime.active.Add(1)
  102. r.processSafely(ctx, workerID, cfg, job)
  103. r.runtime.active.Add(-1)
  104. }
  105. }
  106. }
  107. }
  108. func (r *Runner) processSafely(ctx context.Context, workerID int, cfg ActiveConfig, job *Job) {
  109. defer func() {
  110. if recovered := recover(); recovered != nil {
  111. r.runtime.failed.Add(1)
  112. // Panic values may contain scanner response fragments or prompt data.
  113. // Keep only a stable generic message in runtime state and logs.
  114. r.setLastError("worker_panic", "worker panic recovered")
  115. _ = r.repo.Fail(ctx, job.ID, job.ClaimVersion, "worker_panic", "worker panic recovered")
  116. LogError(EventProcessFailed, mergeLogFields(jobLogFields(job), map[string]any{"worker_id": workerID, "status": "failed", "error_code": "worker_panic"}))
  117. }
  118. }()
  119. if err := r.processJob(ctx, workerID, cfg, job); err != nil {
  120. r.runtime.failed.Add(1)
  121. } else {
  122. r.runtime.processed.Add(1)
  123. r.runtime.lastProcessedNS.Store(r.clock.Now().UnixNano())
  124. }
  125. }
  126. func (r *Runner) processJob(ctx context.Context, workerID int, cfg ActiveConfig, job *Job) error {
  127. baseFields := jobLogFields(job)
  128. LogInfo(EventAuditStarted, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "attempts": job.Attempts, "status": "processing"}))
  129. scanText, err := r.payload.Get(ctx, job.ID)
  130. if err != nil {
  131. return r.finishFailure(ctx, job, &GuardError{Code: "payload_missing", Retryable: false, Cause: err})
  132. }
  133. // The job row only carries redacted metadata; the full prompt for the audit
  134. // event is reconstructed here from the transient scan payload.
  135. job.Snapshot.FullPrompt = FullPromptFromScanText(scanText)
  136. endpoints := cfg.EnabledEndpoints()
  137. if len(endpoints) == 0 {
  138. return r.finishFailure(ctx, job, &GuardError{Code: "no_enabled_endpoint", Retryable: true})
  139. }
  140. chunks := SplitRunes(scanText, minimumInputLimit(endpoints))
  141. results := make([]*NormalizedResult, 0, len(chunks))
  142. started := r.clock.Now()
  143. for index, chunk := range chunks {
  144. if err := r.repo.RefreshLease(ctx, job.ID, job.ClaimVersion, r.clock.Now()); err != nil {
  145. return err
  146. }
  147. chunkStarted := r.clock.Now()
  148. LogInfo(EventChunkStarted, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "chunk_index": index + 1, "chunk_total": len(chunks), "chunk_chars": len([]rune(chunk)), "input_chars": job.Snapshot.PromptLength, "input_limit": minimumInputLimit(endpoints), "status": "started"}))
  149. result, scanErr := scanWithFailover(ctx, r.scanner, cfg.Scanners, endpoints, chunk, r.metrics)
  150. if scanErr != nil {
  151. LogWarn(EventChunkFailed, mergeLogFields(baseFields, map[string]any{
  152. "worker_id": workerID, "chunk_index": index + 1, "chunk_total": len(chunks),
  153. "chunk_chars": len([]rune(chunk)), "input_chars": job.Snapshot.PromptLength,
  154. "input_limit": minimumInputLimit(endpoints), "latency_ms": r.clock.Now().Sub(chunkStarted).Milliseconds(),
  155. "error_code": guardErrorCode(scanErr), "status": "failed",
  156. }))
  157. r.observeAsyncFailure(scanErr, r.clock.Now().Sub(started))
  158. return r.finishFailure(ctx, job, scanErr)
  159. }
  160. results = append(results, result)
  161. LogInfo(EventChunkCompleted, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "chunk_index": index + 1, "chunk_total": len(chunks), "guard_endpoint_id": result.GuardEndpointID, "action": result.Action, "latency_ms": r.clock.Now().Sub(chunkStarted).Milliseconds(), "status": "completed"}))
  162. if result.Action == ActionBlock {
  163. break
  164. }
  165. }
  166. aggregated, err := AggregateResults(results, r.clock.Now().Sub(started))
  167. if err != nil {
  168. if r.metrics != nil {
  169. r.metrics.Observe(DecisionInvalid, r.clock.Now().Sub(started))
  170. }
  171. return r.finishFailure(ctx, job, &GuardError{Code: ErrorCodeInvalidResponse, Cause: err})
  172. }
  173. aggregated.ChunkTotal = len(chunks)
  174. if r.metrics != nil {
  175. r.metrics.Observe(decisionKindForResult(aggregated), r.clock.Now().Sub(started))
  176. }
  177. LogInfo(EventChunksAggregated, mergeLogFields(baseFields, map[string]any{
  178. "worker_id": workerID, "decision": aggregated.Decision, "risk_level": aggregated.RiskLevel,
  179. "action": aggregated.Action, "chunk_total": aggregated.ChunkTotal,
  180. "latency_ms": aggregated.LatencyMS, "guard_endpoint_id": aggregated.GuardEndpointID, "status": "completed",
  181. }))
  182. event, err := r.repo.Complete(ctx, job, aggregated, cfg.StorePassEvents)
  183. if err != nil {
  184. return err
  185. }
  186. if deleteErr := r.payload.Delete(ctx, job.ID); deleteErr != nil {
  187. LogWarn(EventProcessFailed, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "status": "payload_delete_deferred", "error_code": "payload_delete_failed"}))
  188. }
  189. LogInfo(EventProcessed, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "event_id": eventID(event), "decision": aggregated.Decision, "risk_level": aggregated.RiskLevel, "action": aggregated.Action, "guard_endpoint_id": aggregated.GuardEndpointID, "latency_ms": aggregated.LatencyMS, "status": "done"}))
  190. if event != nil && aggregated.Decision != EventPass {
  191. LogWarn(EventFindingRecorded, mergeLogFields(baseFields, map[string]any{"worker_id": workerID, "event_id": event.ID, "decision": aggregated.Decision, "risk_level": aggregated.RiskLevel, "action": aggregated.Action, "guard_endpoint_id": aggregated.GuardEndpointID, "status": "recorded"}))
  192. }
  193. return nil
  194. }
  195. func (r *Runner) observeAsyncFailure(err error, latency time.Duration) {
  196. if r == nil || r.metrics == nil {
  197. return
  198. }
  199. kind := DecisionUnavailable
  200. if guardErrorCode(err) == ErrorCodeInvalidResponse {
  201. kind = DecisionInvalid
  202. }
  203. r.metrics.Observe(kind, latency)
  204. var guardErr *GuardError
  205. if errors.As(err, &guardErr) && guardErr.Timeout {
  206. r.metrics.IncTimeout()
  207. }
  208. }
  209. func decisionKindForResult(result *NormalizedResult) DecisionKind {
  210. if result == nil {
  211. return DecisionInvalid
  212. }
  213. switch result.Action {
  214. case ActionBlock:
  215. return DecisionBlock
  216. case ActionWarn:
  217. return DecisionFlag
  218. default:
  219. return DecisionAllow
  220. }
  221. }
  222. func (r *Runner) finishFailure(ctx context.Context, job *Job, err error) error {
  223. baseFields := jobLogFields(job)
  224. code := guardErrorCode(err)
  225. retryable := false
  226. var guardErr *GuardError
  227. if errors.As(err, &guardErr) {
  228. retryable = guardErr.Retryable
  229. }
  230. if retryable && job.Attempts < job.MaxAttempts {
  231. next := r.clock.Now().Add(retryBackoff(job.Attempts))
  232. if updateErr := r.repo.Retry(ctx, job.ID, job.ClaimVersion, next, code, "prompt guard temporarily unavailable"); updateErr != nil {
  233. return updateErr
  234. }
  235. LogWarn(EventProcessFailed, mergeLogFields(baseFields, map[string]any{"attempts": job.Attempts, "max_attempts": job.MaxAttempts, "status": "retry", "error_code": code, "retryable": true}))
  236. } else {
  237. if updateErr := r.repo.Fail(ctx, job.ID, job.ClaimVersion, code, "prompt guard processing failed"); updateErr != nil {
  238. return updateErr
  239. }
  240. _ = r.payload.Delete(ctx, job.ID)
  241. LogError(EventProcessFailed, mergeLogFields(baseFields, map[string]any{"attempts": job.Attempts, "max_attempts": job.MaxAttempts, "status": "failed", "error_code": code, "retryable": false}))
  242. }
  243. r.setLastError(code, err.Error())
  244. return err
  245. }
  246. func (r *Runner) reclaimer(ctx context.Context) {
  247. defer r.wg.Done()
  248. ticker := time.NewTicker(time.Minute)
  249. defer ticker.Stop()
  250. for {
  251. select {
  252. case <-ctx.Done():
  253. return
  254. case <-ticker.C:
  255. now := r.clock.Now()
  256. count, err := r.repo.ReclaimStale(ctx, now.Add(-2*time.Minute), now.Add(-90*time.Second), 100)
  257. if err != nil {
  258. r.setLastError("reclaim_failed", err.Error())
  259. continue
  260. }
  261. if count > 0 {
  262. LogWarn(EventProcessingReclaimed, map[string]any{"reclaimed_total": count, "status": "reclaimed"})
  263. }
  264. }
  265. }
  266. }
  267. func (r *Runner) Snapshot() (active, processed, failed int64, heartbeat, lastProcessed *time.Time, code, message string) {
  268. if r == nil {
  269. return
  270. }
  271. active, processed, failed = r.runtime.active.Load(), r.runtime.processed.Load(), r.runtime.failed.Load()
  272. if ns := r.runtime.heartbeatNS.Load(); ns > 0 {
  273. value := time.Unix(0, ns).UTC()
  274. heartbeat = &value
  275. }
  276. if ns := r.runtime.lastProcessedNS.Load(); ns > 0 {
  277. value := time.Unix(0, ns).UTC()
  278. lastProcessed = &value
  279. }
  280. r.runtime.lastErrorMu.RLock()
  281. code, message = r.runtime.lastErrorCode, r.runtime.lastErrorMessage
  282. r.runtime.lastErrorMu.RUnlock()
  283. return
  284. }
  285. func (r *Runner) setLastError(code, _ string) {
  286. code, message := sanitizeStoredError(code)
  287. r.runtime.lastErrorMu.Lock()
  288. r.runtime.lastErrorCode = code
  289. r.runtime.lastErrorMessage = message
  290. r.runtime.lastErrorMu.Unlock()
  291. }
  292. func scanWithFailover(ctx context.Context, scanner PromptScanner, scanners []string, endpoints []ActiveEndpoint, chunk string, metrics Metrics) (*NormalizedResult, error) {
  293. var lastErr error
  294. for index, endpoint := range endpoints {
  295. result, err := scanner.Scan(ctx, endpoint, chunk, scanners)
  296. if err == nil && result != nil {
  297. return result, nil
  298. }
  299. if err == nil {
  300. err = &GuardError{Code: ErrorCodeInvalidResponse, Retryable: false}
  301. }
  302. lastErr = err
  303. var guardErr *GuardError
  304. if !errors.As(err, &guardErr) || !guardErr.Retryable {
  305. return nil, err
  306. }
  307. if index < len(endpoints)-1 && metrics != nil {
  308. metrics.IncFailover()
  309. }
  310. }
  311. if lastErr == nil {
  312. lastErr = &GuardError{Code: ErrorCodeUnavailable}
  313. }
  314. return nil, lastErr
  315. }
  316. func retryBackoff(attempt int) time.Duration {
  317. switch attempt {
  318. case 1:
  319. return 5 * time.Second
  320. case 2:
  321. return 30 * time.Second
  322. default:
  323. return 2 * time.Minute
  324. }
  325. }
  326. func eventID(event *Event) int64 {
  327. if event == nil {
  328. return 0
  329. }
  330. return event.ID
  331. }