Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

DST: 14515 #538

Open
github-actions bot opened this issue Jan 26, 2025 · 0 comments
Open

DST: 14515 #538

github-actions bot opened this issue Jan 26, 2025 · 0 comments

Comments

@github-actions
Copy link

DST Failed

DST run failed for seed=14515, ticks=1000, scenario=lazy, store=postgres.

Seed

14515

Scenario

lazy

Store

postgres

Commit

bbb848a386c34a2b8b254bd47631e0f88e25c5c3

Command

go run ./... dst run --seed 14515 --ticks 1000 --scenario lazy --aio-store postgres

Logs

level=INFO msg=DST seed=14515 ticks=1000 reqsPerTick=1:25 dst="DST(ids=2, idempotencyKeys=11, headers=18, data=4, tags=21, backchannel=644)" system="System(api=API(size=135, subsystems=[]), aio=AIODST(subsystems=[router sender store]), config=Config(cms=833, sbs=5, cbs=585, pbs=32, sbs=40, tbs=11, ted=9.949583932s))"
level=INFO msg=DST t=0|999 id=0 req="CreateSubscription(id=sb0, promiseId=p0, recv=\"dst\")" res=Response err=<nil>
level=INFO msg=DST t=0|999 id=1 req="CreateSubscription(id=sb1, promiseId=p0, recv=\"dst\")" res=Response err=<nil>
level=INFO msg=DST t=0|1999 id=4 req="CompletePromise(id=p1, idempotencyKey=3, strict=true, state=REJECTED_CANCELED, value=Value(headers=map[0:8.0], data=))" res="CompletePromise(status=4040, promise=<nil>)" err=<nil>
level=INFO msg=DST t=0|1999 id=2 req="CreateSchedule(id=s1, desc=, cron=21 * * * *, tags=map[0:6.0 resonate:timeout:true], promiseId=s1.{{.timestamp}}, promiseTimeout=669994, promiseParam=Value(headers=map[], data=), promiseTags=map[], idempotencyKey=<nil>)" res="CreateSchedule(status=2010, schedule=Schedule(id=s1, desc=, cron=21 * * * *, tags=map[0:6.0 resonate:timeout:true], promiseId=s1.{{.timestamp}}, promiseTimeout=669994, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=1260000, idempotencyKey=<nil>, createdOn=1000))" err=<nil>
level=INFO msg=DST t=1000|2999 id=6 req="SearchSchedules(id=s*0, tags=map[], limit=7, sortId=0)" res="SearchSchedules(status=2000, schedules=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=1000|2999 id=7 req="ReadSchedule(id=s1)" res="ReadSchedule(status=2000, schedule=Schedule(id=s1, desc=, cron=21 * * * *, tags=map[0:6.0 resonate:timeout:true], promiseId=s1.{{.timestamp}}, promiseTimeout=669994, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=1260000, idempotencyKey=<nil>, createdOn=1000))" err=<nil>
level=INFO msg=DST t=1000|2999 id=8 req="ReleaseLock(resourceId=0, executionId=1)" res="ReleaseLock(status=4042)" err=<nil>
level=INFO msg=DST t=1000|3999 id=9 req="CreateSchedule(id=s1, desc=, cron=54 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=139004, promiseParam=Value(headers=map[], data=0), promiseTags=map[], idempotencyKey=<nil>)" res="CreateSchedule(status=4091, schedule=Schedule(id=s1, desc=, cron=21 * * * *, tags=map[0:6.0 resonate:timeout:true], promiseId=s1.{{.timestamp}}, promiseTimeout=669994, promiseParam=Value(headers=map[], data=), promiseTags=map[], lastRunTime=0, nextRunTime=1260000, idempotencyKey=<nil>, createdOn=1000))" err=<nil>
level=INFO msg=DST t=1000|3999 id=10 req="AcquireLock(resourceId=1, executionId=0, processId=1, ttl=4817)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=0, processId=1, ttl=4817, expiresAt=7817))" err=<nil>
level=INFO msg=DST t=0|3999 id=3 req="CreatePromiseAndTask(promise=CreatePromise(id=p0, idempotencyKey=<nil>, strict=true, param=Value(headers=map[0:16.0 1:16.1], data=0), timeout=8449, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true]), task=CreateTask(promiseId=p0, processId=p0, ttl=3077, timeout=8449))" res="CreatePromiseAndTask(status=2010, promise=Promise(id=p0, state=PENDING, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=0), task=Task(id=1, processId=p0, state=CLAIMED, rootPromiseId=, recv=\"dst\", mesg=Mesg(type=invoke, root=p0, leaf=p0), timeout=8449, counter=1, attempt=0, ttl=3077, expiresAt=4077, createdOn=1000, completedOn=0))" err=<nil>
level=INFO msg=DST t=1000|3999 id=5 req="CreatePromiseAndTask(promise=CreatePromise(id=p1, idempotencyKey=5, strict=false, param=Value(headers=map[], data=3), timeout=1834, tags=map[resonate:invoke:dst]), task=CreateTask(promiseId=p1, processId=p1, ttl=3371, timeout=1834))" res="CreatePromiseAndTask(status=2010, promise=Promise(id=p1, state=PENDING, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=0), task=Task(id=2, processId=p1, state=CLAIMED, rootPromiseId=, recv=\"dst\", mesg=Mesg(type=invoke, root=p1, leaf=p1), timeout=1834, counter=1, attempt=0, ttl=3371, expiresAt=4371, createdOn=1000, completedOn=0))" err=<nil>
level=INFO msg=DST t=1000|4999 id=12 req="HeartbeatLocks(processId=0)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil>
level=INFO msg=DST t=1000|4999 id=13 req="DeleteSchedule(id=s1)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=2000|4999 id=14 req="HeartbeatLocks(processId=0)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil>
level=INFO msg=DST t=2000|5999 id=15 req="ReleaseLock(resourceId=1, executionId=1)" res="ReleaseLock(status=4042)" err=<nil>
level=INFO msg=DST t=2000|6999 id=16 req="CreateSchedule(id=s0, desc=, cron=29 * * * *, tags=map[], promiseId=s0.{{.timestamp}}, promiseTimeout=470287, promiseParam=Value(headers=map[], data=1), promiseTags=map[], idempotencyKey=9)" res="CreateSchedule(status=2010, schedule=Schedule(id=s0, desc=, cron=29 * * * *, tags=map[], promiseId=s0.{{.timestamp}}, promiseTimeout=470287, promiseParam=Value(headers=map[], data=1), promiseTags=map[], lastRunTime=0, nextRunTime=1740000, idempotencyKey=9, createdOn=6000))" err=<nil>
level=INFO msg=DST t=2000|6999 id=17 req="CreateCallback(id=cb1, promiseId=p0, rootPromiseId=p1, timeout=446914, recv=\"dst\")" res="CreateCallback(status=2010, promise=Promise(id=p0, state=PENDING, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=0), callback=Callback(id=p0.cb1, promiseId=p0, recv=\"dst\", mesg=Mesg(type=resume, root=p1, leaf=p0), timeout=446914, createdOn=6000))" err=<nil>
level=INFO msg=DST t=1000|6999 id=11 req="CreatePromise(id=p0, idempotencyKey=<nil>, strict=true, param=Value(headers=map[], data=), timeout=8897, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p0, state=PENDING, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=0))" err=<nil>
level=INFO msg=DST t=2000|7999 id=21 req="CreatePromise(id=p1, idempotencyKey=1, strict=false, param=Value(headers=map[], data=0), timeout=11308, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=2000|7999 id=22 req="ReadSchedule(id=s1)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil>
level=INFO msg=DST t=2000|7999 id=23 req="SearchPromises(id=p*3, states=[REJECTED_CANCELED], tags=map[], limit=1, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=2000|7999 id=18 req="CreatePromise(id=p1, idempotencyKey=<nil>, strict=false, param=Value(headers=map[], data=0), timeout=7397, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=2000|8999 id=25 req="ReadSchedule(id=s0)" res="ReadSchedule(status=2000, schedule=Schedule(id=s0, desc=, cron=29 * * * *, tags=map[], promiseId=s0.{{.timestamp}}, promiseTimeout=470287, promiseParam=Value(headers=map[], data=1), promiseTags=map[], lastRunTime=0, nextRunTime=1740000, idempotencyKey=9, createdOn=6000))" err=<nil>
level=INFO msg=DST t=2000|8999 id=26 req="HeartbeatLocks(processId=0)" res="HeartbeatLocks(status=2000, locksAffected=0)" err=<nil>
level=INFO msg=DST t=2000|8999 id=19 req="ReadPromise(id=p1)" res="ReadPromise(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=2000|8999 id=20 req="CreatePromise(id=p1, idempotencyKey=<nil>, strict=false, param=Value(headers=map[], data=2), timeout=6700, tags=map[0:0.0 1:0.1])" res="CreatePromise(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=2000|9999 id=27 req="CreatePromiseAndTask(promise=CreatePromise(id=p1, idempotencyKey=10, strict=true, param=Value(headers=map[], data=0), timeout=7771, tags=map[0:19.0 resonate:invoke:dst resonate:timeout:true]), task=CreateTask(promiseId=p1, processId=p1, ttl=3293, timeout=7771))" res="CreatePromiseAndTask(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), task=<nil>)" err=<nil>
level=INFO msg=DST t=2000|9999 id=28 req="CreateCallback(id=cb1, promiseId=p1, rootPromiseId=p1, timeout=819882, recv=\"dst\")" res="CreateCallback(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), callback=<nil>)" err=<nil>
level=INFO msg=DST t=3000|9999 id=29 req="SearchPromises(id=p1*, states=[], tags=map[], limit=7, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=2000|9999 id=24 req="CreateSchedule(id=s1, desc=, cron=50 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=378300, promiseParam=Value(headers=map[0:13.0 1:13.1], data=2), promiseTags=map[0:12.0 resonate:timeout:true], idempotencyKey=<nil>)" res="CreateSchedule(status=2010, schedule=Schedule(id=s1, desc=, cron=50 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=378300, promiseParam=Value(headers=map[0:13.0 1:13.1], data=2), promiseTags=map[0:12.0 resonate:timeout:true], lastRunTime=0, nextRunTime=3000000, idempotencyKey=<nil>, createdOn=9000))" err=<nil>
level=INFO msg=DST t=3000|10999 id=30 req="ReadSchedule(id=s0)" res="ReadSchedule(status=2000, schedule=Schedule(id=s0, desc=, cron=29 * * * *, tags=map[], promiseId=s0.{{.timestamp}}, promiseTimeout=470287, promiseParam=Value(headers=map[], data=1), promiseTags=map[], lastRunTime=0, nextRunTime=1740000, idempotencyKey=9, createdOn=6000))" err=<nil>
level=INFO msg=DST t=3000|10999 id=31 req="AcquireLock(resourceId=0, executionId=1, processId=0, ttl=3791)" res="AcquireLock(status=2010, lock=Lock(resourceId=0, executionId=1, processId=0, ttl=3791, expiresAt=13791))" err=<nil>
level=INFO msg=DST t=3000|10999 id=32 req="AcquireLock(resourceId=1, executionId=0, processId=1, ttl=4858)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=0, processId=1, ttl=4858, expiresAt=14858))" err=<nil>
level=INFO msg=DST t=3000|11999 id=33 req="ReadSchedule(id=s0)" res="ReadSchedule(status=2000, schedule=Schedule(id=s0, desc=, cron=29 * * * *, tags=map[], promiseId=s0.{{.timestamp}}, promiseTimeout=470287, promiseParam=Value(headers=map[], data=1), promiseTags=map[], lastRunTime=0, nextRunTime=1740000, idempotencyKey=9, createdOn=6000))" err=<nil>
level=INFO msg=DST t=3000|11999 id=34 req="DeleteSchedule(id=s1)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=3000|11999 id=35 req="DeleteSchedule(id=s1)" res="DeleteSchedule(status=4041)" err=<nil>
level=INFO msg=DST t=3000|12999 id=38 req="ReadPromise(id=p1)" res="ReadPromise(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=3000|13999 id=39 req="CreatePromiseAndTask(promise=CreatePromise(id=p0, idempotencyKey=8, strict=false, param=Value(headers=map[], data=), timeout=6966, tags=map[0:4.0 resonate:invoke:dst resonate:timeout:true]), task=CreateTask(promiseId=p0, processId=p0, ttl=2612, timeout=6966))" res="CreatePromiseAndTask(status=4090, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449), task=<nil>)" err=<nil>
level=INFO msg=DST t=3000|13999 id=40 req="DeleteSchedule(id=s0)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=3000|13999 id=41 req="CreateSubscription(id=sb1, promiseId=p0, recv=\"dst\")" res=Response err=<nil>
level=INFO msg=DST t=3000|13999 id=37 req="CreateCallback(id=cb1, promiseId=p0, rootPromiseId=p0, timeout=14035, recv=\"dst\")" res="CreateCallback(status=2000, promise=Promise(id=p0, state=PENDING, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=0), callback=<nil>)" err=<nil>
level=INFO msg=DST t=3000|13999 id=36 req="CompletePromise(id=p0, idempotencyKey=<nil>, strict=false, state=REJECTED, value=Value(headers=map[0:12.0 1:12.1 2:12.2], data=))" res="CompletePromise(status=4030, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449))" err=<nil>
level=INFO msg=DST t=3000|14999 id=42 req="ReadPromise(id=p1)" res="ReadPromise(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=3000|14999 id=44 req="CompletePromise(id=p1, idempotencyKey=7, strict=true, state=RESOLVED, value=Value(headers=map[0:14.0 1:14.1 2:14.2], data=))" res="CompletePromise(status=4033, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=4000|15999 id=46 req="ReadPromise(id=p0)" res="ReadPromise(status=2000, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449))" err=<nil>
level=INFO msg=DST t=4000|15999 id=47 req="CreateCallback(id=cb0, promiseId=p0, rootPromiseId=p0, timeout=935449, recv=\"dst\")" res="CreateCallback(status=2000, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449), callback=<nil>)" err=<nil>
level=INFO msg=DST t=3000|15999 id=43 req="CreateSchedule(id=s1, desc=, cron=26 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=584876, promiseParam=Value(headers=map[], data=), promiseTags=map[0:14.0], idempotencyKey=1)" res="CreateSchedule(status=2010, schedule=Schedule(id=s1, desc=, cron=26 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=584876, promiseParam=Value(headers=map[], data=), promiseTags=map[0:14.0], lastRunTime=0, nextRunTime=1560000, idempotencyKey=1, createdOn=15000))" err=<nil>
level=INFO msg=DST t=17000|17000 id=186 req="ReleaseLock(resourceId=1, executionId=1)" res=<nil> err="The api submission queue is full"
level=INFO msg=DST t=17000|17000 id=187 req="SearchPromises(id=p7*, states=[PENDING REJECTED_TIMEDOUT REJECTED_CANCELED], tags=map[], limit=1, sortId=0)" res=<nil> err="The api submission queue is full"

...

level=INFO msg=DST t=989000|1034999 id=12355 req="CompletePromise(id=p1, idempotencyKey=9, strict=true, state=REJECTED_CANCELED, value=Value(headers=map[], data=3))" res="CompletePromise(status=4033, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=989000|1034999 id=12356 req="SearchPromises(id=p8*, states=[REJECTED_CANCELED], tags=map[], limit=3, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=989000|1034999 id=12357 req="ReadSchedule(id=s0)" res="ReadSchedule(status=2000, schedule=Schedule(id=s0, desc=, cron=14 * * * *, tags=map[0:8.0 resonate:invoke:dst], promiseId=s0.{{.timestamp}}, promiseTimeout=992044, promiseParam=Value(headers=map[], data=), promiseTags=map[0:14.0], lastRunTime=0, nextRunTime=4440000, idempotencyKey=<nil>, createdOn=1029000))" err=<nil>
level=INFO msg=DST t=990000|1035999 id=12369 req="CreatePromise(id=p1, idempotencyKey=<nil>, strict=false, param=Value(headers=map[0:4.0 1:4.1 2:4.2], data=1), timeout=995595, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=990000|1035999 id=12370 req="DeleteSchedule(id=s1)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=990000|1035999 id=12371 req="ReleaseLock(resourceId=0, executionId=0)" res="ReleaseLock(status=4042)" err=<nil>
level=INFO msg=DST t=991000|1036999 id=12376 req="AcquireLock(resourceId=1, executionId=1, processId=0, ttl=7179)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil>
level=INFO msg=DST t=991000|1036999 id=12377 req="CreatePromise(id=p0, idempotencyKey=<nil>, strict=false, param=Value(headers=map[], data=3), timeout=992400, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449))" err=<nil>
level=INFO msg=DST t=992000|1037999 id=12399 req="ReadPromise(id=p1)" res="ReadPromise(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834))" err=<nil>
level=INFO msg=DST t=992000|1037999 id=12400 req="DeleteSchedule(id=s0)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=992000|1037999 id=12401 req="DeleteSchedule(id=s1)" res="DeleteSchedule(status=2040)" err=<nil>
level=INFO msg=DST t=991000|1037999 id=12375 req="CreateSchedule(id=s1, desc=, cron=53 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=992841, promiseParam=Value(headers=map[], data=3), promiseTags=map[0:9.0 resonate:invoke:dst], idempotencyKey=9)" res="CreateSchedule(status=2010, schedule=Schedule(id=s1, desc=, cron=53 * * * *, tags=map[], promiseId=s1.{{.timestamp}}, promiseTimeout=992841, promiseParam=Value(headers=map[], data=3), promiseTags=map[0:9.0 resonate:invoke:dst], lastRunTime=0, nextRunTime=3180000, idempotencyKey=9, createdOn=1037000))" err=<nil>
level=INFO msg=DST t=993000|1038999 id=12420 req="AcquireLock(resourceId=1, executionId=0, processId=1, ttl=416)" res="AcquireLock(status=2010, lock=Lock(resourceId=1, executionId=0, processId=1, ttl=416, expiresAt=1038416))" err=<nil>
level=INFO msg=DST t=993000|1038999 id=12421 req="SearchPromises(id=p*1, states=[REJECTED_TIMEDOUT PENDING], tags=map[0:1.0 1:1.1], limit=10, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=993000|1038999 id=12422 req="SearchPromises(id=p*5, states=[REJECTED PENDING], tags=map[], limit=8, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=994000|1039999 id=12441 req="CreatePromiseAndTask(promise=CreatePromise(id=p1, idempotencyKey=<nil>, strict=false, param=Value(headers=map[0:4.0 1:4.1 2:4.2], data=3), timeout=998272, tags=map[0:17.0 resonate:invoke:dst resonate:timeout:true]), task=CreateTask(promiseId=p1, processId=p1, ttl=2848, timeout=998272))" res="CreatePromiseAndTask(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), task=<nil>)" err=<nil>
level=INFO msg=DST t=994000|1039999 id=12442 req="SearchSchedules(id=s*1, tags=map[0:11.0 resonate:timeout:true], limit=1, sortId=0)" res="SearchSchedules(status=2000, schedules=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=994000|1039999 id=12443 req="HeartbeatLocks(processId=1)" res="HeartbeatLocks(status=2000, locksAffected=2)" err=<nil>
level=INFO msg=DST t=995000|1040999 id=12457 req="ReadSchedule(id=s0)" res="ReadSchedule(status=4041, schedule=<nil>)" err=<nil>
level=INFO msg=DST t=995000|1040999 id=12458 req="CreateSubscription(id=sb1, promiseId=p1, recv=\"dst\")" res=Response err=<nil>
level=INFO msg=DST t=995000|1040999 id=12459 req="CreatePromiseAndTask(promise=CreatePromise(id=p1, idempotencyKey=4, strict=true, param=Value(headers=map[0:2.0 1:2.1 2:2.2], data=2), timeout=1002936, tags=map[0:1.0 1:1.1 resonate:invoke:dst]), task=CreateTask(promiseId=p1, processId=p1, ttl=1965, timeout=1002936))" res="CreatePromiseAndTask(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), task=<nil>)" err=<nil>
level=INFO msg=DST t=996000|1041999 id=12479 req="AcquireLock(resourceId=1, executionId=1, processId=0, ttl=3418)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil>
level=INFO msg=DST t=996000|1041999 id=12480 req="CompletePromise(id=p0, idempotencyKey=9, strict=false, state=RESOLVED, value=Value(headers=map[0:13.0 1:13.1], data=2))" res="CompletePromise(status=4030, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449))" err=<nil>
level=INFO msg=DST t=996000|1041999 id=12481 req="CreateCallback(id=cb1, promiseId=p1, rootPromiseId=p1, timeout=996573, recv=\"dst\")" res="CreateCallback(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), callback=<nil>)" err=<nil>
level=INFO msg=DST t=997000|1042999 id=12497 req="CreatePromiseAndTask(promise=CreatePromise(id=p1, idempotencyKey=<nil>, strict=true, param=Value(headers=map[0:3.0], data=), timeout=999973, tags=map[resonate:invoke:dst]), task=CreateTask(promiseId=p1, processId=p1, ttl=3634, timeout=999973))" res="CreatePromiseAndTask(status=4090, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), task=<nil>)" err=<nil>
level=INFO msg=DST t=997000|1042999 id=12498 req="SearchPromises(id=p9*, states=[REJECTED_TIMEDOUT], tags=map[0:7.0 resonate:invoke:dst resonate:timeout:true], limit=4, sortId=0)" res="SearchPromises(status=2000, promises=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=997000|1042999 id=12499 req="AcquireLock(resourceId=0, executionId=0, processId=0, ttl=8052)" res="AcquireLock(status=4034, lock=<nil>)" err=<nil>
level=INFO msg=DST t=998000|1043999 id=12516 req="CreateCallback(id=cb1, promiseId=p1, rootPromiseId=p1, timeout=999569, recv=\"dst\")" res="CreateCallback(status=2000, promise=Promise(id=p1, state=REJECTED_TIMEDOUT, param=Value(headers=map[], data=3), value=Value(headers=map[], data=), timeout=1834, idempotencyKeyForCreate=5, idempotencyKeyForUpdate=<nil>, tags=map[resonate:invoke:dst], createdOn=2000, completedOn=1834), callback=<nil>)" err=<nil>
level=INFO msg=DST t=998000|1043999 id=12517 req="SearchSchedules(id=s*8, tags=map[0:19.0 resonate:timeout:true], limit=9, sortId=0)" res="SearchSchedules(status=2000, schedules=[], cursor=<nil>)" err=<nil>
level=INFO msg=DST t=998000|1043999 id=12518 req="DeleteSchedule(id=s0)" res="DeleteSchedule(status=4041)" err=<nil>
level=INFO msg=DST t=999000|1044999 id=12528 req="CreatePromise(id=p0, idempotencyKey=7, strict=false, param=Value(headers=map[], data=), timeout=1006634, tags=map[])" res="CreatePromise(status=4090, promise=Promise(id=p0, state=RESOLVED, param=Value(headers=map[0:16.0 1:16.1], data=0), value=Value(headers=map[], data=), timeout=8449, idempotencyKeyForCreate=<nil>, idempotencyKeyForUpdate=<nil>, tags=map[0:11.0 resonate:invoke:dst resonate:timeout:true], createdOn=2000, completedOn=8449))" err=<nil>
level=INFO msg=DST t=999000|1044999 id=12529 req="CreateSubscription(id=sb0, promiseId=p1, recv=\"dst\")" res=Response err=<nil>
level=INFO msg=DST t=999000|1044999 id=12530 req="CreateSubscription(id=sb1, promiseId=p1, recv=\"dst\")" res=Response err=<nil>
level=ERROR msg="DST timed out before linearizability could be determined"
Error: DST failed for seed='14515'
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")
  -v, --verbose                                   log additional information when run is non linearizable
      --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)
      --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-addr string                      http server address (default ":8001")
      --api-http-auth stringToString              http basic auth username password pairs (default [])
      --api-http-timeout duration                 http server graceful shutdown timeout (default 10s)
      --api-http-task-frequency duration          default task frequency (default 1m0s)
      --api-grpc-enable                           enable subsystem
      --api-grpc-addr string                      grpc server address (default ":50051")
      --aio-size range                            completion buffered channel size (default 1:1000)
      --aio-router-enable                         enable subsystem (default true)
      --aio-router-size int                       submission buffered channel size (default 100)
      --aio-router-workers int                    number of workers (default 1)
      --aio-sender-enable                         enable subsystem (default true)
      --aio-sender-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-addr string                       prometheus metrics server address (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")

more details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
0 participants