QAT_Engine icon indicating copy to clipboard operation
QAT_Engine copied to clipboard

engine ctrl cmd failure(ENABLE_EVENT_DRIVEN_POLLING_MODE)?

Open lastpepole opened this issue 1 year ago • 10 comments

@venkatesh6911 @Yogaraj-Alamenda [root@hostname QAT_Engine]# /usr/local/openssl/bin/openssl engine -t -c -vvvv qatengine (qatengine) Reference implementation of QAT crypto engine(qat_hw) v1.5.0 [RSA, AES-128-CBC-HMAC-SHA256, AES-256-CBC-HMAC-SHA256, id-aes128-CCM, id-aes192-CCM, id-aes256-CCM, TLS1-PRF, X25519, X448] [ available ] ENABLE_EXTERNAL_POLLING: Enables the external polling interface to the engine. (input flags): NO_INPUT ........ SET_INTERNAL_POLL_INTERVAL: Set internal polling interval (input flags): NUMERIC GET_EXTERNAL_POLLING_FD: Returns non blocking fd for crypto engine (input flags): NO_INPUT ENABLE_EVENT_DRIVEN_POLLING_MODE: Set event driven polling mode (input flags): NO_INPUT ........ 1024:error:800A60A5:lib(128):qat_engine_ctrl:engine ctrl cmd failure:e_qat.c:1043: 1024:error:260BC066:engine routines:int_engine_configure:engine configuration error:crypto/engine/eng_cnf.c:141:section=qat_section, name=ENABLE_EVENT_DRIVEN_POLLING_MODE, value=EMPTY 1024:error:0E07606D:configuration file routines:module_run:module initialization error:crypto/conf/conf_mod.c:177:module=engines, value=engine_section, retcode=-1

openssl.cnf: openssl_conf = openssl_def [openssl_def] engines = engine_section

[engine_section] qatengine = qat_section

[qat_section] engine_id = qatengine dynamic_path = /usr/local/openssl/lib/engines-1.1/qatengine.so default_algorithms = ALL ENABLE_EVENT_DRIVEN_POLLING_MODE = EMPTY

lastpepole avatar May 16 '24 08:05 lastpepole

Hi @lastpepole , engine specific messages should be specified before the default_algorithms setting or incorrect behaviour may result.
Edit the [qat_section] like below: [qat_section] engine_id = qatengine dynamic_path = /usr/local/openssl/lib/engines-1.1/qatengine.so ENABLE_EVENT_DRIVEN_POLLING_MODE = EMPTY default_algorithms = ALL

venkatesh6911 avatar Jun 07 '24 08:06 venkatesh6911

Hi @lastpepole , engine specific messages should be specified before the default_algorithms setting or incorrect behaviour may result. Edit the [qat_section] like below: [qat_section] engine_id = qatengine dynamic_path = /usr/local/openssl/lib/engines-1.1/qatengine.so ENABLE_EVENT_DRIVEN_POLLING_MODE = EMPTY default_algorithms = ALL

my machine information as below:

kernel: 5.10
os: centos7u5
qat driver: 4.25.0
qat engine: 1.5.0
openssl: 1.1.1w

same phenomenon. same phenomenon. same phenomenon.

/var/log/qat_engine_debug.log information as below: important log: Error adding fd to epoll.


