search

xcherryio / sdk-go

Golang SDK for xCherry
Apache License 2.0
1 stars 0 forks source link

Fix flaky test `TestProcessIdReusePolicyAllowIfPreviousExitAbnormallyCase1` #27

Open longquanzheng opened 10 months ago

longquanzheng commented 10 months ago

Test log

2023-11-01T03:54:10.4353103Z === RUN   TestProcessIdReusePolicyAllowIfPreviousExitAbnormallyCase1
2023-11-01T03:54:10.4353857Z process id: test1698810828334177738
2023-11-01T03:54:10.4354989Z [GIN] 2023/11/01 - 03:53:48 | 200 |      43.801µs |             ::1 | POST     "/api/v1/xdb/worker/async-state/wait-until"
2023-11-01T03:54:10.4358212Z [GIN] 2023/11/01 - 03:53:48 | 200 |      59.001µs |             ::1 | POST     "/api/v1/xdb/worker/async-state/execute"
2023-11-01T03:54:10.4359548Z [GIN] 2023/11/01 - 03:53:48 | 200 |      54.401µs |             ::1 | POST     "/api/v1/xdb/worker/async-state/execute"
2023-11-01T03:54:10.4360890Z [GIN] 2023/11/01 - 03:53:48 | 200 |        35.9µs |             ::1 | POST     "/api/v1/xdb/worker/async-state/wait-until"
2023-11-01T03:54:10.4362252Z [GIN] 2023/11/01 - 03:53:48 | 200 |      53.901µs |             ::1 | POST     "/api/v1/xdb/worker/async-state/execute"
2023-11-01T03:54:10.4363615Z [GIN] 2023/11/01 - 03:53:49 | 200 |  1.000177261s |             ::1 | POST     "/api/v1/xdb/worker/async-state/execute"
2023-11-01T03:54:10.4364971Z [GIN] 2023/11/01 - 03:53:49 | 200 |  1.000832373s |             ::1 | POST     "/api/v1/xdb/worker/async-state/execute"
2023-11-01T03:54:10.4365819Z     io_process.go:143: 
2023-11-01T03:54:10.4366743Z            Error Trace:    /home/runner/work/xdb-golang-sdk/xdb-golang-sdk/integTests/basic/io_process.go:143
2023-11-01T03:54:10.4367635Z            Error:          Not equal: 
2023-11-01T03:54:10.4368099Z                            expected: "COMPLETED"
2023-11-01T03:54:10.4368600Z                            actual  : "RUNNING"
2023-11-01T03:54:10.4369039Z                            
2023-11-01T03:54:10.4369428Z                            Diff:
2023-11-01T03:54:10.4369854Z                            --- Expected
2023-11-01T03:54:10.4370262Z                            +++ Actual
2023-11-01T03:54:10.4370728Z                            @@ -1,2 +1,2 @@
2023-11-01T03:54:10.4371346Z                            -(xdbapi.ProcessStatus) (len=9) "COMPLETED"
2023-11-01T03:54:10.4371988Z                            +(xdbapi.ProcessStatus) (len=7) "RUNNING"
2023-11-01T03:54:10.4372528Z                             
2023-11-01T03:54:10.4373194Z            Test:           TestProcessIdReusePolicyAllowIfPreviousExitAbnormallyCase1
2023-11-01T03:54:10.4374403Z --- FAIL: TestProcessIdReusePolicyAllowIfPreviousExitAbnormallyCase1 (5.02s)

Server logs:

