rkern / line_profiler

(OLD REPO) Line-by-line profiling for Python - Current repo ->
https://github.com/pyutils/line_profiler
Other
3.6k stars 254 forks source link

Is the profiling result accurate? #118

Closed Huarong closed 6 years ago

Huarong commented 6 years ago

I used line_profiler to analysis my code and got strange results.

why is the line 1023 so slow compared with other lines?

Total time: 0.18081 s
File: models.py
Function: __init__ at line 1018

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
  1018                                               @profile
  1019                                               def __init__(self, info=None):
  1020      9603      12309.0      1.3      6.8          self.drugs = []
  1021      9603      10613.0      1.1      5.9          self.drug_scores = []
  1022
  1023      9603     119325.0     12.4     66.0          self.hit_fit_diseases = {}
  1024      9603      12890.0      1.3      7.1          self.hit_fit_symptoms = {}
  1025      9603       7050.0      0.7      3.9          self.score = 0.0
  1026      9603      11925.0      1.2      6.6          self.is_notated = False
  1027
  1028      9603       6698.0      0.7      3.7          if info:
  1029                                                       self.from_dict(info)
rkern commented 6 years ago

I don't know. Is this repeatable? Are there threads in your program? If there are threads, then it is possible that you hit a context switch at this line.

Can you post a complete minimal example that we can run that demonstrates the issue? Is hit_fit_diseases a property?

Huarong commented 6 years ago

@rkern 1 Yes, It is repeatable. 2 Yes. I use it in Tornado. 3 hit_fit_diseases is not a property but a pure attribute.

I moved this piece of code to a simple script and the line_profiler worked as expected. So I guess it may related to threads.

Thanks for the great tool.