Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
mathieubrun opened this issue Mar 9, 2023 · 6 comments
Open

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

mathieubrun opened this issue Mar 9, 2023 · 6 comments

Comments

@mathieubrun
Copy link

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 mathieubrun changed the title Terraform very slow to create/update more than Terraform very slow to create/update more than 300 policies Mar 9, 2023
@mathieubrun
Copy link
Author

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
Copy link

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
Copy link
Author

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

@MaxxLiu22
Copy link

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
Copy link

Hi @mathieubrun ,

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

Thank,
Maxx

@mathieubrun
Copy link
Author

Hi @MaxxLiu22

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

Thanks,
Mathieu

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants