Performance toolkit exits before running any scenarios

[sshymko]

The Magento Performance Toolkit is unable to run against a vanilla Magento 2 instance installed from scratch with the required fixture data. It successfully completes the preliminary preparation steps, but never gets to execute any frontend scenarios. JMeter exits without any errors.

Preconditions (*)

1. Magento 2.2.7 w/ Redis session storage

mysql -e "CREATE DATABASE magento2"

git clone https://github.com/magento/magento2.git
cd magento2/
git checkout -b v2.2.7 2.2.7

composer install --no-dev
chmod -R ug+rwX app/etc/ var/ pub/media/
php bin/magento setup:install \
    --base-url="http://127.0.0.1/" \
    --backend-frontname="admin" \
    --use-rewrites=1 \
    --db-host="localhost" --db-name="magento2" \
    --admin-user="admin" --admin-password="123123q" \
    --admin-firstname="Admin" --admin-lastname="Admin" --admin-email="admin@example.com" \
    --language=en_US --currency=USD --timezone=America/Los_Angeles \
    --session-save=redis --session-save-redis-host=/var/run/redis.sock --session-save-redis-port=0 \
    --session-save-redis-db=0 --session-save-redis-disable-locking=1 --session-save-redis-log-level=3

php bin/magento config:set dev/static/sign 1
php bin/magento config:set dev/css/minify_files 1
php bin/magento config:set dev/js/minify_files 1
php bin/magento config:set dev/js/enable_js_bundling 1
php bin/magento config:set admin/security/admin_account_sharing 1
php bin/magento config:set admin/security/use_form_key 0

php bin/magento deploy:mode:set production
composer dump-autoload --no-dev --optimize

php bin/magento indexer:set-mode schedule
php bin/magento indexer:reindex

php bin/magento cache:flush

2. JMeter 3.1 w/ JSON plugin

sudo yum install java -y

curl -L -O https://archive.apache.org/dist/jmeter/binaries/apache-jmeter-3.1.tgz
tar -xzf apache-jmeter-3.1.tgz

curl -L -O https://jmeter-plugins.org/files/packages/jpgc-json-2.5.zip
unzip jpgc-json-2.5.zip -d ./apache-jmeter-3.1/

Steps to reproduce (*)

1. Generate fixture data

php bin/magento setup:performance:generate-fixtures setup/performance-toolkit/profiles/ce/small.xml

2. Run JMeter test plan

jmeter -n \
    -t magento2/setup/performance-toolkit/benchmark.jmx \
    -j jmeter.log \
    -l jmeter-results.jtl \
    -Jhost=127.0.0.1 \
    -Jbase_path=/ \
    -Jadmin_path=admin \
    -Jadmin_user=admin \
    -Jadmin_password=123123q \
    -Jfiles_folder=magento2/setup/performance-toolkit/files/ \
    -Jloops=1 \
    -JfrontendPoolUsers=1 \
    -JadminPoolUsers=0 \
    -JcsrPoolUsers=0 \
    -JothersPoolUsers=0

Expected result (*)

1. JMeter successfully runs all frontend scenarios

Actual result (*)

1. JMeter successfully completes the preparation (log in to admin, load products, categories, customers, etc.)
2. JMeter exits before executing any frontend scenarios

Writing log file to: /home/ec2-user/jmeter.log
Creating summariser <summary>
Created the tree successfully using /home/ec2-user/magento2/setup/performance-toolkit/benchmark.jmx
Starting the test @ Sun Feb 10 05:51:07 UTC 2019 (1549777867357)
Waiting for possible Shutdown/StopTestNow/Heapdump message on port 4445
summary =    224 in 00:00:05 =   45.0/s Avg:    15 Min:     0 Max:   676 Err:     0 (0.00%)
Tidying up ...    @ Sun Feb 10 05:51:12 UTC 2019 (1549777872774)
... end of run

3. Nginx access logs shows only preparation requests