[WARN] [0.792272] PID [1111] Thread [1024][e_qat.c:1112:bind_qat()] QAT Warnings enabled.
[DEBUG][0.792294] PID [1111] Thread [1024][e_qat.c:1113:bind_qat()] QAT Debug enabled.
[WARN] [0.792296] PID [1111] Thread [1024][e_qat.c:1114:bind_qat()] (null) - Reference implementation of QAT crypto engine(qat_hw) v1.5.0
[DEBUG][0.792469] PID [1111] Thread [1024][e_qat.c:1131:bind_qat()] QAT HW device available
[DEBUG][0.792477] PID [1111] Thread [1024][qat_evp.c:1769:qat_get_RSA_methods()] QAT HW RSA Registration succeeded
[DEBUG][0.792484] PID [1111] Thread [1024][qat_evp.c:1585:qat_get_EC_methods()] QAT HW ECDSA Registration succeeded
[DEBUG][0.792486] PID [1111] Thread [1024][qat_evp.c:1666:qat_get_EC_methods()] QAT HW ECDH Registration succeeded
[DEBUG][0.792491] PID [1111] Thread [1024][qat_hw_ciphers.c:280:qat_create_cipher_meth()] QAT HW AES_CBC_128_HMAC_SHA registration succeeded
[DEBUG][0.792496] PID [1111] Thread [1024][qat_hw_ciphers.c:280:qat_create_cipher_meth()] QAT HW AES_CBC_256_HMAC_SHA registration succeeded
[DEBUG][0.792498] PID [1111] Thread [1024][qat_evp.c:957:qat_create_ccm_cipher_meth()] QAT HW AES_CCM_128 registration succeeded
[DEBUG][0.792500] PID [1111] Thread [1024][qat_evp.c:935:qat_create_ccm_cipher_meth()] OpenSSL SW AES_CCM_192 registration succeeded
[DEBUG][0.792502] PID [1111] Thread [1024][qat_evp.c:935:qat_create_ccm_cipher_meth()] OpenSSL SW AES_CCM_256 registration succeeded
[DEBUG][0.792512] PID [1111] Thread [1024][e_qat.c:813:qat_engine_ctrl()] Enabled event driven polling mode
[DEBUG][0.792521] PID [1111] Thread [1024][e_qat.c:599:qat_engine_init()] QAT Engine initialization:
[DEBUG][0.792524] PID [1111] Thread [1024][qat_hw_init.c:511:qat_hw_init()] QAT_HW initialization:
[DEBUG][0.792528] PID [1111] Thread [1024][qat_hw_init.c:512:qat_hw_init()] - External polling: OFF
[DEBUG][0.792530] PID [1111] Thread [1024][qat_hw_init.c:513:qat_hw_init()] - Heuristic polling: OFF
[DEBUG][0.792532] PID [1111] Thread [1024][qat_hw_init.c:514:qat_hw_init()] - SW Fallback: OFF
[DEBUG][0.792534] PID [1111] Thread [1024][qat_hw_init.c:515:qat_hw_init()] - Inline polling: OFF
[DEBUG][0.792535] PID [1111] Thread [1024][qat_hw_init.c:516:qat_hw_init()] - Internal poll interval: 10000ns
[DEBUG][0.792537] PID [1111] Thread [1024][qat_hw_init.c:517:qat_hw_init()] - Epoll timeout: 1000ms
[DEBUG][0.792539] PID [1111] Thread [1024][qat_hw_init.c:518:qat_hw_init()] - Event driven polling mode: ON
[DEBUG][0.792541] PID [1111] Thread [1024][qat_hw_init.c:519:qat_hw_init()] - Instance for thread: OFF
[DEBUG][0.792542] PID [1111] Thread [1024][qat_hw_init.c:520:qat_hw_init()] - Max retry count: 5
[DEBUG][0.854912] PID [1111] Thread [1024][qat_hw_init.c:559:qat_hw_init()] Found 6 Cy instances
[WARN][0.854932]  PID [1111] Thread [1024][qat_hw_init.c:626:qat_hw_init()] Error adding fd to epoll
[DEBUG][0.854937] PID [1111] Thread [1024][qat_hw_init.c:807:qat_hw_finish_int()] ---- QAT Finishing...

