Investigate the bottlenecks in the codebase, causing slow imports

[sbs2001]

There are many possible causes of slow imports

1. Time spent in fetching data. This includes fetching the data(actual advisories + Version API calls) : Consider async for this.

2. Time spent in processing the data. This include converting data into Advisory. I can't think these can be significantly optmised further

3. Time spent in writing data to DB. This is possibly the bottleneck. Maybe a better indexing strategy, and reducing db queries.

[sbs2001]

So I did basic CProfile on the openssl importer, here is the report

In [1]: import pstats 
    ...: p = pstats.Stats('stats.file') 
    ...: p.sort_stats('tottime').print_stats(30)
Sat Jun 20 10:47:57 2020    stats.file

         13322904 function calls (12947201 primitive calls) in 138.252 seconds

   Ordered by: internal time
   List reduced from 7531 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    13760   14.728    0.001   15.530    0.001 {method 'execute' of 'psycopg2.extensions.cursor' objects}
     4772    8.259    0.002    8.259    0.002 {method 'commit' of 'psycopg2.extensions.connection' objects}
820974/712151    3.179    0.000    9.124    0.000 {built-in method builtins.hasattr}
   920874    2.844    0.000    3.509    0.000 {built-in method builtins.isinstance}
   109003    2.719    0.000    8.175    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/asgiref/local.py:46(_get_context_id)
578474/523402    2.551    0.000    8.187    0.000 {built-in method builtins.getattr}
    22159    2.407    0.000   27.104    0.001 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/query.py:1204(build_filter)
   109003    1.523    0.000   10.324    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/asgiref/local.py:82(_get_storage)
    79458    1.418    0.000    2.623    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/fields/related.py:630(foreign_related_fields)
107045/62727    1.403    0.000   17.181    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/compiler.py:418(compile)
   109003    1.387    0.000    3.017    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/asgiref/sync.py:321(get_current_task)
   108905    1.332    0.000   11.550    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/asgiref/local.py:98(__getattr__)
60370/32848    1.300    0.000   15.855    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/utils/asyncio.py:14(inner)
   142818    1.269    0.000    2.286    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/compiler.py:401(quote_name_unless_alias)
   465314    1.235    0.000    1.235    0.000 {method 'append' of 'list' objects}
    44318    1.207    0.000    2.802    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/query.py:1425(names_to_path)
     8986    1.164    0.000    8.998    0.001 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/compiler.py:195(get_select)
        1    1.068    1.068    1.069    1.069 {built-in method _socket.getaddrinfo}
     8986    1.001    0.000   27.712    0.003 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/compiler.py:481(as_sql)
    17979    0.970    0.000    2.225    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/query.py:295(clone)
    66913    0.930    0.000    3.188    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/expressions.py:768(as_sql)
     8987    0.872    0.000   30.618    0.003 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/query.py:1359(_add_q)
295705/232972    0.869    0.000   55.698    0.000 {built-in method builtins.len}
    66913    0.865    0.000    1.736    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/fields/__init__.py:395(get_col)
   111132    0.858    0.000    1.255    0.000 <frozen importlib._bootstrap>:389(parent)
    22159    0.848    0.000    9.447    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/lookups.py:166(process_lhs)
     8986    0.841    0.000    3.335    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/compiler.py:643(get_default_columns)
    22159    0.806    0.000    5.994    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/sql/query.py:1521(setup_joins)
     8988    0.791    0.000    1.631    0.000 /home/shivam/coding/opensource/vulnerablecode/venv/lib/python3.8/site-packages/django/db/models/base.py:405(__init__)
    60370    0.787    0.000    1.295    0.000 {built-in method _asyncio.get_event_loop}

Looking at the report, It validates that the obvious, db operations are the bottleneck, Next step is to analyse SQL queries made to insert a whole Advisory.

[sbs2001]

For this test I used the same DB(which was only populated by openssl)
Before Test stats:

vulnerabilities_impactedpackage 4017 rows
vulnerabilities_package 151 rows
vulnerabilities_resolvedpackage 347 rows
vulnerabilities_vulnerability 177 rows
vulnerabilities_vulnerabilityreference 80 rows

You can find contents of profiler.py in https://gist.github.com/sbs2001/85a6d6a3a4e9f988518a892bbf51389a .

To the actual report