3.81.150.213 - - [10/Feb/2019:07:33:39 +0000] "GET /admin HTTP/1.1" 302 5 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:39 +0000] "GET /admin/admin/ HTTP/1.1" 200 2358 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:39 +0000] "POST /admin/admin/dashboard/ HTTP/1.1" 302 5 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "GET /admin/admin/dashboard/ HTTP/1.1" 200 9246 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "GET /rest/V1/categories/list?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=path&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=1%2F2%2F%25&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5BconditionType%5D=like&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=level&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=2&searchCriteria%5BpageSize%5D=100 HTTP/1.1" 200 536 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "GET /rest/default/V1/categories/list?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=children_count&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=0&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=level&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=2&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B0%5D%5BconditionType%5D=gt&searchCriteria%5BpageSize%5D=0 HTTP/1.1" 200 892 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:40 +0000] "GET /rest/V1/products?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=type_id&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=configurable&searchCriteria%5BpageSize%5D=15 HTTP/1.1" 200 8107 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "GET /rest/V1/products?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=type_id&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=configurable&searchCriteria%5BpageSize%5D=15&searchCriteria%5BcurrentPage%5D=2 HTTP/1.1" 200 1271 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "GET /rest/V1/products?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=type_id&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=simple&searchCriteria%5BpageSize%5D=30&searchCriteria%5BcurrentPage%5D=1&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B1%5D%5Bfield%5D=attribute_set_id&searchCriteria%5BfilterGroups%5D%5B1%5D%5Bfilters%5D%5B1%5D%5Bvalue%5D=4 HTTP/1.1" 200 5550 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "POST /rest/V1/integration/admin/token HTTP/1.1" 200 65 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "GET /rest/V1/products?searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bfield%5D=type_id&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B0%5D%5Bvalue%5D=simple&searchCriteria%5BpageSize%5D=30&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B1%5D%5Bfield%5D!=attribute_set_id&searchCriteria%5BfilterGroups%5D%5B0%5D%5Bfilters%5D%5B1%5D%5Bvalue%5D=4 HTTP/1.1" 200 5528 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:41 +0000] "POST /admin/admin/user/roleGrid/limit/200/?ajax=true&isAjax=true HTTP/1.1" 200 3209 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:42 +0000] "GET /admin/customer/index/ HTTP/1.1" 200 7914 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:42 +0000] "GET /admin/mui/index/render/?namespace=customer_listing&sorting%5Bfield%5D=entity_id&sorting%5Bdirection%5D=asc&isAjax=true&filters%5Bplaceholder%5D=customer_since%5Blocale%5D%3Den_US&filters%5Bgroup_id%5D=1&filters%5Bwebsite_id%5D=1&paging%5BpageSize%5D=100&paging%5Bcurrent%5D=1&sorting%5Bfield%5D=entity_id&sorting%5Bdirection%5D=asc&isAjax=true HTTP/1.1" 200 1932 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:42 +0000] "GET /admin/directory/json/countryRegion/?parent=US HTTP/1.1" 200 969 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:43 +0000] "POST /checkout/cart/add HTTP/1.1" 302 5 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:43 +0000] "GET / HTTP/1.1" 200 7050 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"
3.81.150.213 - - [10/Feb/2019:07:33:43 +0000] "GET /page_cache/block/render/?blocks=[\x22customer_form_login\x22]&handles=[\x22default\x22,\x22customer_account_login\x22]&originalRequest={\x22route\x22:\x22customer\x22,\x22controller\x22:\x22account\x22,\x22action\x22:\x22login\x22,\x22uri\x22:\x22/customer/account/login/\x22}&ajax=true&isAjax=true HTTP/1.1" 200 754 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" "-"

4. JMeter log shows no errors
   jmeter.log
   jmeter-results.jtl

[magento-engcom-team]

Hi @sshymko. Thank you for your report.
To help us process this issue please make sure that you provided the following information:

• Summary of the issue
• Information on your environment
• Steps to reproduce
• Expected and actual results

Please make sure that the issue is reproducible on the vanilla Magento instance following Steps to reproduce. To deploy vanilla Magento instance on our environment, please, add a comment to the issue:

@magento-engcom-team give me 2.3-develop instance - upcoming 2.3.x release

For more details, please, review the Magento Contributor Assistant documentation.

@sshymko do you confirm that you was able to reproduce the issue on vanilla Magento instance following steps to reproduce?

• yes
• no

[sshymko]

@magento-engcom-team yes

[sshymko]

@kandy
This is the issue with the performance toolkit I've been facing.
Any idea what could be wrong?

[pmouawad]

@sshymko can you attach the jmx file you use ? thanks

[sshymko]

@pmouawad
This is an unmodified JMX file that comes with the performance toolkit:
https://github.com/magento/magento2/blob/2.2.7/setup/performance-toolkit/benchmark.jmx

[sshymko]

@pmouawad
I see you're part of the JMeter team :)
Please note that the old version of JMeter 3.1 is used for testing.
More up-to-date versions 4 and 5 are unfortunately not supported.
I would really appreciate any clues of what could be wrong.

[pmouawad]

Thanks, any way to provide to me an access to your instance or a docker image or any other alternative ? thanks

[magento-engcom-team]

Hi @engcom-backlog-nazar. Thank you for working on this issue.
In order to make sure that issue has enough information and ready for development, please read and check the following instruction: 👇

• 1. Verify that issue has all the required information. (Preconditions, Steps to reproduce, Expected result, Actual result).

  Details

  If the issue has a valid description, the label Issue: Format is valid will be added to the issue automatically. Please, edit issue description if needed, until label Issue: Format is valid appears.

• 2. Verify that issue has a meaningful description and provides enough information to reproduce the issue. If the report is valid, add Issue: Clear Description label to the issue by yourself.

• 3. Add Component: XXXXX label(s) to the ticket, indicating the components it may be related to.

• 4. Verify that the issue is reproducible on 2.3-develop branch

  Details

  - Add the comment @magento-engcom-team give me 2.3-develop instance to deploy test instance on Magento infrastructure.
  - If the issue is reproducible on 2.3-develop branch, please, add the label Reproduced on 2.3.x.
  - If the issue is not reproducible, add your comment that issue is not reproducible and close the issue and stop verification process here!

• 5. Verify that the issue is reproducible on 2.2-develop branch.

  Details

  - Add the comment @magento-engcom-team give me 2.2-develop instance to deploy test instance on Magento infrastructure.
  - If the issue is reproducible on 2.2-develop branch, please add the label Reproduced on 2.2.x

• Next steps are available in case you are a member of Community Maintainers.

• 6. Add label Issue: Confirmed once verification is complete.

• 7. Make sure that automatic system confirms that report has been added to the backlog.

[sshymko]

@pmouawad
Here's a test instance for you: http://3.85.65.228/
Feel free to play with it for the next ~10 hours; it will be terminated after that.
The JMeter command provided in the ticket description has all credentials embedded.
Thank you so much for looking into this issue, it's greatly appreciated.

[pmouawad]

It would be better if you let it live until 23h30 Paris Timezone, it’s 9am now. I am working for a customer, not sure I can dedicate time today before 20h30

[kandy]

@sshymko Looks like there is an issue of our Jmeter configuration. If loops count < 2 it will not run any scenario.
So current workaround will be to increase number of loops.

[sshymko]

@kandy
Thank you so much! I'll try running with loops > 1 and let you know how it goes.

[sshymko]

@kandy
I can confirm that the workaround of -Jloops=2 does work!