fortinetdev / terraform-provider-fortios

Terraform Fortios provider
https://www.terraform.io/docs/providers/fortios/
Mozilla Public License 2.0
67 stars 48 forks source link

Terraform very slow to create/update more than 300 policies #263

Open mathieubrun opened 1 year ago

mathieubrun commented 1 year ago

Managing more than 300 policies is very slow using terraform : creating or updating objects take a between 5 and 10 seconds for each.

See:

fortios_firewall_policy.sample_policy_198: Modifications complete after 5s [id=128]
fortios_firewall_policy.sample_policy_172: Modifications complete after 6s [id=144]
fortios_firewall_policy.sample_policy_70: Modifications complete after 8s [id=78]
fortios_firewall_policy.sample_policy_108: Modifying... [id=169]
fortios_firewall_policy.sample_policy_22: Modifying... [id=32]
fortios_firewall_address.sample_address_322: Creating...
fortios_firewall_policy.sample_policy_235: Modifying... [id=243]
fortios_firewall_policy.sample_policy_293: Modifications complete after 5s [id=225]
fortios_firewall_policy.sample_policy_153: Modifying... [id=162]
fortios_firewall_policy.sample_policy_182: Modifications complete after 6s [id=156]
fortios_firewall_policy.sample_policy_23: Modifications complete after 7s [id=34]
fortios_firewall_policy.sample_policy_60: Modifying... [id=73]
fortios_firewall_policy.sample_policy_196: Modifying... [id=161]
fortios_firewall_address.sample_address_322: Creation complete after 4s [id=sample_address_322]
fortios_firewall_policy.sample_policy_235: Modifications complete after 4s [id=243]
fortios_firewall_policy.sample_policy_108: Modifications complete after 7s [id=169]
fortios_firewall_policy.sample_policy_22: Modifications complete after 6s [id=32]
fortios_firewall_policy.sample_policy_273: Modifying... [id=210]

I created a python script to generate terraform code exhibiting the issue (see below).

To reproduce, save the script as test.py and run the following commands:

# create 300 objects
./test.py create 300
terraform plan -out plan.json
terraform apply plan.json
# update objects
./main,py update 300
terraform plan -out plan.json
terraform apply plan.json

Interestingly, updating the script to remove the fortios_firewall_security_policyseq seems to improve performance. But without predictable sequencing, the policies are not very useful.

from string import Template
from sys import argv

address = Template("""resource "fortios_firewall_address" "sample_address_$index" {
  name   = "sample_address_$index"
  subnet = "$${cidrhost("10.0.0.0/8", $index)}/32"
  type   = "ipmask"
  lifecycle { create_before_destroy = true }
}

""")

service = Template("""resource "fortios_firewallservice_custom" "sample_service_$service" {
  name          = "sample_service_$service"
  tcp_portrange = 1000 + $service
  protocol      = "TCP/UDP/SCTP"
  lifecycle { create_before_destroy = true }
}

""")

policy = Template("""resource "fortios_firewall_policy" "sample_policy_$index" {
  name             = "sample_policy_$index"
  comments         = "sample_policy_$index $action"
  global_label     = "sample_policy"
  status           = "enable"
  logtraffic       = "all"
  logtraffic_start = "enable"
  action           = "accept"
  srcaddr {
    name = resource.fortios_firewall_address.sample_address_$src.name
  }
  dstaddr {
    name = resource.fortios_firewall_address.sample_address_$dst.name
  }
  service {
    name = resource.fortios_firewallservice_custom.sample_service_$service.name
  }
  srcintf {
    name = "any"
  }
  dstintf {
    name = "any"
  }
}

""")

sequence= Template("""resource "fortios_firewall_security_policyseq" "sample_sequence_$index" {
  policy_src_id         = resource.fortios_firewall_policy.sample_policy_$dst.id
  policy_dst_id         = $dst_pol
  alter_position        = "after"
  enable_state_checking = true
}

""")

count = 10
action = "create"
if len(argv) == 3:
    count = int(argv[1])
    action = argv[2]
else:
    exit()

