Closed github-actions[bot] closed 4 months ago
DST run failed for seed=3450, ticks=1000, scenario=lazy, store=postgres.
Seed
3450
Scenario
lazy
Store
postgres
Commit
1218336eca0e3e862d5f5c181b9f27dc9f4f7603
Command
go run ./... dst run --seed 3450 --ticks 1000 --scenario lazy --aio-store postgres
Logs
level=INFO msg=DST seed=3450 ticks=1000 reqsPerTick=1:25 dst="DST(ids=17, idempotencyKeys=8, headers=3, data=13, tags=20, searches=5)" system="System(api=API(size=360, subsystems=[]), aio=AIODST(subsystems=[store]), config=Config(cms=967, ncs=0, sbs=221, cbs=28, sbs=817))" level=INFO msg=DST t=0|999 tid=0 req="ReleaseLock(resourceId=13, executionId=15)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=0|999 tid=1 req="ReadPromise(id=5)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=0|999 tid=2 req="ReleaseLock(resourceId=5, executionId=16)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=0|999 tid=3 req="ReleaseLock(resourceId=2, executionId=8)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=0|999 tid=4 req="DeleteSchedule(id=2)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=1000|1999 tid=6 req="ReleaseLock(resourceId=12, executionId=7)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=1000|1999 tid=7 req="HeartbeatLocks(processId=16)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=1000|1999 tid=8 req="ReleaseLock(resourceId=0, executionId=6)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=1000|1999 tid=9 req="SearchSchedules(id=4*, tags=map[], limit=6, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=1000|1999 tid=10 req="ReadSchedule(id=2)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=1000|1999 tid=12 req="DeleteSchedule(id=5)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=1000|1999 tid=13 req="DeleteSchedule(id=4)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=1000|1999 tid=14 req="HeartbeatLocks(processId=14)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=1000|1999 tid=15 req="ReadPromise(id=11)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=0|1999 tid=5 req="CreatePromise(id=2, idempotencyKey=<nil>, strict=true, timeout=4770)" res="CreatePromise(status=2010, promise=Promise(id=2, state=PENDING, param=Value(headers=map[0:0.0 1:0.1], data=), value=Value(headers=map[], data=), timeout=4770, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:3.0]))" err=<nil> level=INFO msg=DST t=2000|2999 tid=16 req="ReadSchedule(id=14)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=2000|2999 tid=17 req="SearchPromises(id=*6, states=[RESOLVED RESOLVED], tags=map[], limit=9, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=2000|2999 tid=19 req="ReadPromise(id=9)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=2000|2999 tid=20 req="DeleteSchedule(id=6)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=2000|2999 tid=22 req="ReadPromise(id=16)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=2000|2999 tid=23 req="AcquireLock(resourceId=15, executionId=10, processId=7, expiryInMilliseconds=7533)" res="AcquireLock(status=2010, lock=Lock(resourceId=15, executionId=10, processId=7, expiryInMilliseconds=7533, expiresAt=9533))" err=<nil> level=INFO msg=DST t=1000|2999 tid=11 req="CreateSchedule(id=4, idempotencyKey=<nil>, description=, cron=14 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=4, description=, cron=14 * * * *, tags=map[], promiseId=4.{{.timestamp}}, promiseTimeout=133014, promiseParam=Value(headers=map[0:2.0 1:2.1 2:2.2], data=), promiseTags=map[0:3.0], lastRunTime=0, nextRunTime=840000, idempotencyKey=<nil>, createdOn=2000))" err=<nil> level=INFO msg=DST t=3000|3999 tid=24 req="HeartbeatLocks(processId=6)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=3000|3999 tid=25 req="SearchSchedules(id=8*, tags=map[], limit=5, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=3000|3999 tid=26 req="CompletePromise(id=6, idempotencyKey=6, strict=false, state=REJECTED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=27 req="CompletePromise(id=15, idempotencyKey=4, strict=false, state=REJECTED_CANCELED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=28 req="ReadSchedule(id=7)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=30 req="ReadPromise(id=5)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=31 req="DeleteSchedule(id=6)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=3000|3999 tid=32 req="CompletePromise(id=15, idempotencyKey=7, strict=true, state=RESOLVED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=33 req="HeartbeatLocks(processId=15)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=3000|3999 tid=34 req="CompletePromise(id=15, idempotencyKey=5, strict=true, state=RESOLVED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=35 req="AcquireLock(resourceId=11, executionId=12, processId=16, expiryInMilliseconds=3244)" res="AcquireLock(status=2010, lock=Lock(resourceId=11, executionId=12, processId=16, expiryInMilliseconds=3244, expiresAt=6244))" err=<nil> level=INFO msg=DST t=3000|3999 tid=36 req="ReadSchedule(id=3)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=37 req="DeleteSchedule(id=14)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=3000|3999 tid=39 req="ReadSchedule(id=4)" res="ReadSchedule(status=2000, schedule=Schedule(id=4, description=, cron=14 * * * *, tags=map[], promiseId=4.{{.timestamp}}, promiseTimeout=133014, promiseParam=Value(headers=map[0:2.0 1:2.1 2:2.2], data=), promiseTags=map[0:3.0], lastRunTime=0, nextRunTime=840000, idempotencyKey=<nil>, createdOn=2000))" err=<nil> level=INFO msg=DST t=3000|3999 tid=40 req="ReadPromise(id=11)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=41 req="SearchSchedules(id=4*, tags=map[], limit=2, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[Schedule(id=4, description=, cron=14 * * * *, tags=map[], promiseId=, promiseTimeout=0, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=840000, idempotencyKey=<nil>, createdOn=2000)])" err=<nil> level=INFO msg=DST t=3000|3999 tid=42 req="ReadPromise(id=2)" res="ReadPromise(status=2000, promise=Promise(id=2, state=PENDING, param=Value(headers=map[0:0.0 1:0.1], data=), value=Value(headers=map[], data=), timeout=4770, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:3.0]))" err=<nil> level=INFO msg=DST t=3000|3999 tid=43 req="ReadPromise(id=16)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=44 req="AcquireLock(resourceId=1, executionId=10, processId=8, expiryInMilliseconds=6368)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=10, processId=8, expiryInMilliseconds=6368, expiresAt=9368))" err=<nil> level=INFO msg=DST t=3000|3999 tid=45 req="HeartbeatLocks(processId=2)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=3000|3999 tid=46 req="CompletePromise(id=14, idempotencyKey=<nil>, strict=false, state=REJECTED_CANCELED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=3000|3999 tid=47 req="AcquireLock(resourceId=2, executionId=2, processId=5, expiryInMilliseconds=2658)" res="AcquireLock(status=2010, lock=Lock(resourceId=2, executionId=2, processId=5, expiryInMilliseconds=2658, expiresAt=5658))" err=<nil> level=INFO msg=DST t=2000|3999 tid=18 req="CreateSchedule(id=0, idempotencyKey=<nil>, description=, cron=8 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=0, description=, cron=8 * * * *, tags=map[0:7.0 1:7.1 resonate:timeout:true], promiseId=0.{{.timestamp}}, promiseTimeout=64503, promiseParam=Value(headers=map[0:1.0 1:1.1], data=), promiseTags=map[0:13.0], lastRunTime=0, nextRunTime=480000, idempotencyKey=<nil>, createdOn=3000))" err=<nil> level=INFO msg=DST t=2000|3999 tid=21 req="CreatePromise(id=12, idempotencyKey=2, strict=true, timeout=8356)" res="CreatePromise(status=2010, promise=Promise(id=12, state=PENDING, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=8356, idempotencyKeyForCreate=2, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0]))" err=<nil> level=INFO msg=DST t=4000|4999 tid=48 req="DeleteSchedule(id=13)" res="DeleteSchedule(status=4042)" err=<nil> level=INFO msg=DST t=4000|4999 tid=49 req="DeleteSchedule(id=4)" res="DeleteSchedule(status=2040)" err=<nil> level=INFO msg=DST t=3000|4999 tid=29 req="CreatePromise(id=16, idempotencyKey=3, strict=true, timeout=3982)" res="CreatePromise(status=2010, promise=Promise(id=16, state=PENDING, param=Value(headers=map[], data=12), value=Value(headers=map[], data=), timeout=3982, idempotencyKeyForCreate=3, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> ... level=INFO msg=DST t=997000|997999 tid=12494 req="SearchSchedules(id=*0, tags=map[0:7.0 1:7.1 resonate:timeout:true], limit=9, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=997000|997999 tid=12495 req="CreateSchedule(id=2, idempotencyKey=<nil>, description=, cron=17 * * * *)" res="CreateSchedule(status=4091, schedule=Schedule(id=2, description=, cron=43 * * * *, tags=map[], promiseId=2.{{.timestamp}}, promiseTimeout=990473, promiseParam=Value(headers=map[0:1.0 1:1.1], data=5), promiseTags=map[], lastRunTime=0, nextRunTime=2580000, idempotencyKey=6, createdOn=991000))" err=<nil> level=INFO msg=DST t=997000|997999 tid=12496 req="AcquireLock(resourceId=3, executionId=6, processId=1, expiryInMilliseconds=2762)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil> level=INFO msg=DST t=997000|997999 tid=12497 req="CompletePromise(id=5, idempotencyKey=<nil>, strict=false, state=REJECTED)" res="CompletePromise(status=2000, promise=Promise(id=5, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=7), value=Value(headers=map[], data=), timeout=61336, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=997000|997999 tid=12498 req="HeartbeatLocks(processId=2)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=997000|997999 tid=12499 req="ReadPromise(id=16)" res="ReadPromise(status=2000, promise=Promise(id=16, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=12), value=Value(headers=map[], data=), timeout=3982, idempotencyKeyForCreate=3, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=997000|997999 tid=12500 req="SearchPromises(id=8*, states=[REJECTED_CANCELED REJECTED], tags=map[], limit=9, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=997000|997999 tid=12501 req="SearchSchedules(id=*0, tags=map[], limit=10, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[Schedule(id=10, description=, cron=47 * * * *, tags=map[], promiseId=, promiseTimeout=0, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=2820000, idempotencyKey=4, createdOn=968000)])" err=<nil> level=INFO msg=DST t=997000|997999 tid=12502 req="AcquireLock(resourceId=7, executionId=15, processId=8, expiryInMilliseconds=5137)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil> level=INFO msg=DST t=997000|997999 tid=12503 req="SearchSchedules(id=6*, tags=map[0:14.0 resonate:timeout:true], limit=6, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=997000|997999 tid=12504 req="ReleaseLock(resourceId=16, executionId=12)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=997000|997999 tid=12505 req="CreatePromise(id=5, idempotencyKey=5, strict=true, timeout=997084)" res="CreatePromise(status=4090, promise=Promise(id=5, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=7), value=Value(headers=map[], data=), timeout=61336, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=996000|997999 tid=12491 req="CreateSchedule(id=4, idempotencyKey=<nil>, description=, cron=56 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=4, description=, cron=56 * * * *, tags=map[resonate:timeout:true], promiseId=4.{{.timestamp}}, promiseTimeout=999187, promiseParam=Value(headers=map[0:1.0 1:1.1], data=), promiseTags=map[0:3.0], lastRunTime=0, nextRunTime=3360000, idempotencyKey=<nil>, createdOn=997000))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12506 req="SearchPromises(id=*6, states=[], tags=map[0:18.0 resonate:timeout:true], limit=1, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=998000|998999 tid=12507 req="SearchPromises(id=*8, states=[PENDING REJECTED_CANCELED REJECTED_TIMEDOUT], tags=map[], limit=6, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[Promise(id=8, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:2.0 1:2.1 2:2.2], data=), value=Value(headers=map[], data=), timeout=10193, idempotencyKeyForCreate=4, idempotencyKeyForUpdate=<nil>, tags=map[])])" err=<nil> level=INFO msg=DST t=998000|998999 tid=12508 req="CreatePromise(id=12, idempotencyKey=<nil>, strict=true, timeout=1006795)" res="CreatePromise(status=4090, promise=Promise(id=12, state=REJECTED_CANCELED, param=Value(headers=map[], data=), value=Value(headers=map[0:0.0 1:0.1], data=), timeout=8356, idempotencyKeyForCreate=2, idempotencyKeyForUpdate=1, tags=map[0:0.0]))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12509 req="CreatePromise(id=5, idempotencyKey=0, strict=false, timeout=1001954)" res="CreatePromise(status=4090, promise=Promise(id=5, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=7), value=Value(headers=map[], data=), timeout=61336, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12510 req="HeartbeatLocks(processId=12)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12511 req="ReadSchedule(id=1)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12512 req="AcquireLock(resourceId=10, executionId=12, processId=4, expiryInMilliseconds=6098)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12513 req="HeartbeatLocks(processId=2)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12514 req="SearchSchedules(id=*0, tags=map[0:1.0], limit=9, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=998000|998999 tid=12515 req="CreateSchedule(id=4, idempotencyKey=<nil>, description=, cron=10 * * * *)" res="CreateSchedule(status=4091, schedule=Schedule(id=4, description=, cron=56 * * * *, tags=map[resonate:timeout:true], promiseId=4.{{.timestamp}}, promiseTimeout=999187, promiseParam=Value(headers=map[0:1.0 1:1.1], data=), promiseTags=map[0:3.0], lastRunTime=0, nextRunTime=3360000, idempotencyKey=<nil>, createdOn=997000))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12516 req="CompletePromise(id=13, idempotencyKey=<nil>, strict=false, state=REJECTED_CANCELED)" res="CompletePromise(status=4030, promise=Promise(id=13, state=RESOLVED, param=Value(headers=map[0:0.0 1:0.1], data=10), value=Value(headers=map[], data=), timeout=56559, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:4.0 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12517 req="ReleaseLock(resourceId=8, executionId=1)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12518 req="CompletePromise(id=7, idempotencyKey=4, strict=true, state=RESOLVED)" res="CompletePromise(status=4033, promise=Promise(id=7, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=15659, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0]))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12519 req="AcquireLock(resourceId=7, executionId=8, processId=8, expiryInMilliseconds=4330)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12520 req="ReadSchedule(id=13)" res="ReadSchedule(status=4042, schedule=<nil>)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12521 req="DeleteSchedule(id=15)" res="DeleteSchedule(status=2040)" err=<nil> level=INFO msg=DST t=998000|998999 tid=12523 req="CreateSchedule(id=4, idempotencyKey=7, description=, cron=24 * * * *)" res="CreateSchedule(status=4091, schedule=Schedule(id=4, description=, cron=56 * * * *, tags=map[resonate:timeout:true], promiseId=4.{{.timestamp}}, promiseTimeout=999187, promiseParam=Value(headers=map[0:1.0 1:1.1], data=), promiseTags=map[0:3.0], lastRunTime=0, nextRunTime=3360000, idempotencyKey=<nil>, createdOn=997000))" err=<nil> level=INFO msg=DST t=998000|998999 tid=12524 req="CreatePromise(id=16, idempotencyKey=5, strict=false, timeout=1003536)" res="CreatePromise(status=4090, promise=Promise(id=16, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=12), value=Value(headers=map[], data=), timeout=3982, idempotencyKeyForCreate=3, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12525 req="SearchPromises(id=*2, states=[], tags=map[0:14.0 resonate:timeout:true], limit=6, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12526 req="CreatePromise(id=15, idempotencyKey=1, strict=false, timeout=1008309)" res="CreatePromise(status=4090, promise=Promise(id=15, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:0.0 1:0.1], data=11), value=Value(headers=map[], data=), timeout=50115, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12527 req="CreatePromise(id=10, idempotencyKey=<nil>, strict=false, timeout=999516)" res="CreatePromise(status=4090, promise=Promise(id=10, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:2.0 1:2.1 2:2.2], data=), value=Value(headers=map[], data=), timeout=6891, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12528 req="SearchSchedules(id=8*, tags=map[0:5.0 1:5.1], limit=1, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12529 req="ReleaseLock(resourceId=1, executionId=0)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12530 req="HeartbeatLocks(processId=5)" res="HeartbeatLocks(status=2000, locksAffected=3)" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12531 req="CompletePromise(id=11, idempotencyKey=7, strict=false, state=RESOLVED)" res="CompletePromise(status=2000, promise=Promise(id=11, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=9), value=Value(headers=map[], data=), timeout=19337, idempotencyKeyForCreate=4, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12532 req="ReleaseLock(resourceId=3, executionId=12)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12533 req="ReadPromise(id=13)" res="ReadPromise(status=2000, promise=Promise(id=13, state=RESOLVED, param=Value(headers=map[0:0.0 1:0.1], data=10), value=Value(headers=map[], data=), timeout=56559, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:4.0 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12534 req="SearchPromises(id=*6, states=[REJECTED_CANCELED], tags=map[], limit=7, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12535 req="CreatePromise(id=9, idempotencyKey=5, strict=false, timeout=1005425)" res="CreatePromise(status=4090, promise=Promise(id=9, state=RESOLVED, param=Value(headers=map[0:2.0 1:2.1 2:2.2], data=6), value=Value(headers=map[], data=), timeout=17208, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12536 req="SearchPromises(id=0*, states=[REJECTED REJECTED_TIMEDOUT], tags=map[0:8.0 1:8.1 resonate:timeout:true], limit=3, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12537 req="ReadPromise(id=7)" res="ReadPromise(status=2000, promise=Promise(id=7, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=15659, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12538 req="ReleaseLock(resourceId=0, executionId=9)" res="ReleaseLock(status=4043)" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12540 req="CompletePromise(id=2, idempotencyKey=<nil>, strict=false, state=REJECTED_CANCELED)" res="CompletePromise(status=2000, promise=Promise(id=2, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:0.0 1:0.1], data=), value=Value(headers=map[], data=), timeout=4770, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:3.0]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12541 req="SearchPromises(id=*4, states=[RESOLVED], tags=map[0:4.0 resonate:timeout:true], limit=1, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12542 req="SearchSchedules(id=2*, tags=map[], limit=6, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[Schedule(id=2, description=, cron=43 * * * *, tags=map[], promiseId=, promiseTimeout=0, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=2580000, idempotencyKey=6, createdOn=991000)])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12543 req="ReadPromise(id=16)" res="ReadPromise(status=2000, promise=Promise(id=16, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=12), value=Value(headers=map[], data=), timeout=3982, idempotencyKeyForCreate=3, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12544 req="ReadPromise(id=2)" res="ReadPromise(status=2000, promise=Promise(id=2, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:0.0 1:0.1], data=), value=Value(headers=map[], data=), timeout=4770, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:3.0]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12545 req="CreatePromise(id=15, idempotencyKey=5, strict=true, timeout=1008106)" res="CreatePromise(status=4090, promise=Promise(id=15, state=REJECTED_TIMEDOUT, param=Value(headers=map[0:0.0 1:0.1], data=11), value=Value(headers=map[], data=), timeout=50115, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[]))" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12546 req="SearchSchedules(id=4*, tags=map[], limit=5, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[Schedule(id=4, description=, cron=56 * * * *, tags=map[resonate:timeout:true], promiseId=, promiseTimeout=0, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=3360000, idempotencyKey=<nil>, createdOn=997000)])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12547 req="SearchSchedules(id=*4, tags=map[], limit=8, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[Schedule(id=4, description=, cron=56 * * * *, tags=map[resonate:timeout:true], promiseId=, promiseTimeout=0, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=3360000, idempotencyKey=<nil>, createdOn=997000)])" err=<nil> level=INFO msg=DST t=999000|1000999 tid=12548 req="SearchPromises(id=4*, states=[PENDING], tags=map[], limit=8, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=998000|1000999 tid=12522 req="CreateSchedule(id=10, idempotencyKey=6, description=, cron=59 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=10, description=, cron=59 * * * *, tags=map[0:7.0 1:7.1 resonate:timeout:true], promiseId=10.{{.timestamp}}, promiseTimeout=999753, promiseParam=Value(headers=map[0:2.0 1:2.1 2:2.2], data=2), promiseTags=map[], lastRunTime=0, nextRunTime=3540000, idempotencyKey=6, createdOn=999000))" err=<nil> level=INFO msg=DST t=999000|1001999 tid=12539 req="CreateSchedule(id=9, idempotencyKey=<nil>, description=, cron=48 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=9, description=, cron=48 * * * *, tags=map[0:7.0 1:7.1 resonate:timeout:true], promiseId=9.{{.timestamp}}, promiseTimeout=999366, promiseParam=Value(headers=map[0:1.0 1:1.1], data=3), promiseTags=map[], lastRunTime=0, nextRunTime=2880000, idempotencyKey=<nil>, createdOn=1001000))" err=<nil> level=ERROR msg="DST is non linearizable" Error: DST failed Usage: resonate dst run [flags] Flags: --seed int dst seed --ticks int number of ticks (default 1000) --timeout duration timeout (default 1h0m0s) --visualization-path string file path for porcupine visualization (default "dst.html") --scenario string can be one of: {default, fault, lazy} (default "default") --reqs-per-tick range number of requests per tick (default 1:25) --ids range number promise ids (default 1:25) --idempotency-keys range number promise idempotency keys (default 1:25) --headers range number promise headers (default 1:25) --data range number promise data byte arrays (default 1:25) --tags range number promise tags (default 1:25) --searches range number searches queries (default 1:10) --api-size range size of the submission queue buffered channel (default 1:1000) --aio-size range size of the completion queue buffered channel (default 1:1000) --aio-store string promise store type (default "sqlite") --aio-store-workers int number of concurrent connections to the store (default 1) --aio-store-sqlite-path string sqlite database path (default ":memory:") --aio-store-sqlite-tx-timeout duration sqlite transaction timeout (default 2s) --aio-store-postgres-host string postgres host (default "localhost") --aio-store-postgres-port string postgres port (default "5432") --aio-store-postgres-username string postgres username --aio-store-postgres-password string postgres password --aio-store-postgres-database string postgres database name (default "resonate_dst") --aio-store-postgres-query stringToString postgres query options (default [sslmode=disable]) --aio-store-postgres-tx-timeout duration postgres transaction timeout (default 2s) --aio-network-success-rate float32 simulated success rate of http requests (default 0.5) --aio-queuing-success-rate float32 simulated success rate of queuing requests (default 0.5) --system-coroutine-max-size range max number of coroutines to run concurrently (default 1:1000) --system-submission-batch-size range size of the completion queue buffered channel (default 1:1000) --system-completion-batch-size range max number of completions to process on each tick (default 1:1000) --system-schedule-batch-size range max number of schedules to process on each tick (default 1:1000) -h, --help help for run Global Flags: --config string Config file (default "resonate.yml") --log-level string Log level, can be one of: debug, info, warn, error (default "info") --server string Server address used by the client (default "http://127.0.0.1:8001")
more details
DST Failed
DST run failed for seed=3450, ticks=1000, scenario=lazy, store=postgres.
Seed
Scenario
Store
Commit
Command
Logs
more details