degraded performance in 1.6.0 release

[codingjoe]

Describe the bug

I have seen a performance decrease in version 1.6.0. I a member of FussyFox and we run thousands of bandit checks a day. I see an increase in timeouts (200s limit) since I upgraded the stack to the 1.6.0 release.

My best guess, it's this commit 7c4b9fa
I will further investigate the issue.

The 200-second cap is because the sub process times out. The execution time would be even longer.

[codingjoe]

I believe those two lines cause the performance decrease:

bandit/bandit/formatters/text.py

Lines 144 to 146 in 7c4b9fa

	issues = manager.get_issue_list(sev_level, conf_level)
	if len(issues) or not manager.quiet:

I will further investigate.

[codingjoe]

@ericwb I am cc-ing you here too, since you released 1.6.0. Maybe you have another hint why the performance decreased so drastically. You can see in figure 1 how big the impact is, after the update.

[ehooo]

Hi @codingjoe I just try to find the delay on the code and I cannot find any on the Text formatter.
are you sure that it is not related to issue #438 ?

Could you share more information in order to find the root cause?
Could you tell us the parameters using to run the report?

When I run the line_profile using the example directory it not take delay.

Total time: 0.019999 s
File: ~/code/bandit/bandit/formatters/text.py
...
   151                                           
   152         1          0.0      0.0      0.0          bits.append("\nTest results:")
   153         1      18184.0  18184.0     90.9          bits.append(get_results(manager, sev_level, conf_level, lines))
   154         1          2.0      2.0      0.0          bits.append("\nCode scanned:")
...

[codingjoe]

@ehooo I am not so sure, it's the same problem, since the spike in run time only happens since version 1.6.0 not 1.5.x

[ehooo]

@codingjoe could you share more context to try to reproduce the issue?
Some project affected? the args used to run the report? the report format?, ...

[codingjoe]

@ehooo no specific project, this seems to have affected all kinds of projects.
Bandit is invoked as follows https://github.com/FussyFox/bandit/blob/39772b3e6528ab1f062f7b4190a9993d5937e78d/main.py#L12-L15

[bittner]

I am affected by this issue, too. It seem not to be a general performance issue, but really a bug that makes Bandit collect a large amount of files to inspect.

• When I run Bandit 1.5.1 over my project it takes a fraction of a second.
• When I run Bandit 1.6.0 over my project it counts something to almost 3000 and the CPU load goes up.

Example:

$ tox -e bandit                                                                                                                                                                                                                                                           
bandit installed: bandit==1.6.0,gitdb2==2.0.5,GitPython==2.1.11,pbr==5.2.1,PyYAML==5.1.1,six==1.12.0,smmap2==2.0.5,stevedore==1.30.1                                                                                                                                            
bandit run-test-pre: PYTHONHASHSEED='1925481915'                                                                                                                                                                                                                                
bandit runtests: commands[0] | bandit -r --ini tox.ini                                                                                                                                                                                                                          
[main]  INFO    Using ini file for excluded paths                                                                                                                                                                                                                               
[main]  INFO    Using ini file for selected targets                                                                                                                                                                                                                             
[main]  INFO    profile include tests: None                                                                                                                                                                                                                                     
[main]  INFO    profile exclude tests: None                                                                                                                                                                                                                                     
[main]  INFO    cli include tests: None                                                                                                                                                                                                                                         
[main]  INFO    cli exclude tests: None                                                                                                                                                                                                                                         
[main]  INFO    running on Python 3.6.8                                                                                                                                                                                                                                         
2946 [0.. 50.. 100.. 150.. 200.. 250.. 300.. 350.. ^C

Could it be that for some reason the excluded paths option has become defunct?

[ehooo]

Hi again.

I was working trying to find the root cause for that issue, but i think is affected just for some kind of code.
I mean is run bandit with trying to find the bottleneck.

The following code was used:

pip install bandit==1.5.1
git clone --branch 1.5.0 --single-branch https://github.com/PyCQA/bandit.git ../bandit
python analyse_bandit.py -r ../bandit/examples/

pip install bandit==1.6.0
python analyse_bandit.py -r ../bandit/examples/

pip install bandit==1.6.1
python analyse_bandit.py -r ../bandit/examples/

The results:
1.5.1py27 102.7241
1.6.0py27 97.6364
1.6.1py27 95.4089
1.5.1py3.7 4.2379
1.6.0py37 4.5011
1.6.1py37 4.7639

On python 2.7 we could see the bottleneck on "fnmatchcase"

But on 3.7 the only i could find the functions "isfile", "get_module_qualname..", and "_execute_ast_visit.."

But i not sure that it is the root case.

@bittner i think you issue is related with #488

Could someone give us some feedback to know if this case is solved on 1.6.1 or 1.6.2 version?

[codingjoe]

Thanks @ehooo for the in depth profiling. I upgraded @FussyFox two days ago from 1.5.1 to 1.6.2 and do NOT see an increase in real user time across a couple thousand executions across various code bases.

I guess case closed :)

[codingjoe]

Nope, I was immaturely excited :/
FussyFox/fussyfox.github.io#4 (comment)
There still seems to be an issue with version 1.6.x
I am trying to figure out if there is another problem showing up in the logs. I do see a slightly elevated error rate since the new release.

[bittner]

Why is this issue still closed? Shouldn't we reopen it?

I'm still pinning Bandit to <1.6, because bandit -r . scans .tox (and presumably similar folders such as .git) since 1.6.0 even though I use the --exclude .tox, ... option. This obviously takes significantly longer to complete as that folder typically contains several virtualenvs with a load full of Python packages downloaded from PyPI.