DataRecorder Captures Stale Data Due to Redundant Observable Triggers in _advance_time of model.py #3302
Description
Describe the bug
The DataRecorder captures incorrect intermediate states during event execution instead of the final state at each timestep. This occurs because model.time triggers the Observable signal before every event even when time hasn't changed.
When multiple events occur at the same simulation time, the DataRecorder captures data multiple times - once before each event executes. The final capture overwrites earlier ones, resulting in data that represents the state after some events but before others at that timestep.
Expected behavior
For the MRE below:
- Time 0.0: wealth should be 0 (initial state)
- Time 1.0: wealth should be 11 (after step: +1, then trade: +10)
- Time 2.0: wealth should be 22 (after step: +1, then trade: +10)
- Time 3.0: wealth should be 43 (after step: +1, then scheduled trade: +10, then recurring trade: +10)
- Time 4.0: wealth should be 54 (after step: +1, then trade: +10)
Actual behavior
unique_id wealth time
0 1 0 0.0
1 1 1 1.0
2 1 12 2.0
3 1 23 3.0
4 1 44 4.0
The DataRecorder shows values that suggest it's capturing after step() but before trade().
To Reproduce
from mesa import Model, Agent
from mesa.time import Schedule
from mesa.experimental.data_collection import DataRecorder
from mesa.datacollection import DataCollector
class MyAgent(Agent):
def __init__(self, model):
super().__init__(model)
self.wealth = 0
def step(self):
self.wealth += 1
class MyModel(Model):
def __init__(self):
super().__init__()
MyAgent.create_agents(self,1)
self.data_registry.track_agents(self.agents, "Wealth", "wealth")
self.datacollector = DataCollector(
agent_reporters={"Wealth": "wealth"},
)
self.recorder = DataRecorder(self)
self.schedule_event(self.trade, at=3.0)
self.schedule_recurring(
self.trade,
Schedule(interval=1)
)
self.datacollector.collect(self)
def step(self):
self.agents.shuffle_do("step")
self.datacollector.collect(self)
def trade(self):
for agent in self.agents:
agent.wealth += 10
self.datacollector.collect(self)
model = MyModel()
model.run_until(4)
print(f"New DataRecorder: \n{model.recorder.get_table_dataframe('Wealth').to_string()}\n")
print(f"Old DataCollector: \n{model.datacollector.get_agent_vars_dataframe().to_string()}")Note: Using either schedule_recurring() or schedule_event() will also reproduce the bug
MRE Output:
New DataRecorder:
unique_id wealth time
0 1 0 0.0
1 1 1 1.0
2 1 12 2.0
3 1 23 3.0
4 1 44 4.0
Old DataCollector:
Wealth
Step AgentID
0.0 1 0
1.0 1 11
2.0 1 22
3.0 1 43
4.0 1 54
Root Cause Analysis
The bug is in model.py in the _advance_time() method (line 220):
Lines 213 to 224 in 744df2a
Proposed Fix
if event.time <= until:
if self.time != event.time
self.time = event.time
event.execute()