agentsoz / bdi-abm-integration

BDI ABM Integration
GNU Lesser General Public License v3.0
8 stars 13 forks source link

Agents skipping initial response #68

Closed osbornejr closed 6 years ago

osbornejr commented 6 years ago

When testing behaviours I noticed that a resident with a dependent who had both their thresholds met simultaneously could potentially skip the INITIAL_RESPONSE step and jump straight to the ActNow plan options. This is a major issue because it means that the resident ignores their dependent and just evacuates.

To reproduce, see that as of 4ba84c50571bf7b8aea3135bef07f0482dada4e2 SurfCoastPopulationSubgroupSampleTest resident 3 has this behaviour. Here is their jill.out output:

Time -0001 Resident 3 : memory:-1:BELIEVED:DEPENDENTS_INFO:(Dependent, coords=778707.91,5745384.49), last visited at time=-1.0 Time 45002 Resident 3 : memory:45002:PERCEIVED:emergency_message:ADVICE,Emergency services are attending to a fire north of Anglesea Time 45002 Resident 3 : memory:45002:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.1 Time 50402 Resident 3 : memory:50402:PERCEIVED:emergency_message:ADVICE,13 vehicles are attending to the fire north of Anglesea Time 50402 Resident 3 : memory:50402:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.1 Time 52251 Resident 3 : memory:52251:PERCEIVED:field_of-view:sighted_embers Time 52251 Resident 3 : memory:52251:BELIEVED:RESPONSE_BAROMETER_FIELD_OF_VIEW_CHANGED=0.3 Time 52251 Resident 3 : memory:52251:DECIDED:INITIAL_RESPONSE_THRESHOLD_BREACHED Time 52251 Resident 3 : memory:52251:DECIDED:FINAL_RESPONSE_THRESHOLD_BREACHED Time 52251 Resident 3 : memory:52251:DECIDED:INITIAL_AND_FINAL_RESPONSE_THRESHOLDS_BREACHED_TOGETHER Time 52251 Resident 3 : memory:52251:DECIDED:TRIGGER_INITIAL_RESPONSE_NOW Time 52251 Resident 3 : memory:52251:DECIDED:TRIGGER_FINAL_RESPONSE_NOW Time 52251 Resident 3 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanGoHomeThenLeave=false Time 52251 Resident 3 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanLeaveNow=true Time 52251 Resident 3 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanDoNothing=true Time 52251 Resident 3 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:GoalGotoEvacPlace|PlanGotoEvacPlace=true Time 52251 Resident 3 : memory:52251:DECIDED:GOTO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0) Time 52251 Resident 3 : memory:52251:ACTIONED:drive_to:(Torquay Foreshore, coords=790771.0,5752462.0):18408m away Time 53103 Resident 3 : memory:53103:PERCEIVED:field_of-view:sighted_embers Time 53901 Resident 3 : memory:53901:PERCEIVED:arrived:41943-41945-41947-41949-41951-41953-41955-41957-41959-41961-41963-41965-41967-41969-41971 Time 53901 Resident 3 : memory:53901:BELIEVED:LAST_ENV_ACTION_STATE=PASSED Time 53901 Resident 3 : memory:53901:BELIEVED:DISTANCE_TO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0):0m Time 53901 Resident 3 : memory:53901:BELIEVED:SAFE Time 53901 Resident 3 : memory:53901:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanGoHomeThenLeave=false Time 53901 Resident 3 : memory:53901:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanLeaveNow=true Time 53901 Resident 3 : memory:53901:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanDoNothing=true Time 53901 Resident 3 : memory:53901:DECIDED:IS_PLAN_APPLICABLE:GoalGotoEvacPlace|PlanGotoEvacPlace=true Time 53901 Resident 3 : memory:53901:DECIDED:GOTO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0) Time 53901 Resident 3 : memory:53901:BELIEVED:DISTANCE_TO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0):0m Time 53901 Resident 3 : memory:53901:BELIEVED:SAFE Time 64805 Resident 3 : memory:64805:PERCEIVED:field_of-view:sighted_embers Time 65710 Resident 3 : memory:65710:PERCEIVED:field_of-view:sighted_embers Time 66605 Resident 3 : memory:66605:PERCEIVED:field_of-view:sighted_embers Time 67511 Resident 3 : memory:67511:PERCEIVED:field_of-view:sighted_embers Time 68402 Resident 3 : memory:68402:PERCEIVED:field_of-view:sighted_embers Time 69318 Resident 3 : memory:69318:PERCEIVED:field_of-view:sighted_embers Time 70205 Resident 3 : memory:70205:PERCEIVED:field_of-view:sighted_embers Time 71109 Resident 3 : memory:71109:PERCEIVED:field_of-view:sighted_embers Time 72018 Resident 3 : memory:72018:PERCEIVED:field_of-view:sighted_embers Time 72916 Resident 3 : memory:72916:PERCEIVED:field_of-view:sighted_embers Time 73816 Resident 3 : memory:73816:PERCEIVED:field_of-view:sighted_embers Time 74710 Resident 3 : memory:74710:PERCEIVED:field_of-view:sighted_embers Time 75602 Resident 3 : memory:75602:PERCEIVED:field_of-view:sighted_embers Time 76507 Resident 3 : memory:76507:PERCEIVED:field_of-view:sighted_embers Time 77511 Resident 3 : memory:77511:PERCEIVED:field_of-view:sighted_embers Time 78304 Resident 3 : memory:78304:PERCEIVED:field_of-view:sighted_embers