with open('out.tf', 'w', encoding="utf-8") as f:
    for index in range(0, count):
        f.writelines([address.substitute(index=index)])
    for index in range(0, 10):
        f.writelines([service.substitute(service=index)])
    for index in range(0, count - 1):
        service = index%10
        if action != "create":
            service = (index+1)%10
        f.writelines([policy.substitute(index=index, src=index, dst=index+1,service=service, action=action)])
    for index in range(0, count - 2):
        dst_pol = f"resource.fortios_firewall_security_policyseq.sample_sequence_{index-1}.policy_src_id"
        if index == 0:
            dst_pol = f"resource.fortios_firewall_policy.sample_policy_{index}.id" 
        f.writelines([sequence.substitute(index=index, src=index, dst=index+1, dst_pol=dst_pol)])
mathieubrun commented 1 year ago

More information, running mitmproxy, it appears the bottleneck is client side. When updating all policies, there are a first batch of requests sent at the beginning :

13:17:55 HTTPS GET   firewall.host.name /api/v2/cmdb/system/global?access_token=XXXX        200  application/json  2.1k  16ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/189?access_token=XXXX  200  application/json  337b  48ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/477?access_token=XXXX  200  application/json  337b  40ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/272?access_token=XXXX  200  application/json  337b  33ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/188?access_token=XXXX  200  application/json  337b  34ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/250?access_token=XXXX  200  application/json  337b  33ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/238?access_token=XXXX  200  application/json  337b  35ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/397?access_token=XXXX  200  application/json  337b  38ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/50?access_token=XXXX   200  application/json  336b  37ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/160?access_token=XXXX  200  application/json  337b  37ms
13:17:55 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/243?access_token=XXXX  200  application/json  337b  37ms
13:17:55 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/189?access_token=XXXX  200  application/json  1.3k  11ms
13:17:55 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/477?access_token=XXXX  200  application/json  1.3k  11ms
13:17:55 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/272?access_token=XXXX  200  application/json  1.3k  16ms
13:17:55 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/188?access_token=XXXX  200  application/json  1.3k  11ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/250?access_token=XXXX  200  application/json  1.3k  10ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/238?access_token=XXXX  200  application/json  1.3k  12ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/397?access_token=XXXX  200  application/json  1.3k  11ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/50?access_token=XXXX   200  application/json  1.3k  11ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/160?access_token=XXXX  200  application/json  1.3k  16ms
13:17:56 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/243?access_token=XXXX  200  application/json  1.3k  11ms

And after that, requests are sent after a few seconds interval:

13:18:21 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/164?access_token=XXXX  200  application/json  337b  71ms
13:18:21 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/164?access_token=XXXX  200  application/json  1.3k  19ms
13:18:24 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/39?access_token=XXXX   200  application/json  336b  39ms
13:18:24 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/271?access_token=XXXX  200  application/json  337b  37ms
13:18:24 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/39?access_token=XXXX   200  application/json  1.3k  13ms
13:18:24 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/271?access_token=XXXX  200  application/json  1.3k  11ms
13:18:27 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/82?access_token=XXXX   200  application/json  336b  33ms
13:18:27 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/441?access_token=XXXX  200  application/json  337b  54ms
13:18:27 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/82?access_token=XXXX   200  application/json  1.3k  11ms
13:18:27 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/441?access_token=XXXX  200  application/json  1.3k  20ms
13:18:33 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/178?access_token=XXXX  200  application/json  337b 205ms
13:18:33 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/178?access_token=XXXX  200  application/json  1.3k  11ms
13:18:36 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/482?access_token=XXXX  200  application/json  337b  35ms
13:18:36 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/482?access_token=XXXX  200  application/json  1.3k  10ms
13:18:42 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/394?access_token=XXXX  200  application/json  337b  78ms
13:18:42 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/202?access_token=XXXX  200  application/json  337b  97ms
13:18:42 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/251?access_token=XXXX  200  application/json  337b  65ms
13:18:42 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/394?access_token=XXXX  200  application/json  1.3k  11ms
13:18:42 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/202?access_token=XXXX  200  application/json  1.3k  11ms
13:18:42 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/251?access_token=XXXX  200  application/json  1.3k  11ms
13:18:48 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/179?access_token=XXXX  200  application/json  337b 101ms
13:18:48 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/105?access_token=XXXX  200  application/json  337b  75ms
13:18:48 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/105?access_token=XXXX  200  application/json  1.3k  10ms
13:18:48 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/179?access_token=XXXX  200  application/json  1.3k  10ms
13:18:53 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/489?access_token=XXXX  200  application/json  337b  87ms
13:18:53 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/68?access_token=XXXX   200  application/json  336b 103ms
13:18:53 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/489?access_token=XXXX  200  application/json  1.3k  14ms
13:18:54 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/68?access_token=XXXX   200  application/json  1.3k  14ms
13:18:59 HTTPS PUT   firewall.host.name /api/v2/cmdb/firewall/policy/197?access_token=XXXX  200  application/json  337b  73ms
13:18:59 HTTPS GET   firewall.host.name /api/v2/cmdb/firewall/policy/197?access_token=XXXX  200  application/json  1.3k  11ms
MaxxLiu22 commented 1 year ago