In [1]: from django.db import connection                                                                                                                                            

In [2]: connection.queries                                                                                                                                                          
Out[2]: []

In [3]: import profiler                                                                                                                                                             

In [4]: profiler.update_advisory(profiler.sample_adv)                                                                                                                               

In [5]: connection.queries                                                                                                                                                          
Out[5]: 
[{'sql': 'SELECT "vulnerabilities_vulnerability"."id", "vulnerabilities_vulnerability"."cve_id", "vulnerabilities_vulnerability"."summary", "vulnerabilities_vulnerability"."cvss" FROM "vulnerabilities_vulnerability" WHERE "vulnerabilities_vulnerability"."cve_id" = \'CVE-2016-8703\' LIMIT 21',
  'time': '0.003'},
 {'sql': 'INSERT INTO "vulnerabilities_vulnerability" ("cve_id", "summary", "cvss") VALUES (\'CVE-2016-8703\', \'\', NULL) RETURNING "vulnerabilities_vulnerability"."id"',
  'time': '0.007'},
 {'sql': 'SELECT "vulnerabilities_vulnerabilityreference"."id", "vulnerabilities_vulnerabilityreference"."vulnerability_id", "vulnerabilities_vulnerabilityreference"."source", "vulnerabilities_vulnerabilityreference"."reference_id", "vulnerabilities_vulnerabilityreference"."url" FROM "vulnerabilities_vulnerabilityreference" WHERE ("vulnerabilities_vulnerabilityreference"."url" = \'https://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2016-8703\' AND "vulnerabilities_vulnerabilityreference"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_vulnerabilityreference" ("vulnerability_id", "source", "reference_id", "url") VALUES (179, \'\', \'\', \'https://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2016-8703\') RETURNING "vulnerabilities_vulnerabilityreference"."id"',
  'time': '0.002'},
 {'sql': 'SELECT "vulnerabilities_vulnerabilityreference"."id", "vulnerabilities_vulnerabilityreference"."vulnerability_id", "vulnerabilities_vulnerabilityreference"."source", "vulnerabilities_vulnerabilityreference"."reference_id", "vulnerabilities_vulnerabilityreference"."url" FROM "vulnerabilities_vulnerabilityreference" WHERE ("vulnerabilities_vulnerabilityreference"."url" = \'http://people.canonical.com/~ubuntu-security/cve/2016/CVE-2016-8703.html\' AND "vulnerabilities_vulnerabilityreference"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_vulnerabilityreference" ("vulnerability_id", "source", "reference_id", "url") VALUES (179, \'\', \'\', \'http://people.canonical.com/~ubuntu-security/cve/2016/CVE-2016-8703.html\') RETURNING "vulnerabilities_vulnerabilityreference"."id"',
  'time': '0.001'},
 {'sql': 'SELECT "vulnerabilities_vulnerabilityreference"."id", "vulnerabilities_vulnerabilityreference"."vulnerability_id", "vulnerabilities_vulnerabilityreference"."source", "vulnerabilities_vulnerabilityreference"."reference_id", "vulnerabilities_vulnerabilityreference"."url" FROM "vulnerabilities_vulnerabilityreference" WHERE ("vulnerabilities_vulnerabilityreference"."url" = \'https://blogs.gentoo.org/ago/2016/08/08/potrace-multiplesix-heap-based-buffer-overflow-in-bm_readbody_bmp-bitmap_io-c/\' AND "vulnerabilities_vulnerabilityreference"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_vulnerabilityreference" ("vulnerability_id", "source", "reference_id", "url") VALUES (179, \'\', \'\', \'https://blogs.gentoo.org/ago/2016/08/08/potrace-multiplesix-heap-based-buffer-overflow-in-bm_readbody_bmp-bitmap_io-c/\') RETURNING "vulnerabilities_vulnerabilityreference"."id"',
  'time': '0.001'},
 {'sql': 'SELECT "vulnerabilities_package"."id", "vulnerabilities_package"."type", "vulnerabilities_package"."namespace", "vulnerabilities_package"."name", "vulnerabilities_package"."version", "vulnerabilities_package"."subpath", "vulnerabilities_package"."qualifiers" FROM "vulnerabilities_package" WHERE ("vulnerabilities_package"."name" = \'potrace\' AND "vulnerabilities_package"."type" = \'deb\' AND "vulnerabilities_package"."version" = \'0.2.0\') LIMIT 21',
  'time': '0.002'},
 {'sql': 'INSERT INTO "vulnerabilities_package" ("type", "namespace", "name", "version", "subpath", "qualifiers") VALUES (\'deb\', NULL, \'potrace\', \'0.2.0\', NULL, \'{}\') RETURNING "vulnerabilities_package"."id"',
  'time': '0.002'},
 {'sql': 'SELECT "vulnerabilities_impactedpackage"."id", "vulnerabilities_impactedpackage"."vulnerability_id", "vulnerabilities_impactedpackage"."package_id" FROM "vulnerabilities_impactedpackage" WHERE ("vulnerabilities_impactedpackage"."package_id" = 155 AND "vulnerabilities_impactedpackage"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.002'},
 {'sql': 'INSERT INTO "vulnerabilities_impactedpackage" ("vulnerability_id", "package_id") VALUES (179, 155) RETURNING "vulnerabilities_impactedpackage"."id"',
  'time': '0.002'},
 {'sql': 'SELECT "vulnerabilities_package"."id", "vulnerabilities_package"."type", "vulnerabilities_package"."namespace", "vulnerabilities_package"."name", "vulnerabilities_package"."version", "vulnerabilities_package"."subpath", "vulnerabilities_package"."qualifiers" FROM "vulnerabilities_package" WHERE ("vulnerabilities_package"."name" = \'potrace\' AND "vulnerabilities_package"."type" = \'deb\' AND "vulnerabilities_package"."version" = \'0.3.0\') LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_package" ("type", "namespace", "name", "version", "subpath", "qualifiers") VALUES (\'deb\', NULL, \'potrace\', \'0.3.0\', NULL, \'{}\') RETURNING "vulnerabilities_package"."id"',
  'time': '0.001'},
 {'sql': 'SELECT "vulnerabilities_impactedpackage"."id", "vulnerabilities_impactedpackage"."vulnerability_id", "vulnerabilities_impactedpackage"."package_id" FROM "vulnerabilities_impactedpackage" WHERE ("vulnerabilities_impactedpackage"."package_id" = 156 AND "vulnerabilities_impactedpackage"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_impactedpackage" ("vulnerability_id", "package_id") VALUES (179, 156) RETURNING "vulnerabilities_impactedpackage"."id"',
  'time': '0.001'},
 {'sql': 'SELECT "vulnerabilities_package"."id", "vulnerabilities_package"."type", "vulnerabilities_package"."namespace", "vulnerabilities_package"."name", "vulnerabilities_package"."version", "vulnerabilities_package"."subpath", "vulnerabilities_package"."qualifiers" FROM "vulnerabilities_package" WHERE ("vulnerabilities_package"."name" = \'potrace\' AND "vulnerabilities_package"."type" = \'deb\' AND "vulnerabilities_package"."version" = \'2.14-2\') LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_package" ("type", "namespace", "name", "version", "subpath", "qualifiers") VALUES (\'deb\', NULL, \'potrace\', \'2.14-2\', NULL, \'{}\') RETURNING "vulnerabilities_package"."id"',
  'time': '0.001'},
 {'sql': 'SELECT "vulnerabilities_resolvedpackage"."id", "vulnerabilities_resolvedpackage"."vulnerability_id", "vulnerabilities_resolvedpackage"."package_id" FROM "vulnerabilities_resolvedpackage" WHERE ("vulnerabilities_resolvedpackage"."package_id" = 157 AND "vulnerabilities_resolvedpackage"."vulnerability_id" = 179) LIMIT 21',
  'time': '0.001'},
 {'sql': 'INSERT INTO "vulnerabilities_resolvedpackage" ("vulnerability_id", "package_id") VALUES (179, 157) RETURNING "vulnerabilities_resolvedpackage"."id"',
  'time': '0.002'}]

In [6]: total_time = 0                                                                                                                                                              

In [7]: for i in connection.queries :  
   ...:     total_time += float(i['time']) 
   ...:                                                                                                                                                                             

In [8]: total_time                                                                                                                                                                  
Out[8]: 0.034000000000000016

[pombredanne]

@sbs2001 did you also considered what indexes you have on the data? And is this ticket still relevant now?

[sbs2001]

Fixed due to improved imports via #219 and usage of async requests in #236