Closed github-actions[bot] closed 2 months ago
DST run failed for seed=318, ticks=1000, scenario=default, store=postgres.
Seed
318
Scenario
default
Store
postgres
Commit
4226d320da0dd64f1570a80f14d96eebcd385a03
Command
go run ./... dst run --seed 318 --ticks 1000 --scenario default --aio-store postgres
Logs
level=INFO msg=DST seed=318 ticks=1000 reqsPerTick=1:25 dst="DST(ids=7, idempotencyKeys=24, headers=12, data=9, tags=2, searches=1, backchannel=631)" system="System(api=API(size=401, subsystems=[]), aio=AIODST(subsystems=[queue store]), config=Config(cms=668, sbs=3, cbs=649, pbs=5, sbs=2, tbs=49, ted=7.644759815s))" level=INFO msg=DST t=0|999 tid=0 req="AcquireLock(resourceId=1, executionId=1, processId=6, expiryInMilliseconds=3573)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=1, processId=6, expiryInMilliseconds=3573, expiresAt=3573))" err=<nil> level=INFO msg=DST t=0|1999 tid=2 req="CreateCallback(promiseId=2, message=Message(recv=dst, data=8))" res="CreateCallback(status=4040, promise=<nil>, callback=<nil>)" err=<nil> level=INFO msg=DST t=1000|1999 tid=3 req="AcquireLock(resourceId=4, executionId=2, processId=4, expiryInMilliseconds=434)" res="AcquireLock(status=2010, lock=Lock(resourceId=4, executionId=2, processId=4, expiryInMilliseconds=434, expiresAt=1434))" err=<nil> level=INFO msg=DST t=0|1999 tid=1 req="CreatePromise(id=1, idempotencyKey=23, strict=true, timeout=911009)" res="CreatePromise(status=2010, promise=Promise(id=1, state=PENDING, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=1000|2999 tid=4 req="HeartbeatLocks(processId=4)" res="HeartbeatLocks(status=2000, locksAffected=1)" err=<nil> level=INFO msg=DST t=1000|2999 tid=5 req="DeleteSchedule(id=1)" res="DeleteSchedule(status=4041)" err=<nil> level=INFO msg=DST t=1000|3999 tid=6 req="CompletePromise(id=3, idempotencyKey=20, strict=true, state=REJECTED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=1000|4999 tid=8 req="SearchPromises(id=*0, states=[], tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], limit=9, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=1000|4999 tid=9 req="AcquireLock(resourceId=6, executionId=2, processId=6, expiryInMilliseconds=1379)" res="AcquireLock(status=2010, lock=Lock(resourceId=6, executionId=2, processId=6, expiryInMilliseconds=1379, expiresAt=5379))" err=<nil> level=INFO msg=DST t=1000|4999 tid=7 req="CreateSchedule(id=3, idempotencyKey=<nil>, description=, cron=28 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=3, description=, cron=28 * * * *, tags=map[], promiseId=3.{{.timestamp}}, promiseTimeout=274440, promiseParam=Value(headers=map[], data=), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=1680000, idempotencyKey=<nil>, createdOn=4000))" err=<nil> level=INFO msg=DST t=1000|5999 tid=10 req="DeleteSchedule(id=0)" res="DeleteSchedule(status=4041)" err=<nil> level=INFO msg=DST t=1000|6999 tid=12 req="CreateCallback(promiseId=4, message=Message(recv=dst, data=8))" res="CreateCallback(status=4040, promise=<nil>, callback=<nil>)" err=<nil> level=INFO msg=DST t=1000|6999 tid=13 req="CompletePromise(id=6, idempotencyKey=<nil>, strict=false, state=REJECTED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=1000|6999 tid=11 req="CreatePromise(id=0, idempotencyKey=16, strict=true, timeout=582849)" res="CreatePromise(status=2010, promise=Promise(id=0, state=PENDING, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=1000|7999 tid=14 req="AcquireLock(resourceId=5, executionId=1, processId=2, expiryInMilliseconds=2916)" res="AcquireLock(status=2010, lock=Lock(resourceId=5, executionId=1, processId=2, expiryInMilliseconds=2916, expiresAt=9916))" err=<nil> level=INFO msg=DST t=1000|7999 tid=15 req="CreateSchedule(id=3, idempotencyKey=<nil>, description=, cron=31 * * * *)" res="CreateSchedule(status=4091, schedule=Schedule(id=3, description=, cron=28 * * * *, tags=map[], promiseId=3.{{.timestamp}}, promiseTimeout=274440, promiseParam=Value(headers=map[], data=), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=1680000, idempotencyKey=<nil>, createdOn=4000))" err=<nil> level=INFO msg=DST t=1000|8999 tid=16 req="ReleaseLock(resourceId=2, executionId=3)" res="ReleaseLock(status=4042)" err=<nil> level=INFO msg=DST t=1000|9999 tid=18 req="CompletePromise(id=5, idempotencyKey=8, strict=true, state=REJECTED_CANCELED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=1000|9999 tid=17 req="CompletePromise(id=1, idempotencyKey=<nil>, strict=true, state=REJECTED_CANCELED)" res="CompletePromise(status=2010, promise=Promise(id=1, state=REJECTED_CANCELED, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=0), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=1000|10999 tid=20 req="ReadSchedule(id=6)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=1000|10999 tid=21 req="ReadPromise(id=1)" res="ReadPromise(status=2000, promise=Promise(id=1, state=REJECTED_CANCELED, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=0), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=1000|10999 tid=19 req="CreateSchedule(id=1, idempotencyKey=<nil>, description=, cron=15 * * * *)" res="CreateSchedule(status=2010, schedule=Schedule(id=1, description=, cron=15 * * * *, tags=map[], promiseId=1.{{.timestamp}}, promiseTimeout=136607, promiseParam=Value(headers=map[0:6.0 1:6.1], data=7), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=900000, idempotencyKey=<nil>, createdOn=10000))" err=<nil> level=INFO msg=DST t=1000|11999 tid=22 req="CreatePromise(id=0, idempotencyKey=1, strict=false, timeout=962595)" res="CreatePromise(status=4090, promise=Promise(id=0, state=PENDING, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=1000|12999 tid=24 req="ReadPromise(id=2)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=1000|12999 tid=25 req="SearchPromises(id=0*, states=[REJECTED_CANCELED REJECTED_CANCELED PENDING], tags=map[0:1.0 1:1.1 2:1.2], limit=3, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=1000|12999 tid=23 req="CreatePromise(id=5, idempotencyKey=<nil>, strict=false, timeout=36384)" res="CreatePromise(status=2010, promise=Promise(id=5, state=PENDING, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=36384, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=2000|13999 tid=26 req="ReadSchedule(id=4)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=2000|13999 tid=27 req="ReadSchedule(id=2)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=2000|14999 tid=28 req="HeartbeatLocks(processId=0)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=2000|14999 tid=29 req="HeartbeatLocks(processId=4)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=2000|15999 tid=30 req="AcquireLock(resourceId=3, executionId=5, processId=5, expiryInMilliseconds=1742)" res="AcquireLock(status=2010, lock=Lock(resourceId=3, executionId=5, processId=5, expiryInMilliseconds=1742, expiresAt=16742))" err=<nil> level=INFO msg=DST t=2000|15999 tid=31 req="SearchPromises(id=*0, states=[PENDING], tags=map[], limit=8, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[Promise(id=0, state=PENDING, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true])])" err=<nil> level=INFO msg=DST t=2000|16999 tid=32 req="CompletePromise(id=2, idempotencyKey=<nil>, strict=true, state=REJECTED)" res="CompletePromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=2000|16999 tid=33 req="SearchSchedules(id=0*, tags=map[0:1.0 1:1.1 2:1.2], limit=6, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=2000|17999 tid=34 req="ReadPromise(id=4)" res="ReadPromise(status=4040, promise=<nil>)" err=<nil> level=INFO msg=DST t=2000|17999 tid=35 req="ReleaseLock(resourceId=2, executionId=1)" res="ReleaseLock(status=4042)" err=<nil> level=INFO msg=DST t=2000|18999 tid=36 req="ReadSchedule(id=3)" res="ReadSchedule(status=2000, schedule=Schedule(id=3, description=, cron=28 * * * *, tags=map[], promiseId=3.{{.timestamp}}, promiseTimeout=274440, promiseParam=Value(headers=map[], data=), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=1680000, idempotencyKey=<nil>, createdOn=4000))" err=<nil> level=INFO msg=DST t=2000|18999 tid=37 req="AcquireLock(resourceId=5, executionId=2, processId=2, expiryInMilliseconds=927)" res="AcquireLock(status=2010, lock=Lock(resourceId=5, executionId=2, processId=2, expiryInMilliseconds=927, expiresAt=18927))" err=<nil> level=INFO msg=DST t=2000|19999 tid=38 req="ReadPromise(id=5)" res="ReadPromise(status=2000, promise=Promise(id=5, state=PENDING, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=36384, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=2000|19999 tid=39 req="HeartbeatLocks(processId=2)" res="HeartbeatLocks(status=2000, locksAffected=1)" err=<nil> level=INFO msg=DST t=2000|20999 tid=40 req="AcquireLock(resourceId=3, executionId=4, processId=5, expiryInMilliseconds=7843)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil> level=INFO msg=DST t=2000|20999 tid=41 req="ReadPromise(id=1)" res="ReadPromise(status=2000, promise=Promise(id=1, state=REJECTED_CANCELED, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=0), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=2000|21999 tid=42 req="SearchPromises(id=*0, states=[REJECTED_CANCELED REJECTED REJECTED], tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], limit=2, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=2000|21999 tid=43 req="CreateSchedule(id=1, idempotencyKey=1, description=, cron=3 * * * *)" res="CreateSchedule(status=4091, schedule=Schedule(id=1, description=, cron=15 * * * *, tags=map[], promiseId=1.{{.timestamp}}, promiseTimeout=136607, promiseParam=Value(headers=map[0:6.0 1:6.1], data=7), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=900000, idempotencyKey=<nil>, createdOn=10000))" err=<nil> level=INFO msg=DST t=3000|22999 tid=44 req="ReadSchedule(id=2)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=3000|22999 tid=45 req="ReadSchedule(id=4)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=3000|23999 tid=46 req="CreateCallback(promiseId=4, message=Message(recv=dst, data=8))" res="CreateCallback(status=4040, promise=<nil>, callback=<nil>)" err=<nil> level=INFO msg=DST t=3000|23999 tid=47 req="AcquireLock(resourceId=1, executionId=2, processId=5, expiryInMilliseconds=984)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=2, processId=5, expiryInMilliseconds=984, expiresAt=23984))" err=<nil> level=INFO msg=DST t=3000|24999 tid=49 req="SearchPromises(id=0*, states=[REJECTED_CANCELED PENDING], tags=map[], limit=10, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[Promise(id=0, state=PENDING, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true])])" err=<nil> ... level=INFO msg=DST t=983000|1183999 tid=12523 req="ReadPromise(id=2)" res="ReadPromise(status=2000, promise=Promise(id=2, state=REJECTED_CANCELED, param=Value(headers=map[0:9.0 1:9.1], data=), value=Value(headers=map[0:8.0 1:8.1], data=3), timeout=341982, idempotencyKeyForCreate=22, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=983000|1184999 tid=12524 req="CompletePromise(id=0, idempotencyKey=20, strict=false, state=REJECTED_CANCELED)" res="CompletePromise(status=4032, promise=Promise(id=0, state=REJECTED_CANCELED, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=8, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=984000|1184999 tid=12530 req="AcquireLock(resourceId=0, executionId=1, processId=6, expiryInMilliseconds=7014)" res="AcquireLock(status=2010, lock=Lock(resourceId=0, executionId=1, processId=6, expiryInMilliseconds=7014, expiresAt=1191014))" err=<nil> level=INFO msg=DST t=984000|1185999 tid=12531 req="CompletePromise(id=0, idempotencyKey=<nil>, strict=true, state=RESOLVED)" res="CompletePromise(status=4032, promise=Promise(id=0, state=REJECTED_CANCELED, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=8, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=985000|1185999 tid=12552 req="ReadSchedule(id=2)" res="ReadSchedule(status=2000, schedule=Schedule(id=2, description=, cron=41 * * * *, tags=map[], promiseId=2.{{.timestamp}}, promiseTimeout=972143, promiseParam=Value(headers=map[0:5.0 1:5.1], data=), promiseTags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], lastRunTime=0, nextRunTime=2460000, idempotencyKey=<nil>, createdOn=1170000))" err=<nil> level=INFO msg=DST t=985000|1186999 tid=12553 req="HeartbeatLocks(processId=3)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=986000|1186999 tid=12561 req="CreateCallback(promiseId=0, message=Message(recv=dst, data=8))" res="CreateCallback(status=2000, promise=Promise(id=0, state=REJECTED_CANCELED, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=8, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]), callback=<nil>)" err=<nil> level=INFO msg=DST t=986000|1187999 tid=12562 req="ReadSchedule(id=1)" res="ReadSchedule(status=2000, schedule=Schedule(id=1, description=, cron=5 * * * *, tags=map[0:1.0 1:1.1 2:1.2], promiseId=1.{{.timestamp}}, promiseTimeout=974803, promiseParam=Value(headers=map[0:6.0 1:6.1], data=), promiseTags=map[], lastRunTime=0, nextRunTime=3900000, idempotencyKey=<nil>, createdOn=1140000))" err=<nil> level=INFO msg=DST t=987000|1187999 tid=12579 req="ReadPromise(id=2)" res="ReadPromise(status=2000, promise=Promise(id=2, state=REJECTED_CANCELED, param=Value(headers=map[0:9.0 1:9.1], data=), value=Value(headers=map[0:8.0 1:8.1], data=3), timeout=341982, idempotencyKeyForCreate=22, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=987000|1188999 tid=12580 req="SearchPromises(id=*0, states=[REJECTED_TIMEDOUT], tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], limit=3, sortId=<nil>)" res="SearchPromises(status=2000, cursor=<nil>, promises=[])" err=<nil> level=INFO msg=DST t=988000|1188999 tid=12591 req="SearchSchedules(id=0*, tags=map[], limit=8, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=988000|1189999 tid=12592 req="SearchSchedules(id=0*, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], limit=2, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=989000|1189999 tid=12598 req="SearchSchedules(id=*0, tags=map[0:1.0 1:1.1 2:1.2], limit=8, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=989000|1190999 tid=12599 req="ReadSchedule(id=3)" res="ReadSchedule(status=2000, schedule=Schedule(id=3, description=, cron=22 * * * *, tags=map[], promiseId=3.{{.timestamp}}, promiseTimeout=992593, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=1320000, idempotencyKey=23, createdOn=1128000))" err=<nil> level=INFO msg=DST t=990000|1190999 tid=12606 req="CompletePromise(id=1, idempotencyKey=<nil>, strict=false, state=RESOLVED)" res="CompletePromise(status=4032, promise=Promise(id=1, state=REJECTED_CANCELED, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=0), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=991000|1191999 tid=12607 req="CreateCallback(promiseId=4, message=Message(recv=dst, data=8))" res="CreateCallback(status=2000, promise=Promise(id=4, state=RESOLVED, param=Value(headers=map[], data=1), value=Value(headers=map[], data=2), timeout=406302, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=16, tags=map[]), callback=<nil>)" err=<nil> level=INFO msg=DST t=991000|1191999 tid=12608 req="ReadPromise(id=6)" res="ReadPromise(status=2000, promise=Promise(id=6, state=REJECTED, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=726418, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:1.0 1:1.1 2:1.2]))" err=<nil> level=INFO msg=DST t=991000|1192999 tid=12609 req="CreatePromise(id=1, idempotencyKey=14, strict=true, timeout=1458118)" res="CreatePromise(status=4090, promise=Promise(id=1, state=REJECTED_CANCELED, param=Value(headers=map[0:1.0 1:1.1 2:1.2], data=1), value=Value(headers=map[], data=0), timeout=911009, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=992000|1192999 tid=12627 req="ReadSchedule(id=1)" res="ReadSchedule(status=2000, schedule=Schedule(id=1, description=, cron=5 * * * *, tags=map[0:1.0 1:1.1 2:1.2], promiseId=1.{{.timestamp}}, promiseTimeout=974803, promiseParam=Value(headers=map[0:6.0 1:6.1], data=), promiseTags=map[], lastRunTime=0, nextRunTime=3900000, idempotencyKey=<nil>, createdOn=1140000))" err=<nil> level=INFO msg=DST t=992000|1193999 tid=12628 req="ReleaseLock(resourceId=0, executionId=2)" res="ReleaseLock(status=4042)" err=<nil> level=INFO msg=DST t=993000|1193999 tid=12630 req="HeartbeatLocks(processId=1)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=993000|1194999 tid=12631 req="ReleaseLock(resourceId=0, executionId=1)" res="ReleaseLock(status=4042)" err=<nil> level=INFO msg=DST t=994000|1194999 tid=12640 req="ReadSchedule(id=0)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=994000|1195999 tid=12641 req="ReadSchedule(id=4)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil> level=INFO msg=DST t=995000|1195999 tid=12661 req="AcquireLock(resourceId=1, executionId=6, processId=0, expiryInMilliseconds=2830)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=6, processId=0, expiryInMilliseconds=2830, expiresAt=1197830))" err=<nil> level=INFO msg=DST t=995000|1196999 tid=12662 req="SearchSchedules(id=*0, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true], limit=10, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=996000|1196999 tid=12681 req="CreateCallback(promiseId=2, message=Message(recv=dst, data=8))" res="CreateCallback(status=2000, promise=Promise(id=2, state=REJECTED_CANCELED, param=Value(headers=map[0:9.0 1:9.1], data=), value=Value(headers=map[0:8.0 1:8.1], data=3), timeout=341982, idempotencyKeyForCreate=22, idempotencyKeyForUpdate=<nil>, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]), callback=<nil>)" err=<nil> level=INFO msg=DST t=996000|1197999 tid=12682 req="ReleaseLock(resourceId=2, executionId=0)" res="ReleaseLock(status=4042)" err=<nil> level=INFO msg=DST t=997000|1197999 tid=12705 req="ReadPromise(id=0)" res="ReadPromise(status=2000, promise=Promise(id=0, state=REJECTED_CANCELED, param=Value(headers=map[0:2.0], data=), value=Value(headers=map[], data=), timeout=582849, idempotencyKeyForCreate=16, idempotencyKeyForUpdate=8, tags=map[0:0.0 1:0.1 2:0.2 resonate:timeout:true]))" err=<nil> level=INFO msg=DST t=997000|1198999 tid=12706 req="ReadPromise(id=4)" res="ReadPromise(status=2000, promise=Promise(id=4, state=RESOLVED, param=Value(headers=map[], data=1), value=Value(headers=map[], data=2), timeout=406302, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=16, tags=map[]))" err=<nil> level=INFO msg=DST t=998000|1198999 tid=12719 req="SearchSchedules(id=*0, tags=map[], limit=2, sortId=<nil>)" res="SearchSchedules(status=2000, cursor=<nil>, schedules=[])" err=<nil> level=INFO msg=DST t=998000|1199999 tid=12720 req="HeartbeatLocks(processId=4)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=INFO msg=DST t=999000|1199999 tid=12743 req="CreatePromise(id=6, idempotencyKey=6, strict=false, timeout=1245730)" res="CreatePromise(status=4090, promise=Promise(id=6, state=REJECTED, param=Value(headers=map[], data=), value=Value(headers=map[], data=), timeout=726418, idempotencyKeyForCreate=23, idempotencyKeyForUpdate=<nil>, tags=map[0:1.0 1:1.1 2:1.2]))" err=<nil> level=INFO msg=DST t=999000|1200999 tid=12744 req="HeartbeatLocks(processId=2)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil> level=ERROR msg="DST timed out before linearizability could be determined" 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) --scenario string can be one of: default, fault, lazy (default "default") --visualization-path string porcupine visualization file path (default "dst.html") --reqs-per-tick range number of requests per tick (default 1:25) --ids range promise id set size (default 1:25) --idempotency-keys range idempotency key set size (default 1:25) --headers range promise header set size (default 1:25) --data range promise data set size (default 1:25) --tags range promise tags set size (default 1:25) --searches range search set size (default 1:10) --backchannel-size range backchannel size (default 1:1000) --system-url string resonate server url --system-coroutine-max-size range max concurrent coroutines (default 1:1000) --system-submission-batch-size range max submissions processed per tick (default 1:1000) --system-completion-batch-size range max completions processed per tick (default 1:1000) --system-promise-batch-size range max promises processed per iteration (default 1:100) --system-schedule-batch-size range max schedules processed per iteration (default 1:100) --system-task-batch-size range max tasks processed per iteration (default 1:100) --system-task-enqueue-delay range time delay before attempting to reenqueue tasks (default 1s:10s) --system-signal-timeout range time to wait for api/aio signal (default 1s:10s) --api-size range submission buffered channel size (default 1:1000) --api-http-enable enable subsystem --api-http-host string http server host (default "0.0.0.0") --api-http-port int http server port (default 8001) --api-http-timeout duration http server graceful shutdown timeout (default 10s) --api-http-auth stringToString http basic auth username password pairs (default []) --api-grpc-enable enable subsystem --api-grpc-host string grpc server host (default "0.0.0.0") --api-grpc-port int grpc server port (default 50051) --aio-size range completion buffered channel size (default 1:1000) --aio-queue-enable enable subsystem (default true) --aio-queue-p range probability of simulated unsuccessful request (default 0.00:1.00) --aio-store-postgres-enable enable subsystem --aio-store-postgres-size int submission buffered channel size (default 1000) --aio-store-postgres-batch-size int max submissions processed per iteration (default 1000) --aio-store-postgres-workers int number of workers (default 1) --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 (default "resonate_dst") --aio-store-postgres-query stringToString postgres query options (default [sslmode=disable]) --aio-store-postgres-tx-timeout duration postgres transaction timeout (default 10s) --aio-store-postgres-reset reset postgres db on shutdown (default true) --aio-store-sqlite-enable enable subsystem (default true) --aio-store-sqlite-size int submission buffered channel size (default 1000) --aio-store-sqlite-batch-size int max submissions processed per iteration (default 1000) --aio-store-sqlite-path string sqlite database path (default ":memory:") --aio-store-sqlite-tx-timeout duration sqlite transaction timeout (default 10s) --aio-store-sqlite-reset reset sqlite db on shutdown (default true) --metrics-port int prometheus metrics server port (default 9090) --log-level string can be one of: debug, info, warn, error (default "info") -h, --help help for run Global Flags: --config string Config file (default "resonate.yml") --server string Resonate server url (default "http://localhost:8001")
more details
DST Failed
DST run failed for seed=318, ticks=1000, scenario=default, store=postgres.
Seed
Scenario
Store
Commit
Command
Logs
more details