From: Martin T. <mto...@gm...> - 2017-10-14 19:37:08
|
Hi, [snip] > After putting some printk's in process_measurement the problem seems > to be the inode for /bin/kmod is locked and then sometime before > calling ima_appraise_measurement and inode_unlock process_measurement > gets called again with the /bin/kmod inode and it hangs. > > integrity_inode_get > ima_rdwr_violation_check /lib/systemd/systemd > ima_collect_measurement > ima_appraise_measurement > process_measurement /bin/kmod > inode_locked > integrity_inode_get > ima_rdwr_violation_check /bin/kmod > ima_collect_measurement > ima_appraise_measurement > process_measurement /bin/kmod > > hangs until hung_task_detector kicks in and resets. My guess is that > on my board systemd is loading a kernel module which in turn loads > another dependent kernel module which is causing the problem. I'll > see if I can get the name of the 2 modules being loaded > > -Martin. I put in a load of debug prints and now have the following trace. It looks to me that the problem is when systemd starts it tries to verify it's signature which invokes crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha1)) I checked my certificate creation and I'm using RSA and SHA1 so looks good. so it tries to load the module for this which then tries to verify /bin/kmod which has been signed the same way so this also tries to load the pkcs1pad(rsa,sha1) which the invokes /bin/kmod and hence are in a deadlock situation. Is the problem that earlier on in the trace it verifies the ima-x509.der key and loads pkcs1pad(rsa,sha256) module crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha256)) Does ima assume that sha256 will be used for signing? Should I create my signing certificates with sha256? Any help greatly appreciated, Martin. crypto_alloc_tfm: crypto_find_alg(crct10dif) crypto_alloc_tfm: crypto_create_tfm(crct10dif) crypto_alloc_tfm: crypto_find_alg(sha1) crypto_alloc_tfm: crypto_create_tfm(sha1) imx-sdma 20ec000.sdma: Direct firmware load for imx/sdma/sdma-imx6q.bin failed with error -2 imx-sdma 20ec000.sdma: Falling back to user helper __request_module: mdio:00000000000001111100000011110001 call_usermodehelper_exec_async: /sbin/modprobe -q -- mdio:00000000000001111100000011110001 106 cpu cpu0: dev_pm_opp_get_opp_count: OPP table not found (-19) crypto_alloc_tfm: crypto_find_alg(sha1) crypto_alloc_tfm: crypto_create_tfm(sha1) crypto_alloc_tfm: crypto_find_alg(hmac(sha256)) __request_module: crypto-hmac(sha256) call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-hmac(sha256) 111 __request_module: crypto-hmac(sha256)-all call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-hmac(sha256)-all 112 crypto_alloc_tfm: crypto_create_tfm(hmac(sha256)) crypto_alloc_tfm: crypto_find_alg(sha256) crypto_alloc_tfm: crypto_create_tfm(sha256) crypto_alloc_tfm: crypto_find_alg(cbc(aes)) __request_module: crypto-cbc(aes) call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-cbc(aes) 115 __request_module: crypto-cbc(aes)-all call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-cbc(aes)-all 116 crypto_alloc_tfm: crypto_create_tfm(cbc(aes)) crypto_alloc_tfm: crypto_find_alg(sha1) crypto_alloc_tfm: crypto_create_tfm(sha1) process_measurement /etc/keys/ima-x509.der 1 inode_locked integrity_inode_get ima_rdwr_violation_check /etc/keys/ima-x509.der ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked crypto_alloc_tfm: crypto_find_alg(sha256) crypto_alloc_tfm: crypto_create_tfm(sha256) ASYM: ==>restrict_link_by_signature() ASYM: ==>restrict_link_by_signature find_asymmetric_key() ASYM: ==>restrict_link_by_signature verify_signature() SIG: ==>verify_signature(1) SIG: ==>verify_signature asymmetric_key_subtype() SIG: ==>verify_signature subtype=80d4cad4 PKEY: ==>public_key_verify_signature() 1 PKEY: ==>public_key_verify_signature crypto_alloc_akcipher() 1 crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha256)) __request_module: crypto-pkcs1pad(rsa,sha256) call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-pkcs1pad(rsa,sha256) 120 process_measurement /bin/kmod 120 inode_locked ima_rdwr_violation_check /bin/kmod inode unlock inode_unlocked process_measurement /bin/kmod 120 inode_locked integrity_inode_get ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/ld-2.23.so 120 inode_locked ima_rdwr_violation_check /lib/ld-2.23.so inode unlock inode_unlocked process_measurement /bin/kmod 120 inode_locked integrity_inode_get ima_rdwr_violation_check /bin/kmod ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/ld-2.23.so 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/ld-2.23.so ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /etc/ld.so.cache 120 inode_locked integrity_inode_get ima_rdwr_violation_check /etc/ld.so.cache ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/libz.so.1.2.8 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libz.so.1.2.8 ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/libz.so.1.2.8 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libz.so.1.2.8 ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/libc-2.23.so 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libc-2.23.so ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/libc-2.23.so 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libc-2.23.so ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.softdep 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.softdep ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.dep.bin 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.dep.bin ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.alias.bin 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.alias.bin ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.symbols.bin 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.symbols.bin ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.builtin.bin 120 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.builtin.bin ima_read_xattr? false ima_get_hash_algo ima_collect_measurement ima_store_measurement freeing xattr inode unlock inode_unlocked __request_module: crypto-pkcs1pad(rsa,sha256)-all call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-pkcs1pad(rsa,sha256)-all 121 process_measurement /bin/kmod 121 inode_locked ima_rdwr_violation_check /bin/kmod inode unlock inode_unlocked process_measurement /bin/kmod 121 inode_locked integrity_inode_get ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/ld-2.23.so 121 inode_locked ima_rdwr_violation_check /lib/ld-2.23.so inode unlock inode_unlocked process_measurement /bin/kmod 121 inode_locked integrity_inode_get ima_rdwr_violation_check /bin/kmod ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/ld-2.23.so 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/ld-2.23.so ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /etc/ld.so.cache 121 inode_locked integrity_inode_get ima_rdwr_violation_check /etc/ld.so.cache ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/libz.so.1.2.8 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libz.so.1.2.8 ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/libz.so.1.2.8 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libz.so.1.2.8 ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/libc-2.23.so 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libc-2.23.so ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/libc-2.23.so 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/libc-2.23.so ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.softdep 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.softdep ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.dep.bin 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.dep.bin ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.alias.bin 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.alias.bin ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.symbols.bin 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.symbols.bin ima_get_cache_status? false freeing xattr inode unlock inode_unlocked process_measurement /lib/modules/4.9.44-fslc+g8f876e1/modules.builtin.bin 121 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/modules/4.9.44-fslc+g8f876e1/modules.builtin.bin ima_get_cache_status? false freeing xattr inode unlock inode_unlocked crypto_alloc_tfm: crypto_create_tfm(pkcs1pad(rsa,sha256)) PKEY: ==>public_key_verify_signature akcipher_request_alloc() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_set_pub_key() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_maxsize() 1 PKEY: ==>public_key_verify_signature akcipher_request_set_crypt() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_verify() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_verify() finished: 0 PKEY: <==public_key_verify_signature done PKEY: <==public_key_verify_signature() returning = 0 SIG: <==verify_signature() = 0 ASYM: ==>restrict_link_by_signature verify_signature() ret:0 process_measurement /etc/keys/ima-x509.der 1 inode_locked integrity_inode_get ima_rdwr_violation_check /etc/keys/ima-x509.der ima_get_cache_status? false freeing xattr inode unlock inode_unlocked crypto_alloc_tfm: crypto_find_alg(sha256) crypto_alloc_tfm: crypto_create_tfm(sha256) ASYM: ==>restrict_link_by_signature() ASYM: ==>restrict_link_by_signature find_asymmetric_key() ASYM: ==>restrict_link_by_signature verify_signature() SIG: ==>verify_signature(1) SIG: ==>verify_signature asymmetric_key_subtype() SIG: ==>verify_signature subtype=80d4cad4 PKEY: ==>public_key_verify_signature() 1 PKEY: ==>public_key_verify_signature crypto_alloc_akcipher() 1 crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha256)) crypto_alloc_tfm: crypto_create_tfm(pkcs1pad(rsa,sha256)) PKEY: ==>public_key_verify_signature akcipher_request_alloc() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_set_pub_key() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_maxsize() 1 PKEY: ==>public_key_verify_signature akcipher_request_set_crypt() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_verify() 1 PKEY: ==>public_key_verify_signature crypto_akcipher_verify() finished: 0 PKEY: <==public_key_verify_signature done PKEY: <==public_key_verify_signature() returning = 0 SIG: <==verify_signature() = 0 ASYM: ==>restrict_link_by_signature verify_signature() ret:0 process_measurement /lib/systemd/systemd 1 inode_locked integrity_inode_get ima_rdwr_violation_check /lib/systemd/systemd ima_read_xattr? true ima_get_hash_algo ima_collect_measurement ima_appraise_measurement evm_verifyxattr evm_verifyxattr 1 evm_verifyxattr cache:96524210 evm_verify_hmac evm_verify_hmac EVM_IMA_XATTR_DIGSIG evm_calc_hash crypto_alloc_tfm: crypto_find_alg(sha1) crypto_alloc_tfm: crypto_create_tfm(sha1) rc=0 integrity_digsig_verify integrity_digsig_verify 1 got key 2 asymmetric_verify asymmetric_verify request_asymmetric_key verify_signature SIG: ==>verify_signature(1) SIG: ==>verify_signature asymmetric_key_subtype() SIG: ==>verify_signature subtype=80d4cad4 PKEY: ==>public_key_verify_signature() 1 PKEY: ==>public_key_verify_signature crypto_alloc_akcipher() 1 crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha1)) __request_module: crypto-pkcs1pad(rsa,sha1) call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-pkcs1pad(rsa,sha1) 124 process_measurement /bin/kmod 124 inode_locked integrity_inode_get ima_rdwr_violation_check /bin/kmod ima_read_xattr? true ima_get_hash_algo ima_collect_measurement ima_appraise_measurement evm_verifyxattr evm_verifyxattr 124 evm_verifyxattr cache:96524030 evm_verify_hmac evm_verify_hmac EVM_IMA_XATTR_DIGSIG evm_calc_hash rc=0 integrity_digsig_verify integrity_digsig_verify 124 got key 2 asymmetric_verify asymmetric_verify request_asymmetric_key verify_signature SIG: ==>verify_signature(124) SIG: ==>verify_signature asymmetric_key_subtype() SIG: ==>verify_signature subtype=80d4cad4 PKEY: ==>public_key_verify_signature() 124 PKEY: ==>public_key_verify_signature crypto_alloc_akcipher() 124 crypto_alloc_tfm: crypto_find_alg(pkcs1pad(rsa,sha1)) __request_module: crypto-pkcs1pad(rsa,sha1) call_usermodehelper_exec_async: /sbin/modprobe -q -- crypto-pkcs1pad(rsa,sha1) 126 process_measurement /bin/kmod 126 |