dhixsingh commented 6 years ago

Haven't found instances of this in the large 500 agents test SurfCoastShirePopulationSubgroupsTest. The closest I got was this where it seems that ActNow is happening before InitialResponse but it is not (just logging is out of order in that timestep):

Time -0001 VisitorDaytime 417 : memory:-1:BELIEVED:DEPENDENTS_INFO:null
Time 50402 VisitorDaytime 417 : memory:50402:PERCEIVED:emergency_message:ADVICE,13 vehicles are attending to the fire north of Anglesea
Time 50402 VisitorDaytime 417 : memory:50402:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.1
Time 54002 VisitorDaytime 417 : memory:54002:PERCEIVED:emergency_message:WATCH_AND_ACT,Bushfire north of Anglesea not under control yet
Time 54002 VisitorDaytime 417 : memory:54002:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.2
Time 54011 VisitorDaytime 417 : memory:54011:PERCEIVED:field_of-view:sighted_embers
Time 54011 VisitorDaytime 417 : memory:54011:BELIEVED:RESPONSE_BAROMETER_FIELD_OF_VIEW_CHANGED=0.3
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:INITIAL_RESPONSE_THRESHOLD_BREACHED
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:FINAL_RESPONSE_THRESHOLD_BREACHED
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:INITIAL_AND_FINAL_RESPONSE_THRESHOLDS_BREACHED_TOGETHER
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:TRIGGER_INITIAL_RESPONSE_NOW
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:TRIGGER_FINAL_RESPONSE_NOW
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanGoHomeThenLeave=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanLeaveNow=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanDoNothing=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:GoalGotoEvacPlace|PlanGotoEvacPlace=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:GOTO_LOCATION:(NSP Surf Club, coords=759414.662987548,5729942.34603638)
Time 54011 VisitorDaytime 417 : memory:54011:ACTIONED:drive_to:(NSP Surf Club, coords=759414.662987548,5729942.34603638):25607m away
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:InitialResponse|PlanGotoDependentsIfNearby=false
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:InitialResponse|PlanGoHomeIfDependentsAfar=false
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:InitialResponse|PlanInitialResponseWithoutDependents=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:IS_PLAN_APPLICABLE:InitialResponse|PlanDoNothing=true
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:DONE_FOR_NOW
Time 54011 VisitorDaytime 417 : memory:54011:DECIDED:GOTO_LOCATION:(NSP Surf Club, coords=759414.662987548,5729942.34603638)
Time 54011 VisitorDaytime 417 : memory:54011:ACTIONED:drive_to:(NSP Surf Club, coords=759414.662987548,5729942.34603638):25607m away
Time 55509 VisitorDaytime 417 : memory:55509:PERCEIVED:arrived:4378-4380-4382-4384
Time 55509 VisitorDaytime 417 : memory:55509:BELIEVED:LAST_ENV_ACTION_STATE=PASSED
Time 55509 VisitorDaytime 417 : memory:55509:BELIEVED:DISTANCE_TO_LOCATION:(NSP Surf Club, coords=759414.662987548,5729942.34603638):0m
Time 55509 VisitorDaytime 417 : memory:55509:BELIEVED:SAFE
dhixsingh commented 6 years ago

MIght be this is no longer an issue but leaving open for now.

osbornejr commented 6 years ago

Do you reproduce the output I posted above on the referenced commit? Even if it is unlikely, it is worrying that it can happen-- whatever process is going on the result is an agent ignoring their dependents.

dhixsingh commented 6 years ago

I just tried this. In that commit the random seed was not getting set correctly so the results are non-deterministic. I ran the test four times and got four slightly different logs but Resident 3 went to the dependents each time. Can't say I can reproduce this one. Can you @osbornejr?

osbornejr commented 6 years ago

As of latest commit, am still getting this behaviour. Hard to pin down though because it doesn't happen every time or with the same resident every time. Here is a read out of resident 4 on one run:

