<SYSTEM_TASK:>
Given the following text description, write Python code to implement the functionality described below step by step
<END_TASK>
<USER_TASK:>
Description:
 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
Step1:  To collect information about model training times (both on CPU and GPU), one must set profile option in the model configuration to True
Step2:  To gather statistics about how long each action takes, we must set profile to True inside run call
Step3:  Pipeline profiling
First of all, there is an elapsed_time attribute inside every instance of Pipeline
Step4:  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
Step5:  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
Step6:  Model profiling
Step7:  There is an info property that, unsurprisingly, shows a lot of interesting details regarding model itself or the training process
Step8:  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)
<ASSISTANT_TASK:>
Python 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()
Explanation: 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.
End of explanation
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'))
                )
Explanation: To collect information about model training times (both on CPU and GPU), one must set profile option in the model configuration to True:
End of explanation
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}')))
Explanation: To gather statistics about how long each action takes, we must set profile to True inside run call:
End of explanation
pipeline.elapsed_time
Explanation: 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):
End of explanation
pipeline.profile_info.head()
Explanation: 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:
End of explanation
# 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)
Explanation: 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 method
More 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.
End of explanation
model = pipeline.m('resnet')
Explanation: Model profiling
End of explanation
model.info
Explanation: There is an info property that, unsurprisingly, shows a lot of interesting details regarding model itself or the training process:
End of explanation
# 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)
Explanation: 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)
End of explanation
<END_TASK>