[WARN][0.854944]  PID [1111] Thread [1024][qat_hw_init.c:881:qat_hw_finish_int()] Error removing fd from epoll
[DEBUG][0.867523] PID [1111] Thread [1024][qat_hw_init.c:907:qat_hw_finish_int()] Calling pthread_key_delete()
[DEBUG][0.867906] PID [1111] Thread [1024][e_qat.c:599:qat_engine_init()] QAT Engine initialization:
[DEBUG][0.867911] PID [1111] Thread [1024][qat_hw_init.c:511:qat_hw_init()] QAT_HW initialization:
[DEBUG][0.867913] PID [1111] Thread [1024][qat_hw_init.c:512:qat_hw_init()] - External polling: OFF
[DEBUG][0.867915] PID [1111] Thread [1024][qat_hw_init.c:513:qat_hw_init()] - Heuristic polling: OFF
[DEBUG][0.867917] PID [1111] Thread [1024][qat_hw_init.c:514:qat_hw_init()] - SW Fallback: OFF
[DEBUG][0.867928] PID [1111] Thread [1024][qat_hw_init.c:515:qat_hw_init()] - Inline polling: OFF
[DEBUG][0.867930] PID [1111] Thread [1024][qat_hw_init.c:516:qat_hw_init()] - Internal poll interval: 10000ns
[DEBUG][0.867932] PID [1111] Thread [1024][qat_hw_init.c:517:qat_hw_init()] - Epoll timeout: 1000ms
[DEBUG][0.867934] PID [1111] Thread [1024][qat_hw_init.c:518:qat_hw_init()] - Event driven polling mode: OFF
[DEBUG][0.867935] PID [1111] Thread [1024][qat_hw_init.c:519:qat_hw_init()] - Instance for thread: OFF
[DEBUG][0.867937] PID [1111] Thread [1024][qat_hw_init.c:520:qat_hw_init()] - Max retry count: 5
[DEBUG][0.924544] PID [1111] Thread [1024][qat_hw_init.c:559:qat_hw_init()] Found 6 Cy instances
[DEBUG][0.924571] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 0 Located on Device: 0
[DEBUG][0.924584] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 1 Located on Device: 1
[DEBUG][0.924595] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 2 Located on Device: 2
[DEBUG][0.924607] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 3 Located on Device: 3
[DEBUG][0.924620] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 4 Located on Device: 4
[DEBUG][0.924631] PID [1111] Thread [1024][qat_hw_init.c:678:qat_hw_init()] Started Instance No: 5 Located on Device: 5
Asymmetric instances sequence: 0 1 2 3 4 5
Symmetric instances sequence: 0 1 2 3 4 5
[DEBUG][0.924641] PID [1111] Thread [1024][qat_hw_init.c:704:qat_hw_init()] Instances 6, SVM instances 0, contig instances 6Asym sequence for thread mapping: 0 1 2 3 4 5
Sym sequence for thread mapping: 0 1 2 3 4 5
[DEBUG][0.924717] PID [1111] Thread [1025][qat_hw_polling.c:148:qat_timer_poll_func()] timer_poll_func started
[DEBUG][0.924731] PID [1111] Thread [1025][qat_hw_polling.c:160:qat_timer_poll_func()] qat_timer_poll_func_thread = 0x1025
[DEBUG][0.924746] PID [1111] Thread [1024][e_qat.c:645:qat_engine_finish_int()] ---- QAT Engine Finishing...

[DEBUG][0.924752] PID [1111] Thread [1024][e_qat.c:647:qat_engine_finish_int()] RSA Priv retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924757] PID [1111] Thread [1024][e_qat.c:649:qat_engine_finish_int()] RSA Pub retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924758] PID [1111] Thread [1024][e_qat.c:652:qat_engine_finish_int()] ECDH keygen retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924761] PID [1111] Thread [1024][e_qat.c:655:qat_engine_finish_int()] ECDH derive retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924762] PID [1111] Thread [1024][e_qat.c:657:qat_engine_finish_int()] ECX keygen retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924764] PID [1111] Thread [1024][e_qat.c:659:qat_engine_finish_int()] ECX derive retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924766] PID [1111] Thread [1024][e_qat.c:661:qat_engine_finish_int()] ECDSA sign retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924768] PID [1111] Thread [1024][e_qat.c:664:qat_engine_finish_int()] SM4-CBC retries: 0, HW requests: 0, SW requests: 0
[DEBUG][0.924769] PID [1111] Thread [1024][qat_hw_init.c:807:qat_hw_finish_int()] ---- QAT Finishing...

[DEBUG][0.924838] PID [1111] Thread [1025][qat_hw_polling.c:226:qat_timer_poll_func()] timer_poll_func finishing - pid = 1111
[DEBUG][0.937312] PID [1111] Thread [1024][qat_hw_init.c:907:qat_hw_finish_int()] Calling pthread_key_delete()
[DEBUG][0.937497] PID [1111] Thread [1024][qat_hw_prf.c:138:qat_prf_pmeth()] QAT HW PRF is disabled, using OpenSSL SW
[DEBUG][0.937509] PID [1111] Thread [1024][qat_evp.c:613:qat_x25519_pmeth()] QAT HW X25519 is disabled
[DEBUG][0.937511] PID [1111] Thread [1024][qat_evp.c:686:qat_x448_pmeth()] QAT HW ECDH X448 is disabled, using OpenSSL SW
[DEBUG][0.937513] PID [1111] Thread [1024][e_qat.c:488:qat_engine_destroy()] ---- Destroying Engine...

lastpepole avatar Jun 11 '24 03:06 lastpepole

@venkatesh6911 Can you reproduce this case? or any new result?

lastpepole avatar Jun 11 '24 03:06 lastpepole

@lastpepole I am able to reproduce "Error removing fd from epoll" with event driven polling mode enabled. I am working to root cause this. We will keep you updated.

venkatesh6911 avatar Jun 11 '24 06:06 venkatesh6911

@lastpepole I am able to reproduce "Error removing fd from epoll" with event driven polling mode enabled. I am working to root cause this. We will keep you updated.

