Profiling and debugging

Profiling

One of the main reasons people don’t use ABMs is because they can be very slow. While “vanilla Starsim” is quite fast (10,000 agents running for 100 timesteps should take about a second), custom modules, if not properly written, can be quite slow.

The first step of fixing a slow module is to identify the problem. To do this, Starsim includes some built-in profiling tools.

Let’s look at a simple simulation:

import sciris as sc
import starsim as ss
ss.options(jupyter=True)
sc.options(jupyter=True)

pars = dict(
    start = '2000-01-01',
    stop = '2020-01-01',
    diseases = 'sis',
    networks = 'random'
)

# Profile sim
sim = ss.Sim(pars)
prof = sim.profile()
Initializing sim with 10000 agents

Profiling 15 function(s):

 <bound method Sim.run of Sim(n=10000; 2000.01.01—2020.01.01; networks=randomnet; diseases=sis)>

<bound method Sim.start_step of Sim(n=10000; 2000.01.01—2020.01.01; networks=randomnet; diseases=sis [...]

<function Module.start_step at 0x7f3dd84985c0>

<function Module.start_step at 0x7f3dd84985c0>

<bound method SIS.step_state of sis(pars=[init_prev, beta, dur_inf, waning, imm_boost, _n_initial_ca [...]

<bound method DynamicNetwork.step of randomnet(n_edges=50000; pars=[n_contacts, dur, beta]; states=[ [...]

<bound method Infection.step of sis(pars=[init_prev, beta, dur_inf, waning, imm_boost, _n_initial_ca [...]

<bound method People.step_die of People(n=10000; age=30.0±17.3)>

<bound method People.update_results of People(n=10000; age=30.0±17.3)>

<bound method Network.update_results of randomnet(n_edges=50000; pars=[n_contacts, dur, beta]; state [...]

<function SIS.update_results at 0x7f3dd7e378a0>

<function Module.finish_step at 0x7f3dd84987d0>

<function Module.finish_step at 0x7f3dd84987d0>

<bound method People.finish_step of People(n=10000; age=30.0±17.3)>

<bound method Sim.finish_step of Sim(n=10000; 2000.01.01—2020.01.01; networks=randomnet; diseases=si [...] 




  Running 2000.01.01 ( 0/21) (0.00 s)  ———————————————————— 5%


  Running 2010.01.01 (10/21) (0.82 s)  ••••••••••—————————— 52%


  Running 2020.01.01 (20/21) (0.90 s)  •••••••••••••••••••• 100%



Elapsed time: 0.925 s





——————————————————————————————————————————————————————————————————————

Profile of networks.Network.update_results: 0.000507274 s (0.0548333%)

——————————————————————————————————————————————————————————————————————



Total time: 0.000507274 s

File: /home/runner/work/starsim/starsim/starsim/networks.py

Function: Network.update_results at line 254



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   254                                               def update_results(self):

   255                                                   """ Store the number of edges in the network """

   256        21      95962.0   4569.6     18.9          super().update_results()

   257        21     402789.0  19180.4     79.4          self.results['n_edges'][self.ti] = len(self)

   258        21       8523.0    405.9      1.7          return







————————————————————————————————————————————————————————————————

Profile of people.People.finish_step: 0.000916916 s (0.0991131%)

————————————————————————————————————————————————————————————————



Total time: 0.000916916 s

File: /home/runner/work/starsim/starsim/starsim/people.py

Function: People.finish_step at line 490



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   490                                               def finish_step(self):

   491        21     596905.0  28424.0     65.1          self.remove_dead()

   492        21     312149.0  14864.2     34.0          self.update_post()

   493        21       7862.0    374.4      0.9          return







———————————————————————————————————————————————————————————

Profile of people.People.step_die: 0.00205963 s (0.222634%)

———————————————————————————————————————————————————————————



Total time: 0.00205963 s

File: /home/runner/work/starsim/starsim/starsim/people.py

Function: People.step_die at line 452



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   452                                               def step_die(self):

   453                                                   """ Carry out any deaths or removals that took place this timestep """

   454        21    1753473.0  83498.7     85.1          death_uids = ((self.ti_dead <= self.sim.ti) | (self.ti_removed <= self.sim.ti)).uids

   455        21      88495.0   4214.0      4.3          self.alive[death_uids] = False  # Whilst not dead, removed agents should not be included in alive totals

   456                                           

   457                                                   # Execute deaths that took place this timestep (i.e., changing the `alive` state of the agents). This is executed

   458                                                   # before analyzers have run so that analyzers are able to inspect and record outcomes for agents that died this timestep

   459        42     162739.0   3874.7      7.9          for disease in self.sim.diseases():

   460        21      16419.0    781.9      0.8              if isinstance(disease, ss.Disease):

   461        21      29626.0   1410.8      1.4                  disease.step_die(death_uids)

   462                                           

   463        21       8877.0    422.7      0.4          return death_uids







————————————————————————————————————————————————————————————————

Profile of people.People.update_results: 0.0035537 s (0.384134%)

————————————————————————————————————————————————————————————————



Total time: 0.0035537 s

File: /home/runner/work/starsim/starsim/starsim/people.py

Function: People.update_results at line 481



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   481                                               def update_results(self):

   482        21      33349.0   1588.0      0.9          ti = self.sim.ti

   483        21      18127.0    863.2      0.5          res = self.sim.results

   484        21     698502.0  33262.0     19.7          res.n_alive[ti] = np.count_nonzero(self.alive)

   485        21    1002329.0  47730.0     28.2          res.new_deaths[ti] = np.count_nonzero(self.ti_dead == ti)

   486        21     870243.0  41440.1     24.5          res.new_emigrants[ti] = np.count_nonzero(self.ti_removed == ti)

   487        21     921353.0  43874.0     25.9          res.cum_deaths[ti] = np.sum(res.new_deaths[:ti]) # TODO: inefficient to compute the cumulative sum on every timestep!

   488        21       9798.0    466.6      0.3          return







————————————————————————————————————————————————————————————————

Profile of diseases.SIS.update_results: 0.00360167 s (0.389319%)

————————————————————————————————————————————————————————————————



Total time: 0.00360167 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: SIS.update_results at line 670



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   670                                               @ss.required()

   671                                               def update_results(self):

   672                                                   """ Store the population immunity (susceptibility) """

   673        21    2642133.0 125815.9     73.4          super().update_results()

   674        21     950712.0  45272.0     26.4          self.results['rel_sus'][self.ti] = self.rel_sus.mean()

   675        21       8827.0    420.3      0.2          return







——————————————————————————————————————————————————————

Profile of sim.Sim.start_step: 0.00520186 s (0.56229%)

——————————————————————————————————————————————————————



Total time: 0.00520186 s

File: /home/runner/work/starsim/starsim/starsim/sim.py

Function: Sim.start_step at line 438



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   438                                               def start_step(self):

   439                                                   """ Start the step -- only print progress; all actual changes happen in the modules """

   440                                           

   441                                                   # Set the time and if we have reached the end of the simulation, then do nothing

   442        21      13372.0    636.8      0.3          if self.complete:

   443                                                       errormsg = 'Simulation already complete (call sim.init() to re-run)'

   444                                                       raise AlreadyRunError(errormsg)

   445                                           

   446                                                   # Print out progress if needed

   447        21    3533491.0 168261.5     67.9          self.elapsed = self.timer.toc(output=True)

   448        21      15081.0    718.1      0.3          if self.verbose: # Print progress

   449        21      10800.0    514.3      0.2              t = self.t

   450        21     276298.0  13157.0      5.3              simlabel = f'"{self.label}": ' if self.label else ''

   451        21     865953.0  41235.9     16.6              string = f'  Running {simlabel}{t.now("str")} ({t.ti:2.0f}/{t.npts}) ({self.elapsed:0.2f} s) '

   452        21      16472.0    784.4      0.3              if self.verbose >= 1:

   453                                                           sc.heading(string)

   454        21      11975.0    570.2      0.2              elif self.verbose > 0:

   455        21      23254.0   1107.3      0.4                  if not (t.ti % int(1.0 / self.verbose)):

   456         3     425373.0 141791.0      8.2                      sc.progressbar(t.ti + 1, t.npts, label=string, length=20, newline=True)

   457        21       9789.0    466.1      0.2          return







————————————————————————————————————————————————————————————

Profile of diseases.SIS.step_state: 0.00579115 s (0.625989%)

————————————————————————————————————————————————————————————



Total time: 0.00579115 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: SIS.step_state at line 631



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   631                                               def step_state(self):

   632                                                   """ Progress infectious -> recovered """

   633        21    1426865.0  67946.0     24.6          recovered = (self.infected & (self.ti_recovered <= self.ti)).uids

   634        21      99272.0   4727.2      1.7          self.infected[recovered] = False

   635        21      66092.0   3147.2      1.1          self.susceptible[recovered] = True

   636        21    4189542.0 199502.0     72.3          self.update_immunity()

   637        21       9377.0    446.5      0.2          return







————————————————————————————————————————————————————————————

Profile of modules.Module.start_step: 0.0133938 s (1.44779%)

————————————————————————————————————————————————————————————



Total time: 0.0133938 s

File: /home/runner/work/starsim/starsim/starsim/modules.py

Function: Module.start_step at line 678



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   678                                               @required()

   679                                               def start_step(self):

   680                                                   """ Tasks to perform at the beginning of the step """

   681        42      31457.0    749.0      0.2          if self.finalized:

   682                                                       errormsg = f'The module {self._debug_name} has already been run. Did you mean to copy it before running it?'

   683                                                       raise RuntimeError(errormsg)

   684        42      23873.0    568.4      0.2          if self.dists is not None: # Will be None if no distributions are defined

   685        42   13317252.0 317077.4     99.4              self.dists.jump_dt() # Advance random number generators forward for calls on this step

   686        42      21209.0    505.0      0.2          return







———————————————————————————————————————————————————————————————

Profile of networks.DynamicNetwork.step: 0.0483088 s (5.22189%)

———————————————————————————————————————————————————————————————



Total time: 0.0483088 s

File: /home/runner/work/starsim/starsim/starsim/networks.py

Function: DynamicNetwork.step at line 412



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   412                                               def step(self):

   413        21   14340127.0 682863.2     29.7          self.end_pairs()

   414        21   33958477.0 1.62e+06     70.3          self.add_pairs()

   415        21      10165.0    484.0      0.0          return







—————————————————————————————————————————————————————————

Profile of diseases.Infection.step: 0.817697 s (88.3882%)

—————————————————————————————————————————————————————————



Total time: 0.817697 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: Infection.step at line 208



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   208                                               def step(self):

   209                                                   """

   210                                                   Perform key infection updates, including infection and setting prognoses

   211                                                   """

   212                                                   # Create new cases

   213        21  801704121.0 3.82e+07     98.0          new_cases, sources, networks = self.infect() # TODO: store outputs in self or use objdict rather than 3 returns

   214                                           

   215                                                   # Set prognoses

   216        21      15229.0    725.2      0.0          if len(new_cases):

   217        21   15964366.0 760207.9      2.0              self.set_outcomes(new_cases, sources)

   218                                           

   219        21      12961.0    617.2      0.0          return new_cases, sources, networks



Figure(672x480)

This graph (which is a shortcut to sim.loop.plot_cpu()) shows us how much time each step in the integration loop takes. We can get line-by-line detail of where each function is taking time, though:

prof.disp(maxentries=5)




——————————————————————————————————————————————————————

Profile of sim.Sim.start_step: 0.00520186 s (0.56229%)

——————————————————————————————————————————————————————



Total time: 0.00520186 s

File: /home/runner/work/starsim/starsim/starsim/sim.py

Function: Sim.start_step at line 438



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   438                                               def start_step(self):

   439                                                   """ Start the step -- only print progress; all actual changes happen in the modules """

   440                                           

   441                                                   # Set the time and if we have reached the end of the simulation, then do nothing

   442        21      13372.0    636.8      0.3          if self.complete:

   443                                                       errormsg = 'Simulation already complete (call sim.init() to re-run)'

   444                                                       raise AlreadyRunError(errormsg)

   445                                           

   446                                                   # Print out progress if needed

   447        21    3533491.0 168261.5     67.9          self.elapsed = self.timer.toc(output=True)

   448        21      15081.0    718.1      0.3          if self.verbose: # Print progress

   449        21      10800.0    514.3      0.2              t = self.t

   450        21     276298.0  13157.0      5.3              simlabel = f'"{self.label}": ' if self.label else ''

   451        21     865953.0  41235.9     16.6              string = f'  Running {simlabel}{t.now("str")} ({t.ti:2.0f}/{t.npts}) ({self.elapsed:0.2f} s) '

   452        21      16472.0    784.4      0.3              if self.verbose >= 1:

   453                                                           sc.heading(string)

   454        21      11975.0    570.2      0.2              elif self.verbose > 0:

   455        21      23254.0   1107.3      0.4                  if not (t.ti % int(1.0 / self.verbose)):

   456         3     425373.0 141791.0      8.2                      sc.progressbar(t.ti + 1, t.npts, label=string, length=20, newline=True)

   457        21       9789.0    466.1      0.2          return







————————————————————————————————————————————————————————————

Profile of diseases.SIS.step_state: 0.00579115 s (0.625989%)

————————————————————————————————————————————————————————————



Total time: 0.00579115 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: SIS.step_state at line 631



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   631                                               def step_state(self):

   632                                                   """ Progress infectious -> recovered """

   633        21    1426865.0  67946.0     24.6          recovered = (self.infected & (self.ti_recovered <= self.ti)).uids

   634        21      99272.0   4727.2      1.7          self.infected[recovered] = False

   635        21      66092.0   3147.2      1.1          self.susceptible[recovered] = True

   636        21    4189542.0 199502.0     72.3          self.update_immunity()

   637        21       9377.0    446.5      0.2          return







————————————————————————————————————————————————————————————

Profile of modules.Module.start_step: 0.0133938 s (1.44779%)

————————————————————————————————————————————————————————————



Total time: 0.0133938 s

File: /home/runner/work/starsim/starsim/starsim/modules.py

Function: Module.start_step at line 678



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   678                                               @required()

   679                                               def start_step(self):

   680                                                   """ Tasks to perform at the beginning of the step """

   681        42      31457.0    749.0      0.2          if self.finalized:

   682                                                       errormsg = f'The module {self._debug_name} has already been run. Did you mean to copy it before running it?'

   683                                                       raise RuntimeError(errormsg)

   684        42      23873.0    568.4      0.2          if self.dists is not None: # Will be None if no distributions are defined

   685        42   13317252.0 317077.4     99.4              self.dists.jump_dt() # Advance random number generators forward for calls on this step

   686        42      21209.0    505.0      0.2          return







———————————————————————————————————————————————————————————————

Profile of networks.DynamicNetwork.step: 0.0483088 s (5.22189%)

———————————————————————————————————————————————————————————————



Total time: 0.0483088 s

File: /home/runner/work/starsim/starsim/starsim/networks.py

Function: DynamicNetwork.step at line 412



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   412                                               def step(self):

   413        21   14340127.0 682863.2     29.7          self.end_pairs()

   414        21   33958477.0 1.62e+06     70.3          self.add_pairs()

   415        21      10165.0    484.0      0.0          return







—————————————————————————————————————————————————————————

Profile of diseases.Infection.step: 0.817697 s (88.3882%)

—————————————————————————————————————————————————————————



Total time: 0.817697 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: Infection.step at line 208



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   208                                               def step(self):

   209                                                   """

   210                                                   Perform key infection updates, including infection and setting prognoses

   211                                                   """

   212                                                   # Create new cases

   213        21  801704121.0 3.82e+07     98.0          new_cases, sources, networks = self.infect() # TODO: store outputs in self or use objdict rather than 3 returns

   214                                           

   215                                                   # Set prognoses

   216        21      15229.0    725.2      0.0          if len(new_cases):

   217        21   15964366.0 760207.9      2.0              self.set_outcomes(new_cases, sources)

   218                                           

   219        21      12961.0    617.2      0.0          return new_cases, sources, networks


(Note that the names of the functions here refer to the actual functions called, which may not match the graph above. That’s because, for example, ss.SIS does not define its own step() method, but instead inherits step() from Infection. In the graph, this is shown as sis.step(), but is listed in the table as Infection.step(). This is because it’s referring to the actual code being run, so refers to where those lines of code exist in the codebase; there is no code corresponding to SIS.step() since it’s just inherited from Infection.step().)

If you want more detail, you can also define custom functions to follow. For example, we can see that ss.SIS.infect() takes the most time in ss.SIS.step(), so let’s profile that:

prof = sim.profile(follow=ss.SIS.infect, plot=False)
prof.disp()
Initializing sim with 10000 agents

Profiling 1 function(s):

 <function Infection.infect at 0x7f3dd7e364b0> 




  Running 2000.01.01 ( 0/21) (0.00 s)  ———————————————————— 5%


  Running 2010.01.01 (10/21) (0.08 s)  ••••••••••—————————— 52%


  Running 2020.01.01 (20/21) (0.15 s)  •••••••••••••••••••• 100%



Elapsed time: 0.176 s





————————————————————————————————————————————————————————————

Profile of diseases.Infection.infect: 0.0662263 s (37.6094%)

————————————————————————————————————————————————————————————



Total time: 0.0662263 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: Infection.infect at line 230



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   230                                               def infect(self):

   231                                                   """ Determine who gets infected on this timestep via transmission on the network """

   232        21      14004.0    666.9      0.0          new_cases = []

   233        21       7930.0    377.6      0.0          sources = []

   234        21       7576.0    360.8      0.0          networks = []

   235        21     611924.0  29139.2      0.9          betamap = self.validate_beta()

   236                                           

   237        21    1368093.0  65147.3      2.1          rel_trans = self.rel_trans.asnew(self.infectious * self.rel_trans)

   238        21    1035269.0  49298.5      1.6          rel_sus   = self.rel_sus.asnew(self.susceptible * self.rel_sus)

   239                                           

   240        42     144379.0   3437.6      0.2          for i, (nkey,route) in enumerate(self.sim.networks.items()):

   241        21      35106.0   1671.7      0.1              nk = ss.standardize_netkey(nkey)

   242                                           

   243                                                       # Main use case: networks

   244        21      13099.0    623.8      0.0              if isinstance(route, ss.Network):

   245        21     253010.0  12048.1      0.4                  if len(route): # Skip networks with no edges

   246        21      10330.0    491.9      0.0                      edges = route.edges

   247        21     352238.0  16773.2      0.5                      p1p2b0 = [edges.p1, edges.p2, betamap[nk][0]] # Person 1, person 2, beta 0

   248        21     334397.0  15923.7      0.5                      p2p1b1 = [edges.p2, edges.p1, betamap[nk][1]] # Person 2, person 1, beta 1

   249        63      43908.0    697.0      0.1                      for src, trg, beta in [p1p2b0, p2p1b1]:

   250        42      69989.0   1666.4      0.1                          if beta: # Skip networks with no transmission

   251        42    1188392.0  28295.0      1.8                              disease_beta = beta.to_prob(self.t.dt) if isinstance(beta, ss.Rate) else beta

   252        42    1696509.0  40393.1      2.6                              beta_per_dt = route.net_beta(disease_beta=disease_beta, disease=self) # Compute beta for this network and timestep

   253        42   49291345.0 1.17e+06     74.4                              randvals = self.trans_rng.rvs(src, trg) # Generate a new random number based on the two other random numbers

   254        42      37272.0    887.4      0.1                              args = (src, trg, rel_trans, rel_sus, beta_per_dt, randvals) # Set up the arguments to calculate transmission

   255        42    7358028.0 175191.1     11.1                              target_uids, source_uids = self.compute_transmission(*args) # Actually calculate it

   256        42      27273.0    649.4      0.0                              new_cases.append(target_uids)

   257        42      21199.0    504.7      0.0                              sources.append(source_uids)

   258        42     446485.0  10630.6      0.7                              networks.append(np.full(len(target_uids), dtype=ss_int, fill_value=i))

   259                                           

   260                                                       # Handle everything else: mixing pools, environmental transmission, etc.

   261                                                       elif isinstance(route, ss.Route):

   262                                                           # Mixing pools are unidirectional, only use the first beta value

   263                                                           disease_beta = betamap[nk][0].to_prob(self.t.dt) if isinstance(betamap[nk][0], ss.Rate) else betamap[nk][0]

   264                                                           target_uids = route.compute_transmission(rel_sus, rel_trans, disease_beta, disease=self)

   265                                                           new_cases.append(target_uids)

   266                                                           sources.append(np.full(len(target_uids), dtype=ss_float, fill_value=np.nan))

   267                                                           networks.append(np.full(len(target_uids), dtype=ss_int, fill_value=i))

   268                                                       else:

   269                                                           errormsg = f'Cannot compute transmission via route {type(route)}; please subclass ss.Route and define a compute_transmission() method'

   270                                                           raise TypeError(errormsg)

   271                                           

   272                                                   # Finalize

   273        21      16585.0    789.8      0.0          if len(new_cases) and len(sources):

   274        21     252912.0  12043.4      0.4              new_cases = ss.uids.cat(new_cases)

   275        21    1256683.0  59842.0      1.9              new_cases, inds = new_cases.unique(return_index=True)

   276        21     216187.0  10294.6      0.3              sources = ss.uids.cat(sources)[inds]

   277        21     104458.0   4974.2      0.2              networks = np.concatenate(networks)[inds]

   278                                                   else:

   279                                                       new_cases = ss.uids()

   280                                                       sources = ss.uids()

   281                                                       networks = np.empty(0, dtype=ss_int)

   282                                           

   283        21      11720.0    558.1      0.0          return new_cases, sources, networks







————————————————————————————————————————————————————————————

Profile of diseases.Infection.infect: 0.0662263 s (37.6094%)

————————————————————————————————————————————————————————————



Total time: 0.0662263 s

File: /home/runner/work/starsim/starsim/starsim/diseases.py

Function: Infection.infect at line 230



Line #      Hits         Time  Per Hit   % Time  Line Contents

==============================================================

   230                                               def infect(self):

   231                                                   """ Determine who gets infected on this timestep via transmission on the network """

   232        21      14004.0    666.9      0.0          new_cases = []

   233        21       7930.0    377.6      0.0          sources = []

   234        21       7576.0    360.8      0.0          networks = []

   235        21     611924.0  29139.2      0.9          betamap = self.validate_beta()

   236                                           

   237        21    1368093.0  65147.3      2.1          rel_trans = self.rel_trans.asnew(self.infectious * self.rel_trans)

   238        21    1035269.0  49298.5      1.6          rel_sus   = self.rel_sus.asnew(self.susceptible * self.rel_sus)

   239                                           

   240        42     144379.0   3437.6      0.2          for i, (nkey,route) in enumerate(self.sim.networks.items()):

   241        21      35106.0   1671.7      0.1              nk = ss.standardize_netkey(nkey)

   242                                           

   243                                                       # Main use case: networks

   244        21      13099.0    623.8      0.0              if isinstance(route, ss.Network):

   245        21     253010.0  12048.1      0.4                  if len(route): # Skip networks with no edges

   246        21      10330.0    491.9      0.0                      edges = route.edges

   247        21     352238.0  16773.2      0.5                      p1p2b0 = [edges.p1, edges.p2, betamap[nk][0]] # Person 1, person 2, beta 0

   248        21     334397.0  15923.7      0.5                      p2p1b1 = [edges.p2, edges.p1, betamap[nk][1]] # Person 2, person 1, beta 1

   249        63      43908.0    697.0      0.1                      for src, trg, beta in [p1p2b0, p2p1b1]:

   250        42      69989.0   1666.4      0.1                          if beta: # Skip networks with no transmission

   251        42    1188392.0  28295.0      1.8                              disease_beta = beta.to_prob(self.t.dt) if isinstance(beta, ss.Rate) else beta

   252        42    1696509.0  40393.1      2.6                              beta_per_dt = route.net_beta(disease_beta=disease_beta, disease=self) # Compute beta for this network and timestep

   253        42   49291345.0 1.17e+06     74.4                              randvals = self.trans_rng.rvs(src, trg) # Generate a new random number based on the two other random numbers

   254        42      37272.0    887.4      0.1                              args = (src, trg, rel_trans, rel_sus, beta_per_dt, randvals) # Set up the arguments to calculate transmission

   255        42    7358028.0 175191.1     11.1                              target_uids, source_uids = self.compute_transmission(*args) # Actually calculate it

   256        42      27273.0    649.4      0.0                              new_cases.append(target_uids)

   257        42      21199.0    504.7      0.0                              sources.append(source_uids)

   258        42     446485.0  10630.6      0.7                              networks.append(np.full(len(target_uids), dtype=ss_int, fill_value=i))

   259                                           

   260                                                       # Handle everything else: mixing pools, environmental transmission, etc.

   261                                                       elif isinstance(route, ss.Route):

   262                                                           # Mixing pools are unidirectional, only use the first beta value

   263                                                           disease_beta = betamap[nk][0].to_prob(self.t.dt) if isinstance(betamap[nk][0], ss.Rate) else betamap[nk][0]

   264                                                           target_uids = route.compute_transmission(rel_sus, rel_trans, disease_beta, disease=self)

   265                                                           new_cases.append(target_uids)

   266                                                           sources.append(np.full(len(target_uids), dtype=ss_float, fill_value=np.nan))

   267                                                           networks.append(np.full(len(target_uids), dtype=ss_int, fill_value=i))

   268                                                       else:

   269                                                           errormsg = f'Cannot compute transmission via route {type(route)}; please subclass ss.Route and define a compute_transmission() method'

   270                                                           raise TypeError(errormsg)

   271                                           

   272                                                   # Finalize

   273        21      16585.0    789.8      0.0          if len(new_cases) and len(sources):

   274        21     252912.0  12043.4      0.4              new_cases = ss.uids.cat(new_cases)

   275        21    1256683.0  59842.0      1.9              new_cases, inds = new_cases.unique(return_index=True)

   276        21     216187.0  10294.6      0.3              sources = ss.uids.cat(sources)[inds]

   277        21     104458.0   4974.2      0.2              networks = np.concatenate(networks)[inds]

   278                                                   else:

   279                                                       new_cases = ss.uids()

   280                                                       sources = ss.uids()

   281                                                       networks = np.empty(0, dtype=ss_int)

   282                                           

   283        21      11720.0    558.1      0.0          return new_cases, sources, networks


(Note: you can only follow functions that are called as part of sim.run() this way. To follow other functions, such as those run by sim.init(), you can use sc.profile() directly.)

Debugging

When figuring out what your sim is doing – whether it’s doing something it shouldn’t be, or not doing something it should – sim.loop is your friend. It shows everything that will happen in the sim, and in what order:

import starsim as ss

sim = ss.Sim(
    start = 2000,
    stop = 2002,
    diseases = 'sis',
    networks = 'random',
    verbose = 0,
)
sim.run()
sim.loop.df.disp()
# %%
    time  ti  func_order                     label     module       func_name    cpu_time
0   2000   0           0            sim.start_step        sim      start_step  3.4356e-04
1   2000   0           1      randomnet.start_step  randomnet      start_step  1.8969e-04
2   2000   0           2            sis.start_step        sis      start_step  2.3185e-04
3   2000   0           3            sis.step_state        sis      step_state  1.0892e-04
4   2000   0           4            randomnet.step  randomnet            step  1.4802e-03
5   2000   0           5                  sis.step        sis            step  3.6242e-03
6   2000   0           6           people.step_die     people        step_die  5.3280e-05
7   2000   0           7     people.update_results     people  update_results  8.4187e-05
8   2000   0           8  randomnet.update_results  randomnet  update_results  1.5269e-05
9   2000   0           9        sis.update_results        sis  update_results  9.2813e-05
10  2000   0          10     randomnet.finish_step  randomnet     finish_step  7.6840e-06
11  2000   0          11           sis.finish_step        sis     finish_step  2.7550e-06
12  2000   0          12        people.finish_step     people     finish_step  2.3774e-05
13  2000   0          13           sim.finish_step        sim     finish_step  4.0880e-06
14  2001   1           0            sim.start_step        sim      start_step  6.8267e-05
15  2001   1           1      randomnet.start_step  randomnet      start_step  1.7717e-04
16  2001   1           2            sis.start_step        sis      start_step  2.2043e-04
17  2001   1           3            sis.step_state        sis      step_state  9.4546e-05
18  2001   1           4            randomnet.step  randomnet            step  1.3380e-03
19  2001   1           5                  sis.step        sis            step  2.3453e-03
20  2001   1           6           people.step_die     people        step_die  4.7068e-05
21  2001   1           7     people.update_results     people  update_results  7.1253e-05
22  2001   1           8  randomnet.update_results  randomnet  update_results  1.2514e-05
23  2001   1           9        sis.update_results        sis  update_results  8.0820e-05
24  2001   1          10     randomnet.finish_step  randomnet     finish_step  6.6130e-06
25  2001   1          11           sis.finish_step        sis     finish_step  2.3940e-06
26  2001   1          12        people.finish_step     people     finish_step  1.9286e-05
27  2001   1          13           sim.finish_step        sim     finish_step  3.1860e-06
28  2002   2           0            sim.start_step        sim      start_step  6.6394e-05
29  2002   2           1      randomnet.start_step  randomnet      start_step  1.4487e-04
30  2002   2           2            sis.start_step        sis      start_step  2.2061e-04
31  2002   2           3            sis.step_state        sis      step_state  8.6071e-05
32  2002   2           4            randomnet.step  randomnet            step  1.5233e-03
33  2002   2           5                  sis.step        sis            step  2.2678e-03
34  2002   2           6           people.step_die     people        step_die  4.5164e-05
35  2002   2           7     people.update_results     people  update_results  6.9139e-05
36  2002   2           8  randomnet.update_results  randomnet  update_results  1.1491e-05
37  2002   2           9        sis.update_results        sis  update_results  7.7425e-05
38  2002   2          10     randomnet.finish_step  randomnet     finish_step  5.9610e-06
39  2002   2          11           sis.finish_step        sis     finish_step  2.4350e-06
40  2002   2          12        people.finish_step     people     finish_step  1.9035e-05
41  2002   2          13           sim.finish_step        sim     finish_step  3.1360e-06

As you can see, it’s a lot – this is only three timesteps and two modules, and it’s already 41 steps.

The typical way to do debugging is to insert breakpoints or print statements into your modules for custom debugging (e.g., to print a value), or to use analyzers for heavier-lift debugging. Starsim also lets you manually modify the loop by inserting “probes” or other arbitrary functions. For example, if you wanted to check the population size after each time the People object is updated:

def check_pop_size(sim):
    print(f'Population size is {len(sim.people)}')

sim = ss.Sim(diseases='sir', networks='random', demographics=True, dur=10)
sim.init()
sim.loop.insert(check_pop_size, label='people.finish_step')
sim.run()
Initializing sim with 10000 agents
  Running 2000.01.01 ( 0/11) (0.00 s)  •——————————————————— 9%
Population size is 10191
Population size is 10264
Population size is 10357
Population size is 10447
Population size is 10557
Population size is 10664
Population size is 10739
Population size is 10817
Population size is 10917
Population size is 11033
  Running 2010.01.01 (10/11) (0.08 s)  •••••••••••••••••••• 100%

Population size is 11124
Sim(n=10000; 2000—2010.0; demographics=births, deaths; networks=randomnet; diseases=sir)

In this case, you get the same output as using an analyzer:

def check_pop_size(sim):
    print(f'Population size is {len(sim.people)}')

sim = ss.Sim(diseases='sir', networks='random', demographics=True, dur=10, analyzers=check_pop_size)
sim.run()
Initializing sim with 10000 agents
  Running 2000.01.01 ( 0/11) (0.00 s)  •——————————————————— 9%
Population size is 10191
Population size is 10264
Population size is 10357
Population size is 10447
Population size is 10557
Population size is 10664
Population size is 10739
Population size is 10817
Population size is 10917
Population size is 11033
  Running 2010.01.01 (10/11) (0.08 s)  •••••••••••••••••••• 100%

Population size is 11124
Sim(n=10000; 2000—2010.0; demographics=births, deaths; networks=randomnet; diseases=sir; analyzers=check_pop_size)

However, inserting functions directly in the loop gives you more control over their exact placement, whereas analyzers are always executed last in the timestep.

The loop also has methods for visualizing itself. You can get a simple representation of the loop with loop.plot():

sim.loop.plot()
Figure(672x480)

Or a slightly more detailed one with loop.plot_step_order():

sim.loop.plot_step_order()
Figure(672x480)

This is especially useful if your simulation has modules with different timesteps, e.g.:

sis = ss.SIS(dt=0.1)
net = ss.RandomNet(dt=0.5)
births = ss.Births(dt=1)
sim = ss.Sim(dt=0.1, dur=5, diseases=sis, networks=net, demographics=births)
sim.init()
sim.loop.plot_step_order()
Initializing sim with 10000 agents
Figure(672x480)

(Note: this is a 3D plot, so it helps if you can plot it in a separate window interactively to be able to move it around, rather than just in a notebook.)