Hi @mathieubrun ,

Thank you for your testing script, I run it on my local environment, every module is created less than 1 second, I guess there may be some limitation on client side.

fortios_firewall_security_policyseq.sample_sequence_291: Creation complete after 0s [id=290]
fortios_firewall_security_policyseq.sample_sequence_292: Creating...
fortios_firewall_security_policyseq.sample_sequence_292: Creation complete after 0s [id=291]
fortios_firewall_security_policyseq.sample_sequence_293: Creating...
fortios_firewall_security_policyseq.sample_sequence_293: Creation complete after 0s [id=192]
fortios_firewall_security_policyseq.sample_sequence_294: Creating...
fortios_firewall_security_policyseq.sample_sequence_294: Creation complete after 0s [id=165]
fortios_firewall_security_policyseq.sample_sequence_295: Creating...
fortios_firewall_security_policyseq.sample_sequence_295: Creation complete after 0s [id=166]
fortios_firewall_security_policyseq.sample_sequence_296: Creating...
fortios_firewall_security_policyseq.sample_sequence_296: Creation complete after 0s [id=84]
fortios_firewall_security_policyseq.sample_sequence_297: Creating...
fortios_firewall_security_policyseq.sample_sequence_297: Creation complete after 0s [id=148]

Thanks, Maxx

mathieubrun commented 1 year ago

Hi @MaxxLiu22 Thanks for the feedback. Could you try the update part as well ?

MaxxLiu22 commented 1 year ago

Hi @mathieubrun ,

I tried update part, result looks good to me.

fortios_firewall_security_policyseq.sample_sequence_290: Modifications complete after 0s [id=224]
fortios_firewall_security_policyseq.sample_sequence_291: Modifying... [id=38]
fortios_firewall_security_policyseq.sample_sequence_291: Modifications complete after 1s [id=8]
fortios_firewall_security_policyseq.sample_sequence_292: Modifying... [id=148]
fortios_firewall_security_policyseq.sample_sequence_292: Modifications complete after 0s [id=239]
fortios_firewall_security_policyseq.sample_sequence_293: Modifying... [id=122]
fortios_firewall_security_policyseq.sample_sequence_293: Modifications complete after 0s [id=240]
fortios_firewall_security_policyseq.sample_sequence_294: Modifying... [id=219]
fortios_firewall_security_policyseq.sample_sequence_294: Modifications complete after 0s [id=252]
fortios_firewall_security_policyseq.sample_sequence_295: Modifying... [id=221]
fortios_firewall_security_policyseq.sample_sequence_295: Modifications complete after 0s [id=254]
fortios_firewall_security_policyseq.sample_sequence_296: Modifying... [id=191]
fortios_firewall_security_policyseq.sample_sequence_296: Modifications complete after 0s [id=114]
fortios_firewall_security_policyseq.sample_sequence_297: Modifying... [id=177]
fortios_firewall_security_policyseq.sample_sequence_297: Modifications complete after 1s [id=201]

Thanks, Maxx

MaxxLiu22 commented 1 year ago

Hi @mathieubrun ,

It seems Terraform works well on my side, Do you find any other potential reason to cause this issue?

Thank, Maxx

mathieubrun commented 1 year ago

Hi @MaxxLiu22

The issue is still present on my side. Updating resources still takes ~8 seconds per resource.

Thanks, Mathieu