hi @venkatesh6911 this is good news. Look forward to your soonest reply. Thank you very much.

lastpepole avatar Jun 11 '24 07:06 lastpepole

hi, @venkatesh6911 Have any result? Thank you very much.

lastpepole avatar Jun 17 '24 07:06 lastpepole

Hi @lastpepole , sorry for the delayed reply.. I looked into the error "Error adding fd to epoll" and it seems to be occurring when event fds of non-epoll instances are getting added to the interest list of the epoll file descriptor. As these event fds are 0 for more than one occurence, epoll_ctl() report an error saying that the event fd 0 is already added to the interest fd list.

We will create an issue internally and get this resolved with the next release. Thank you for your patience.

venkatesh6911 avatar Jul 03 '24 17:07 venkatesh6911

Hi @lastpepole , we checked internally and found that only one epoll instance can be configured per bank due to performance reasons. https://www.intel.com/content/www/us/en/content-details/710060/intel-quickassist-technology-software-for-linux-programmer-s-guide-customer-enabling-release.html Refer page 20.

Please check if you have configured more than epoll instance in your QAT device config...

venkatesh6911 avatar Jul 22 '24 06:07 venkatesh6911

hi @venkatesh6911 , can't start qat engine, new problem.

step 1: edit /etc/c6xx_dev0.conf......c6xx_dev5.conf

......
##############################################
# User Process Instance Section
##############################################
[SHIM]
NumberCyInstances = 1
NumberDcInstances = 0
NumProcesses = 64
LimitDevAccess = 0

# Crypto - User instance #0
Cy0Name = "UserCY0"
Cy0IsPolled = 1   --------------> modify to Cy0IsPolled = 2
# List of core affinities
Cy0CoreAffinity = 0

step 2: start qat engine. run command:

service qat_service start

error log: Ioctl failed

Restarting all devices.
Processing /etc/c6xx_dev0.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev0
Processing /etc/c6xx_dev1.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev1
Processing /etc/c6xx_dev2.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev2
Processing /etc/c6xx_dev3.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev3
Processing /etc/c6xx_dev4.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev4
Processing /etc/c6xx_dev5.conf
Ioctl failed
QAT Error: Failed to load config data to device
Failed to configure qat_dev5
Checking status of all devices.
There is 6 QAT acceleration device(s) in the system:
 qat_dev0 - type: c6xx,  inst_id: 0,  node_id: 0,  bsf: 0000:60:00.0,  #accel: 5 #engines: 10 state: down
 qat_dev1 - type: c6xx,  inst_id: 1,  node_id: 0,  bsf: 0000:61:00.0,  #accel: 5 #engines: 10 state: down
 qat_dev2 - type: c6xx,  inst_id: 2,  node_id: 0,  bsf: 0000:62:00.0,  #accel: 5 #engines: 10 state: down
 qat_dev3 - type: c6xx,  inst_id: 3,  node_id: 1,  bsf: 0000:b1:00.0,  #accel: 5 #engines: 10 state: down
 qat_dev4 - type: c6xx,  inst_id: 4,  node_id: 1,  bsf: 0000:b2:00.0,  #accel: 5 #engines: 10 state: down
 qat_dev5 - type: c6xx,  inst_id: 5,  node_id: 1,  bsf: 0000:b3:00.0,  #accel: 5 #engines: 10 state: down

dmesg log: Don't have enough rings for instance UserCY0 in process SHIM_INT_16

[Tue Jul 22 10:10:00 2024] Don't have enough rings for instance UserCY0 in process SHIM_INT_16
[Tue Jul 22 10:10:00 2024] c6xx 0000:60:00.0: Failed to create rings for cy
[Tue Jul 22 10:10:00 2024] c6xx 0000:60:00.0: Failed to process user section SHIM
[Tue Jul 22 10:10:00 2024] c6xx 0000:60:00.0: Failed to config device
......
[Tue Jul 22 10:10:00 2024] Don't have enough rings for instance UserCY0 in process SHIM_INT_16
[Tue Jul 22 10:10:00 2024] c6xx 0000:b3:00.0: Failed to create rings for cy
[Tue Jul 22 10:10:00 2024] c6xx 0000:b3:00.0: Failed to process user section SHIM
[Tue Jul 22 10:10:00 2024] c6xx 0000:b3:00.0: Failed to config device

lastpepole avatar Jul 23 '24 10:07 lastpepole

There is a limit on the NumProcesses parameter for a single CY instance. Can you update NumProcesses to 16 in the device confs and give a try ?

venkatesh6911 avatar Jul 24 '24 06:07 venkatesh6911