2023-11-01T03:54:10.6630635Z {"level":"debug","ts":"2023-11-01T03:53:48.333Z","msg":"responded StartProcess API request","service":"api","value":"{\"processExecutionId\":\"43234acb-786a-11ee-a2af-6045bd815517\"}","value":"null","logging-call-at":"gin_handler.go:53"}
2023-11-01T03:54:10.6635212Z {"level":"debug","ts":"2023-11-01T03:53:48.334Z","msg":"received StartProcess API request","service":"api","value":"{\"namespace\":\"default\",\"processId\":\"test1698810828334177738\",\"processStartConfig\":{\"timeoutSeconds\":0},\"processType\":\"basic.IOProcess\",\"startStateConfig\":{},\"startStateId\":\"basic.state1\",\"startStateInput\":{\"data\":\"124\",\"encoding\":\"golangJson\"},\"workerUrl\":\"http://localhost:8803\"}","logging-call-at":"gin_handler.go:51"}
2023-11-01T03:54:10.6639124Z {"level":"debug","ts":"2023-11-01T03:53:48.336Z","msg":"poll time succeeded","service":"async","shard":0,"value":"3","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6641498Z {"level":"debug","ts":"2023-11-01T03:53:48.336Z","msg":"start executing immediate task","service":"async","ID":"0-39","ImmediateTaskType":"WaitUntil","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6644150Z {"level":"debug","ts":"2023-11-01T03:53:48.336Z","msg":"start executing immediate task","service":"async","ID":"0-40","ImmediateTaskType":"Execute","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6646780Z {"level":"debug","ts":"2023-11-01T03:53:48.336Z","msg":"start executing immediate task","service":"async","ID":"0-41","ImmediateTaskType":"WaitUntil","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6649397Z {"level":"warn","ts":"2023-11-01T03:53:48.337Z","msg":"noop for immediate task ","service":"async","ID":"0xc000668840","value":"status Aborted","logging-call-at":"immediate_task_conrrent_processor.go:153"}
2023-11-01T03:54:10.6652215Z {"level":"debug","ts":"2023-11-01T03:53:48.342Z","msg":"responded StartProcess API request","service":"api","value":"{\"processExecutionId\":\"4323e6b8-786a-11ee-a2af-6045bd815517\"}","value":"null","logging-call-at":"gin_handler.go:53"}
2023-11-01T03:54:10.6654722Z {"level":"debug","ts":"2023-11-01T03:53:48.342Z","msg":"poll time succeeded","service":"async","shard":0,"value":"0","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6659355Z {"level":"debug","ts":"2023-11-01T03:53:48.342Z","msg":"received StartProcess API request","service":"api","value":"{\"namespace\":\"default\",\"processId\":\"test1698810828334177738\",\"processStartConfig\":{\"idReusePolicy\":\"ALLOW_IF_PREVIOUS_EXIT_ABNORMALLY\",\"timeoutSeconds\":0},\"processType\":\"basic.IOProcess\",\"startStateConfig\":{},\"startStateId\":\"basic.state1\",\"startStateInput\":{\"data\":\"123\",\"encoding\":\"golangJson\"},\"workerUrl\":\"http://localhost:8803\"}","logging-call-at":"gin_handler.go:51"}
2023-11-01T03:54:10.6664655Z {"level":"debug","ts":"2023-11-01T03:53:48.345Z","msg":"responded StartProcess API request","service":"api","value":"null","value":"{\"StatusCode\":409,\"Error\":{\"detail\":\"Process is already started, try use a different processId or a proper processIdReusePolicy\"}}","logging-call-at":"gin_handler.go:53"}
2023-11-01T03:54:10.6667579Z {"level":"debug","ts":"2023-11-01T03:53:48.346Z","msg":"poll time succeeded","service":"async","shard":0,"value":"1","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6669949Z {"level":"debug","ts":"2023-11-01T03:53:48.346Z","msg":"start executing immediate task","service":"async","ID":"0-42","ImmediateTaskType":"WaitUntil","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6672358Z {"level":"debug","ts":"2023-11-01T03:53:48.347Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6674559Z {"level":"debug","ts":"2023-11-01T03:53:48.348Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6676655Z {"level":"debug","ts":"2023-11-01T03:53:48.349Z","msg":"poll time succeeded","service":"async","shard":0,"value":"1","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6679105Z {"level":"debug","ts":"2023-11-01T03:53:48.349Z","msg":"start executing immediate task","service":"async","ID":"0-43","ImmediateTaskType":"Execute","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6681500Z {"level":"debug","ts":"2023-11-01T03:53:48.350Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6683683Z {"level":"debug","ts":"2023-11-01T03:53:48.354Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6685796Z {"level":"debug","ts":"2023-11-01T03:53:48.356Z","msg":"poll time succeeded","service":"async","shard":0,"value":"2","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6688134Z {"level":"debug","ts":"2023-11-01T03:53:48.356Z","msg":"start executing immediate task","service":"async","ID":"0-44","ImmediateTaskType":"Execute","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6690760Z {"level":"debug","ts":"2023-11-01T03:53:48.356Z","msg":"start executing immediate task","service":"async","ID":"0-46","ImmediateTaskType":"Execute","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6693079Z {"level":"debug","ts":"2023-11-01T03:53:48.357Z","msg":"poll time succeeded","service":"async","shard":0,"value":"0","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6695098Z {"level":"debug","ts":"2023-11-01T03:53:48.358Z","msg":"poll time succeeded","service":"async","shard":0,"value":"0","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6697218Z {"level":"debug","ts":"2023-11-01T03:53:48.364Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6699308Z {"level":"debug","ts":"2023-11-01T03:53:48.367Z","msg":"poll time succeeded","service":"async","shard":0,"value":"1","logging-call-at":"immediate_task_queue.go:159"}
2023-11-01T03:54:10.6701785Z {"level":"debug","ts":"2023-11-01T03:53:48.367Z","msg":"start executing immediate task","service":"async","ID":"0-47","ImmediateTaskType":"Execute","logging-call-at":"immediate_task_conrrent_processor.go:122"}
2023-11-01T03:54:10.6704170Z {"level":"debug","ts":"2023-11-01T03:53:49.358Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6706459Z {"level":"debug","ts":"2023-11-01T03:53:49.369Z","msg":"immediate task executed","service":"async","status":200,"logging-call-at":"immediate_task_conrrent_processor.go:486"}
2023-11-01T03:54:10.6709020Z {"level":"debug","ts":"2023-11-01T03:53:53.348Z","msg":"received DescribeProcess API request","service":"api","value":"{\"namespace\":\"default\",\"processId\":\"test1698810828334177738\"}","logging-call-at":"gin_handler.go:96"}
2023-11-01T03:54:10.6712885Z {"level":"debug","ts":"2023-11-01T03:53:53.349Z","msg":"responded DescribeProcess API request","service":"api","value":"{\"processExecutionId\":\"4323e6b8-786a-11ee-a2af-6045bd815517\",\"processType\":\"basic.IOProcess\",\"startTimestamp\":1698810828,\"status\":\"RUNNING\",\"workerUrl\":\"http://localhost:8803\"}","value":"null","logging-call-at":"gin_handler.go:98"}
2023-11-01T03:54:10.6718689Z {"level":"debug","ts":"2023-11-01T03:53:53.350Z","msg":"received StartProcess API request","service":"api","value":"{\"namespace\":\"default\",\"processId\":\"test1698810828334177738\",\"processStartConfig\":{\"idReusePolicy\":\"ALLOW_IF_PREVIOUS_EXIT_ABNORMALLY\",\"timeoutSeconds\":0},\"processType\":\"basic.IOProcess\",\"startStateConfig\":{},\"startStateId\":\"basic.state1\",\"startStateInput\":{\"data\":\"123\",\"encoding\":\"golangJson\"},\"workerUrl\":\"http://localhost:8803\"}","logging-call-at":"gin_handler.go:51"}