<jupyter_start><jupyter_text>Profiling BatchFlow code A profile is a set of statistics that describes how often and for how long various parts of the program executed.This notebooks shows how to profile various parts of BatchFlow: namely, pipelines and models.<jupyter_code>import sys

sys.path.append("../../..")
from batchflow import B, V, W
from batchflow.opensets import MNIST
from batchflow.models.torch import ResNet18
dataset = MNIST()<jupyter_output><empty_output><jupyter_text>To collect information about model training times (both on CPU and GPU), one must set `profile` option in the model configuration to `True`:<jupyter_code>model_config = {
    'inputs/labels/classes': 10,
    'loss': 'ce',
    'profile': True,
}
pipeline = (dataset.train.p
                .init_variable('loss_history', [])
                .to_array(channels='first', dtype='float32')
                .multiply(multiplier=1/255., preserve_type=False)
                .init_model('dynamic', ResNet18,
                            'resnet', config=model_config)
                .train_model('resnet',
                             B.images, B.labels,
                             fetches='loss',
                             save_to=V('loss_history', mode='a'))
                )<jupyter_output><empty_output><jupyter_text>To gather statistics about how long each action takes, we must set `profile` to `True` inside `run` call:<jupyter_code>BATCH_SIZE = 64
N_ITERS = 50

pipeline.run(BATCH_SIZE, n_iters=N_ITERS, bar=True, profile=True,
                   bar_desc=W(V('loss_history')[-1].format('Loss is {:7.7}')))<jupyter_output>Loss is 0.1426592: 100%|██████████| 50/50 [01:22<00:00,  1.29s/it]<jupyter_text>Pipeline profiling First of all, there is an `elapsed_time` attribute inside every instance of `Pipeline`: it stores total time of running the pipeline (even if it was used multiple times):<jupyter_code>pipeline.elapsed_time<jupyter_output><empty_output><jupyter_text>Note that `elapsed_time` attribute is created whether or not we set `profile` to `True`.After running with `profile=True`, pipeline has attribute `profile_info`: this `DataFrame` holds collected information:<jupyter_code>pipeline.profile_info.head()<jupyter_output><empty_output><jupyter_text>Note that there is a detailed information about exact methods that are called inside each of the actions. That is a lot of data which can give us precise understanding of parts of the code, that are our bottlenecks.Columns of the `profile_info`:- `action`, `iter`, `batch_id` and `start_time` are pretty self-explainable- `id` allows to identify exact method with great details: it is a concatenation of `method_name`, `file_name`, `line_number` and `callee`- `total_time` is a time taken by an action- `pipeline_time` is `total_time` plus time of processing the profiling table at each iteration- `tottime` is a time taken by a method inside action- `cumtime` is a time take by a method and all of the methods that are called inside this methodMore often than not, though, we don't need such granularity. Pipeline method `show_profile_info` makes some handy aggregations:**Note:** by default, results are sorted on `total_time` or `tottime`, depending on level of details.<jupyter_code># timings for each action
pipeline.show_profile_info(per_iter=False, detailed=False)
# for each action show 2 of the slowest methods, based on maximum `ncalls`
pipeline.show_profile_info(per_iter=False, detailed=True, sortby=('ncalls', 'max'), limit=2)
# timings for each action for each iter
pipeline.show_profile_info(per_iter=True, detailed=False,)
# for each iter each action show 3 of the slowest methods, based on maximum `ncalls`
pipeline.show_profile_info(per_iter=True, detailed=True, sortby='tottime', limit=3)<jupyter_output><empty_output><jupyter_text>Model profiling<jupyter_code>model = pipeline.m('resnet')<jupyter_output><empty_output><jupyter_text>There is an `info` property that, unsurprisingly, shows a lot of interesting details regarding model itself or the training process:<jupyter_code>model.info<jupyter_output>##### Config:
{'benchmark': True,
 'body': {'encoder': {'blocks': {'base': <class 'batchflow.models.torch.blocks.ResBlock'>,
                                 'bottleneck': False,
                                 'downsample': [False, True, True, True],
                                 'filters': [64, 128, 256, 512],
                                 'layout': 'cnacn',
                                 'n_reps': [2, 2, 2, 2],
                                 'se': False},
                      'downsample': {'layout': 'p',
                                     'pool_size': 2,
                                     'pool_strides': 2},
                      'num_stages': 4,
                      'order': ['skip', 'block']}},
 'common': {'data_format': 'channels_first'},
 'decay': None,
 'device': None,
 'head': {'classes': 10,
          'dropout_rate': 0.4,
          'filters': 10,
          'layout': 'Vdf',
          'target_shape': (64,),
          'units': 10},
 'initial_block': {'filters'[...]<jupyter_text>As with pipeline, there is a `profile_info` attribute, as well as `show_profile_info` method. Depending on type of the used device (`CPU` or `GPU`)<jupyter_code># one row for every operation inside model; limit at 5 rows
model.show_profile_info(per_iter=False, limit=5)
# for each iteration show 3 of the slowest operations
model.show_profile_info(per_iter=True, limit=3)<jupyter_output><empty_output>
StarcoderdataJupyterStructuredCleanDedup