Time -0001 Resident 4 : memory:-1:BELIEVED:DEPENDENTS_INFO:(Dependent, coords=778707.91,5745384.49), last visited at time=-1.0 Time 45002 Resident 4 : memory:45002:PERCEIVED:emergency_message:ADVICE,Emergency services are attending to a fire north of Anglesea Time 45002 Resident 4 : memory:45002:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.1 Time 50402 Resident 4 : memory:50402:PERCEIVED:emergency_message:ADVICE,13 vehicles are attending to the fire north of Anglesea Time 50402 Resident 4 : memory:50402:BELIEVED:RESPONSE_BAROMETER_MESSAGES_CHANGED=0.1 Time 52251 Resident 4 : memory:52251:PERCEIVED:field_of-view:sighted_embers Time 52251 Resident 4 : memory:52251:BELIEVED:RESPONSE_BAROMETER_FIELD_OF_VIEW_CHANGED=0.3 Time 52251 Resident 4 : memory:52251:DECIDED:INITIAL_RESPONSE_THRESHOLD_BREACHED Time 52251 Resident 4 : memory:52251:DECIDED:FINAL_RESPONSE_THRESHOLD_BREACHED Time 52251 Resident 4 : memory:52251:DECIDED:INITIAL_AND_FINAL_RESPONSE_THRESHOLDS_BREACHED_TOGETHER Time 52251 Resident 4 : memory:52251:DECIDED:TRIGGER_INITIAL_RESPONSE_NOW Time 52251 Resident 4 : memory:52251:DECIDED:TRIGGER_FINAL_RESPONSE_NOW Time 52251 Resident 4 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanGoHomeThenLeave=false Time 52251 Resident 4 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanLeaveNow=true Time 52251 Resident 4 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanDoNothing=true Time 52251 Resident 4 : memory:52251:DECIDED:IS_PLAN_APPLICABLE:GoalGotoEvacPlace|PlanGotoEvacPlace=true Time 52251 Resident 4 : memory:52251:DECIDED:GOTO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0) Time 52251 Resident 4 : memory:52251:ACTIONED:drive_to:(Torquay Foreshore, coords=790771.0,5752462.0):18408m away Time 53189 Resident 4 : memory:53189:PERCEIVED:arrived:41943-41945-41947-41949-41951-41953-41955-41957-41959-41961-41963-41965-41967-41969-41971 Time 53189 Resident 4 : memory:53189:BELIEVED:LAST_ENV_ACTION_STATE=PASSED Time 53189 Resident 4 : memory:53189:BELIEVED:DISTANCE_TO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0):0m Time 53189 Resident 4 : memory:53189:BELIEVED:SAFE Time 53189 Resident 4 : memory:53189:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanGoHomeThenLeave=false Time 53189 Resident 4 : memory:53189:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanLeaveNow=true Time 53189 Resident 4 : memory:53189:DECIDED:IS_PLAN_APPLICABLE:ActNow|PlanDoNothing=true Time 53189 Resident 4 : memory:53189:DECIDED:IS_PLAN_APPLICABLE:GoalGotoEvacPlace|PlanGotoEvacPlace=true Time 53189 Resident 4 : memory:53189:DECIDED:GOTO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0) Time 53189 Resident 4 : memory:53189:BELIEVED:DISTANCE_TO_LOCATION:(Torquay Foreshore, coords=790771.0,5752462.0):0m Time 53189 Resident 4 : memory:53189:BELIEVED:SAFE Time 64805 Resident 4 : memory:64805:PERCEIVED:field_of-view:sighted_embers Time 65710 Resident 4 : memory:65710:PERCEIVED:field_of-view:sighted_embers Time 66605 Resident 4 : memory:66605:PERCEIVED:field_of-view:sighted_embers Time 67511 Resident 4 : memory:67511:PERCEIVED:field_of-view:sighted_embers Time 68402 Resident 4 : memory:68402:PERCEIVED:field_of-view:sighted_embers Time 69318 Resident 4 : memory:69318:PERCEIVED:field_of-view:sighted_embers Time 70205 Resident 4 : memory:70205:PERCEIVED:field_of-view:sighted_embers Time 71109 Resident 4 : memory:71109:PERCEIVED:field_of-view:sighted_embers Time 72018 Resident 4 : memory:72018:PERCEIVED:field_of-view:sighted_embers Time 72916 Resident 4 : memory:72916:PERCEIVED:field_of-view:sighted_embers Time 73816 Resident 4 : memory:73816:PERCEIVED:field_of-view:sighted_embers Time 74710 Resident 4 : memory:74710:PERCEIVED:field_of-view:sighted_embers Time 75602 Resident 4 : memory:75602:PERCEIVED:field_of-view:sighted_embers Time 76507 Resident 4 : memory:76507:PERCEIVED:field_of-view:sighted_embers Time 77511 Resident 4 : memory:77511:PERCEIVED:field_of-view:sighted_embers

I then could not reproduce it on any subsequent runs. Apart from this issue, is the seed working properly? Even the previous commit was after the seed was meant to have been fixed, so this in itself is worrying.

dhixsingh commented 6 years ago

Try disabling congestion rerouting as that causes some non determinism too. I will look again too.

dhixsingh commented 6 years ago

This issue was moved to agentsoz/ees#3