Very slow loading time after clicking complete order button in whmcs client side

[rahulkg]

We noticed after clicking completeorder button in cart.php?a=checkout page , it takes more than 1 minute to load the invoice , we removed all hooks and all addons (except that coming with whmcs ) and switched to six theme and again found the loading time greater than 1 minute. so clients close the cart page and we got many blank invoices in whmcs. How to solve this issue. when checked with whmcs support they told the following

" I've placed some order on your installation to do some diagnosis, and observed the process of inserting the service and order into your MySQL database takes about 30 seconds.
Generating the invoice and invoice line items takes about 20 seconds
Sending the emails takes a further 8-10 seconds.

The time taken to send emails is dictated by the speed of your mail server, so isn't something WHMCS can control. However I'd expect the records to be inserted into the database faster. WHMCS uses efficient MySQL to insert data with the fewest connections possible, meaning it can handle 10,000's clients and 100,000's services. 
To diagnose performance in further details, it would be necessary to use strace on the server.

Specifically, attach it to the /sailors/orderadd.php file, place an order via the admin area, stop strace, then review the logs.

This should help determine where the slowness is occurring; for example is there a wait for the MySQL server to connect or to write to the database
Depending upon where the delay is located will depend upon where your server administrator can look to optimize the server configuration or introduce additional processing power/memory as appropriate to reduce the delays."

I have checked https://www.thegeekdiary.com/how-to-use-strace-and-ltrace-commands-in-linux/ for installing strace in server. Can you advise us further how to  use strace commands to check this further by step by step manner.

[rahulkg]

We have tried to order a new product and run the following  strace command
# strace -t -f -o strace.txt /usr/bin/php ordersadd.php

and got the following logs

" access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
23013 11:24:35 open("/usr/lib/x86_64-linux-gnu/libargon2.so.1", O_RDONLY|O_CLOEXEC) = 3
23013 11:24:35 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\16\0\0\0\0\0\0"..., 832) = 832
23013 11:24:35 fstat(3, {st_mode=S_IFREG|0644, st_size=34792, ...}) = 0
23013 11:24:35 mmap(NULL, 2130128, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fed3a9b1000
23013 11:24:35 mprotect(0x7fed3a9b9000, 2093056, PROT_NONE) = 0
23013 11:24:35 mmap(0x7fed3abb8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7fed3abb8000
23013 11:24:35 close(3)                 = 0
23013 11:24:35 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
23013 11:24:35 open("/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
23013 11:24:35 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220:\0\0\0\0\0\0"..., 832) = 832
23013 11:24:35 fstat(3, {st_mode=S_IFREG|0644, st_size=84856, ...}) = 0
23013 11:24:35 mmap(NULL, 2189928, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fed3a79a000
23013 11:24:35 mprotect(0x7fed3a7ae000, 2093056, PROT_NONE) = 0
23013 11:24:35 mmap(0x7fed3a9ad000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x7fed3a9ad000
23013 11:24:35 mmap(0x7fed3a9af000, 6760, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fed3a9af000
23013 11:24:35 close(3)                 = 0
23013 11:24:35 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
23013 11:24:35 open("/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
23013 11:24:35 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \"\0\0\0\0\0\0"..., 832) = 832
23013 11:24:35 fstat(3, {st_mode=S_IFREG|0644, st_size=109144, ...}) = 0
23013 11:24:35 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fed3adca000
23013 11:24:35 mmap(NULL, 2204200, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fed3a57f000
23013 11:24:35 mprotect(0x7fed3a599000, 2093056, PROT_NONE) = 0
23013 11:24:35 mmap(0x7fed3a798000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7fed3a798000
23013 11:24:35 close(3)                 = 0
23013 11:24:35 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
23013 11:24:35 open("/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
23013 11:24:35 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\27\0\0\0\0\0\0"..., 832) = 832
23013 11:24:35 fstat(3, {st_mode=S_IFREG|0644, st_size=448440, ...}) = 0
23013 11:24:35 mmap(NULL, 2543976, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fed3a311000
23013 11:24:35 mprotect(0x7fed3a37d000, 2097152, PROT_NONE) = 0
23013 11:24:35 mmap(0x7fed3a57d000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6c000) = 0x7fed3a57d000
23013 11:24:35 close(3)                 = 0
23013 11:24:35 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
23013 11:24:35 open("/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
23013 11:24:35 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200U\0\0\0\0\0\0"..., 832) = 832
23013 11:24:35 fstat(3, {st_mode=S_IFREG|0644, st_size=1051056, ...}) = 0
23013 11:24:35 mmap(NULL, 3146072, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fed3a010000
23013 11:24:35 mprotect(0x7fed3a110000, 2093056, PROT_NONE) = 0"

But dont get from above logs where the delay has occured . Can you advise further ?