* init_ima() adds 8 % to boot time
@ 2022-02-19 9:44 Paul Menzel
2022-02-20 15:19 ` Mimi Zohar
0 siblings, 1 reply; 6+ messages in thread
From: Paul Menzel @ 2022-02-19 9:44 UTC (permalink / raw)
To: Mimi Zohar, Dmitry Kasatkin; +Cc: linux-integrity, LKML
[-- Attachment #1: Type: text/plain, Size: 3430 bytes --]
Dear Linux folks,
Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
around 33 ms, adding 8 % to the boot time up to loading the initrd.
[ 0.000000] Linux version 5.17.0-rc4-amd64
(debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
(2022-02-18)
[…]
[ 0.238520] calling init_tis+0x0/0xde @ 1
[ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
[ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
[…]
[ 0.301327] calling init_ima+0x0/0xb5 @ 1
[ 0.301332] ima: Allocated hash algorithm: sha256
[ 0.335502] ima: No architecture policies found
[ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
[…]
[ 0.447312] Run /init as init process
Tracing `init_ima` with a depth of 5 shows
`ima_calc_boot_aggregate_tfm()` takes 24 ms, and
`ima_add_template_entry()` takes 10 ms.
1.282630 | 1) swapper-1 | |
ima_add_boot_aggregate() {
1.282631 | 1) swapper-1 | |
ima_calc_boot_aggregate() {
1.282631 | 1) swapper-1 | 0.153 us |
ima_alloc_tfm();
1.282631 | 1) swapper-1 | * 24404.59 us |
ima_calc_boot_aggregate_tfm();
1.307037 | 1) swapper-1 | 0.482 us |
ima_free_tfm.part.0();
1.307038 | 1) swapper-1 | * 24407.06 us | } /*
ima_calc_boot_aggregate */
1.307038 | 1) swapper-1 | |
ima_alloc_init_template() {
1.307038 | 1) swapper-1 | 0.173 us |
ima_template_desc_current();
1.307039 | 1) swapper-1 | 0.836 us |
__kmalloc();
1.307040 | 1) swapper-1 | 0.580 us |
__kmalloc();
1.307041 | 1) swapper-1 | 1.555 us |
ima_eventdigest_ng_init();
1.307043 | 1) swapper-1 | 1.275 us |
ima_eventname_ng_init();
1.307044 | 1) swapper-1 | 0.256 us |
ima_eventsig_init();
1.307045 | 1) swapper-1 | 6.618 us | } /*
ima_alloc_init_template */
1.307045 | 1) swapper-1 | |
ima_store_template() {
1.307045 | 1) swapper-1 | 5.049 us |
ima_calc_field_array_hash();
1.307051 | 1) swapper-1 | # 9316.953 us |
ima_add_template_entry();
1.316369 | 1) swapper-1 | # 9323.728 us | } /*
ima_store_template */
1.316369 | 1) swapper-1 | * 33738.54 us | } /*
ima_add_boot_aggregate */
Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
`tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
the TPM supposed to be that slow?
In the last years, Linux decreased it’s boot time a lot, so do you see a
way to move things out of the hot path and get `init_ima` well below 10
ms? (As systems get faster and faster, having systems with standard
distributions to be up below two seconds after pressing the power button
should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
Linux kernel + 1 s user space).
Kind regards,
Paul
[1]:
https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
[-- Attachment #2: linux-5.17-rc4-ima_calc_boot_aggregate_tfm.trace.txt --]
[-- Type: text/plain, Size: 21571 bytes --]
# tracer: function_graph
#
# TIME CPU TASK/PID DURATION FUNCTION CALLS
# | | | | | | | | | |
1.278970 | 0) swapper-1 | | ima_calc_boot_aggregate_tfm() {
1.278971 | 0) swapper-1 | | tpm_pcr_read() {
1.278971 | 0) swapper-1 | | tpm_find_get_ops() {
1.278971 | 0) swapper-1 | | tpm_try_get_ops() {
1.278971 | 0) swapper-1 | 0.201 us | get_device();
1.278972 | 0) swapper-1 | 0.265 us | down_read();
1.278972 | 0) swapper-1 | 0.252 us | mutex_lock();
1.278972 | 0) swapper-1 | 8.257 us | tpm_chip_start();
1.278981 | 0) swapper-1 | 9.794 us | } /* tpm_try_get_ops */
1.278981 | 0) swapper-1 | + 10.120 us | } /* tpm_find_get_ops */
1.278981 | 0) swapper-1 | | tpm1_pcr_read() {
1.278981 | 0) swapper-1 | | __get_free_pages() {
1.278981 | 0) swapper-1 | 0.825 us | alloc_pages();
1.278982 | 0) swapper-1 | 1.122 us | } /* __get_free_pages */
1.278983 | 0) swapper-1 | | tpm_transmit_cmd() {
1.278983 | 0) swapper-1 | | tpm_transmit() {
1.295183 | 3) swapper-1 | * 16199.26 us | } /* tpm_transmit */
1.295183 | 3) swapper-1 | * 16200.69 us | } /* tpm_transmit_cmd */
1.295184 | 3) swapper-1 | | free_pages() {
1.295184 | 3) swapper-1 | 1.827 us | __free_pages();
1.295186 | 3) swapper-1 | 2.395 us | } /* free_pages */
1.295186 | 3) swapper-1 | * 16205.24 us | } /* tpm1_pcr_read */
1.295187 | 3) swapper-1 | | tpm_put_ops() {
1.295187 | 3) swapper-1 | | tpm_chip_stop() {
1.295187 | 3) swapper-1 | 0.398 us | tpm_relinquish_locality();
1.295188 | 3) swapper-1 | 0.256 us | tpm_tis_clkrun_enable();
1.295188 | 3) swapper-1 | 1.426 us | } /* tpm_chip_stop */
1.295189 | 3) swapper-1 | 0.173 us | mutex_unlock();
1.295189 | 3) swapper-1 | 0.175 us | up_read();
1.295189 | 3) swapper-1 | 0.236 us | put_device();
1.295190 | 3) swapper-1 | 3.051 us | } /* tpm_put_ops */
1.295190 | 3) swapper-1 | * 16219.30 us | } /* tpm_pcr_read */
1.295190 | 3) swapper-1 | | crypto_shash_update() {
1.295191 | 3) swapper-1 | 0.200 us | crypto_sha1_update();
1.295191 | 3) swapper-1 | 0.693 us | } /* crypto_shash_update */
1.295191 | 3) swapper-1 | | tpm_pcr_read() {
1.295191 | 3) swapper-1 | | tpm_find_get_ops() {
1.295192 | 3) swapper-1 | | tpm_try_get_ops() {
1.295192 | 3) swapper-1 | 0.241 us | get_device();
1.295192 | 3) swapper-1 | 0.245 us | down_read();
1.295193 | 3) swapper-1 | 0.232 us | mutex_lock();
1.295193 | 3) swapper-1 | 8.181 us | tpm_chip_start();
1.295201 | 3) swapper-1 | 9.890 us | } /* tpm_try_get_ops */
1.295202 | 3) swapper-1 | + 10.217 us | } /* tpm_find_get_ops */
1.295202 | 3) swapper-1 | | tpm1_pcr_read() {
1.295202 | 3) swapper-1 | | __get_free_pages() {
1.295202 | 3) swapper-1 | 2.108 us | alloc_pages();
1.295205 | 3) swapper-1 | 2.512 us | } /* __get_free_pages */
1.295205 | 3) swapper-1 | | tpm_transmit_cmd() {
1.295205 | 3) swapper-1 | # 1186.160 us | tpm_transmit();
1.296392 | 3) swapper-1 | # 1187.552 us | } /* tpm_transmit_cmd */
1.296393 | 3) swapper-1 | | free_pages() {
1.296393 | 3) swapper-1 | 1.615 us | __free_pages();
1.296395 | 3) swapper-1 | 2.090 us | } /* free_pages */
1.296395 | 3) swapper-1 | # 1193.126 us | } /* tpm1_pcr_read */
1.296395 | 3) swapper-1 | | tpm_put_ops() {
1.296396 | 3) swapper-1 | | tpm_chip_stop() {
1.296396 | 3) swapper-1 | 0.394 us | tpm_relinquish_locality();
1.296396 | 3) swapper-1 | 0.249 us | tpm_tis_clkrun_enable();
1.296397 | 3) swapper-1 | 1.338 us | } /* tpm_chip_stop */
1.296397 | 3) swapper-1 | 0.168 us | mutex_unlock();
1.296397 | 3) swapper-1 | 0.163 us | up_read();
1.296398 | 3) swapper-1 | 0.241 us | put_device();
1.296398 | 3) swapper-1 | 2.996 us | } /* tpm_put_ops */
1.296398 | 3) swapper-1 | # 1207.262 us | } /* tpm_pcr_read */
1.296399 | 3) swapper-1 | | crypto_shash_update() {
1.296399 | 3) swapper-1 | 0.189 us | crypto_sha1_update();
1.296400 | 3) swapper-1 | 0.919 us | } /* crypto_shash_update */
1.296400 | 3) swapper-1 | | tpm_pcr_read() {
1.296400 | 3) swapper-1 | | tpm_find_get_ops() {
1.296400 | 3) swapper-1 | | tpm_try_get_ops() {
1.296401 | 3) swapper-1 | 0.239 us | get_device();
1.296401 | 3) swapper-1 | 0.243 us | down_read();
1.296402 | 3) swapper-1 | 0.228 us | mutex_lock();
1.296402 | 3) swapper-1 | 7.939 us | tpm_chip_start();
1.296410 | 3) swapper-1 | 9.650 us | } /* tpm_try_get_ops */
1.296410 | 3) swapper-1 | 9.975 us | } /* tpm_find_get_ops */
1.296411 | 3) swapper-1 | | tpm1_pcr_read() {
1.296411 | 3) swapper-1 | | __get_free_pages() {
1.296411 | 3) swapper-1 | 2.460 us | alloc_pages();
1.296414 | 3) swapper-1 | 2.867 us | } /* __get_free_pages */
1.296414 | 3) swapper-1 | | tpm_transmit_cmd() {
1.296414 | 3) swapper-1 | # 1187.963 us | tpm_transmit();
1.297603 | 3) swapper-1 | # 1189.319 us | } /* tpm_transmit_cmd */
1.297604 | 3) swapper-1 | | free_pages() {
1.297604 | 3) swapper-1 | 1.612 us | __free_pages();
1.297606 | 3) swapper-1 | 2.114 us | } /* free_pages */
1.297606 | 3) swapper-1 | # 1195.291 us | } /* tpm1_pcr_read */
1.297606 | 3) swapper-1 | | tpm_put_ops() {
1.297606 | 3) swapper-1 | | tpm_chip_stop() {
1.297607 | 3) swapper-1 | 0.407 us | tpm_relinquish_locality();
1.297607 | 3) swapper-1 | 0.254 us | tpm_tis_clkrun_enable();
1.297608 | 3) swapper-1 | 1.354 us | } /* tpm_chip_stop */
1.297608 | 3) swapper-1 | 0.178 us | mutex_unlock();
1.297608 | 3) swapper-1 | 0.157 us | up_read();
1.297609 | 3) swapper-1 | 0.235 us | put_device();
1.297609 | 3) swapper-1 | 2.973 us | } /* tpm_put_ops */
1.297609 | 3) swapper-1 | # 1209.350 us | } /* tpm_pcr_read */
1.297610 | 3) swapper-1 | | crypto_shash_update() {
1.297610 | 3) swapper-1 | 0.186 us | crypto_sha1_update();
1.297611 | 3) swapper-1 | 0.919 us | } /* crypto_shash_update */
1.297611 | 3) swapper-1 | | tpm_pcr_read() {
1.297611 | 3) swapper-1 | | tpm_find_get_ops() {
1.297612 | 3) swapper-1 | | tpm_try_get_ops() {
1.297612 | 3) swapper-1 | 0.238 us | get_device();
1.297612 | 3) swapper-1 | 0.241 us | down_read();
1.297613 | 3) swapper-1 | 0.231 us | mutex_lock();
1.297613 | 3) swapper-1 | 7.872 us | tpm_chip_start();
1.297621 | 3) swapper-1 | 9.611 us | } /* tpm_try_get_ops */
1.297621 | 3) swapper-1 | 9.953 us | } /* tpm_find_get_ops */
1.297622 | 3) swapper-1 | | tpm1_pcr_read() {
1.297622 | 3) swapper-1 | | __get_free_pages() {
1.297622 | 3) swapper-1 | 2.088 us | alloc_pages();
1.297624 | 3) swapper-1 | 2.499 us | } /* __get_free_pages */
1.297625 | 3) swapper-1 | | tpm_transmit_cmd() {
1.297625 | 3) swapper-1 | # 1186.932 us | tpm_transmit();
1.298813 | 3) swapper-1 | # 1188.266 us | } /* tpm_transmit_cmd */
1.298813 | 3) swapper-1 | | free_pages() {
1.298814 | 3) swapper-1 | 1.605 us | __free_pages();
1.298815 | 3) swapper-1 | 2.086 us | } /* free_pages */
1.298815 | 3) swapper-1 | # 1193.817 us | } /* tpm1_pcr_read */
1.298816 | 3) swapper-1 | | tpm_put_ops() {
1.298816 | 3) swapper-1 | | tpm_chip_stop() {
1.298816 | 3) swapper-1 | 0.415 us | tpm_relinquish_locality();
1.298817 | 3) swapper-1 | 0.264 us | tpm_tis_clkrun_enable();
1.298817 | 3) swapper-1 | 1.364 us | } /* tpm_chip_stop */
1.298818 | 3) swapper-1 | 0.170 us | mutex_unlock();
1.298818 | 3) swapper-1 | 0.157 us | up_read();
1.298818 | 3) swapper-1 | 0.264 us | put_device();
1.298819 | 3) swapper-1 | 3.007 us | } /* tpm_put_ops */
1.298819 | 3) swapper-1 | # 1207.997 us | } /* tpm_pcr_read */
1.298820 | 3) swapper-1 | | crypto_shash_update() {
1.298820 | 3) swapper-1 | 0.776 us | crypto_sha1_update();
1.298821 | 3) swapper-1 | 1.564 us | } /* crypto_shash_update */
1.298821 | 3) swapper-1 | | tpm_pcr_read() {
1.298821 | 3) swapper-1 | | tpm_find_get_ops() {
1.298821 | 3) swapper-1 | | tpm_try_get_ops() {
1.298822 | 3) swapper-1 | 0.239 us | get_device();
1.298822 | 3) swapper-1 | 0.252 us | down_read();
1.298823 | 3) swapper-1 | 0.228 us | mutex_lock();
1.298823 | 3) swapper-1 | 7.872 us | tpm_chip_start();
1.298831 | 3) swapper-1 | 9.576 us | } /* tpm_try_get_ops */
1.298831 | 3) swapper-1 | 9.900 us | } /* tpm_find_get_ops */
1.298831 | 3) swapper-1 | | tpm1_pcr_read() {
1.298832 | 3) swapper-1 | | __get_free_pages() {
1.298832 | 3) swapper-1 | 2.257 us | alloc_pages();
1.298834 | 3) swapper-1 | 2.674 us | } /* __get_free_pages */
1.298835 | 3) swapper-1 | | tpm_transmit_cmd() {
1.298835 | 3) swapper-1 | # 1186.138 us | tpm_transmit();
1.300022 | 3) swapper-1 | # 1187.494 us | } /* tpm_transmit_cmd */
1.300022 | 3) swapper-1 | | free_pages() {
1.300023 | 3) swapper-1 | 1.619 us | __free_pages();
1.300025 | 3) swapper-1 | 2.099 us | } /* free_pages */
1.300025 | 3) swapper-1 | # 1193.254 us | } /* tpm1_pcr_read */
1.300025 | 3) swapper-1 | | tpm_put_ops() {
1.300025 | 3) swapper-1 | | tpm_chip_stop() {
1.300026 | 3) swapper-1 | 0.402 us | tpm_relinquish_locality();
1.300026 | 3) swapper-1 | 0.245 us | tpm_tis_clkrun_enable();
1.300027 | 3) swapper-1 | 1.339 us | } /* tpm_chip_stop */
1.300027 | 3) swapper-1 | 0.170 us | mutex_unlock();
1.300027 | 3) swapper-1 | 0.156 us | up_read();
1.300028 | 3) swapper-1 | 0.236 us | put_device();
1.300028 | 3) swapper-1 | 2.927 us | } /* tpm_put_ops */
1.300028 | 3) swapper-1 | # 1206.993 us | } /* tpm_pcr_read */
1.300028 | 3) swapper-1 | | crypto_shash_update() {
1.300029 | 3) swapper-1 | 0.191 us | crypto_sha1_update();
1.300029 | 3) swapper-1 | 0.688 us | } /* crypto_shash_update */
1.300029 | 3) swapper-1 | | tpm_pcr_read() {
1.300030 | 3) swapper-1 | | tpm_find_get_ops() {
1.300030 | 3) swapper-1 | | tpm_try_get_ops() {
1.300030 | 3) swapper-1 | 0.239 us | get_device();
1.300031 | 3) swapper-1 | 0.248 us | down_read();
1.300031 | 3) swapper-1 | 0.233 us | mutex_lock();
1.300031 | 3) swapper-1 | 8.122 us | tpm_chip_start();
1.300040 | 3) swapper-1 | 9.962 us | } /* tpm_try_get_ops */
1.300040 | 3) swapper-1 | + 10.292 us | } /* tpm_find_get_ops */
1.300040 | 3) swapper-1 | | tpm1_pcr_read() {
1.300041 | 3) swapper-1 | | __get_free_pages() {
1.300041 | 3) swapper-1 | 2.407 us | alloc_pages();
1.300043 | 3) swapper-1 | 2.813 us | } /* __get_free_pages */
1.300044 | 3) swapper-1 | | tpm_transmit_cmd() {
1.300044 | 3) swapper-1 | # 1186.643 us | tpm_transmit();
1.301232 | 3) swapper-1 | # 1188.031 us | } /* tpm_transmit_cmd */
1.301232 | 3) swapper-1 | | free_pages() {
1.301232 | 3) swapper-1 | 1.604 us | __free_pages();
1.301234 | 3) swapper-1 | 2.095 us | } /* free_pages */
1.301234 | 3) swapper-1 | # 1193.909 us | } /* tpm1_pcr_read */
1.301234 | 3) swapper-1 | | tpm_put_ops() {
1.301235 | 3) swapper-1 | | tpm_chip_stop() {
1.301235 | 3) swapper-1 | 0.402 us | tpm_relinquish_locality();
1.301236 | 3) swapper-1 | 0.247 us | tpm_tis_clkrun_enable();
1.301236 | 3) swapper-1 | 1.622 us | } /* tpm_chip_stop */
1.301237 | 3) swapper-1 | 0.166 us | mutex_unlock();
1.301237 | 3) swapper-1 | 0.167 us | up_read();
1.301237 | 3) swapper-1 | 0.235 us | put_device();
1.301238 | 3) swapper-1 | 3.237 us | } /* tpm_put_ops */
1.301238 | 3) swapper-1 | # 1208.564 us | } /* tpm_pcr_read */
1.301239 | 3) swapper-1 | | crypto_shash_update() {
1.301239 | 3) swapper-1 | 0.185 us | crypto_sha1_update();
1.301239 | 3) swapper-1 | 0.933 us | } /* crypto_shash_update */
1.301239 | 3) swapper-1 | | tpm_pcr_read() {
1.301240 | 3) swapper-1 | | tpm_find_get_ops() {
1.301240 | 3) swapper-1 | | tpm_try_get_ops() {
1.301240 | 3) swapper-1 | 0.240 us | get_device();
1.301241 | 3) swapper-1 | 0.247 us | down_read();
1.301241 | 3) swapper-1 | 0.233 us | mutex_lock();
1.301242 | 3) swapper-1 | 7.824 us | tpm_chip_start();
1.301250 | 3) swapper-1 | 9.726 us | } /* tpm_try_get_ops */
1.301250 | 3) swapper-1 | + 10.054 us | } /* tpm_find_get_ops */
1.301250 | 3) swapper-1 | | tpm1_pcr_read() {
1.301250 | 3) swapper-1 | | __get_free_pages() {
1.301250 | 3) swapper-1 | 2.341 us | alloc_pages();
1.301253 | 3) swapper-1 | 2.754 us | } /* __get_free_pages */
1.301253 | 3) swapper-1 | | tpm_transmit_cmd() {
1.301253 | 3) swapper-1 | # 1163.840 us | tpm_transmit();
1.302418 | 3) swapper-1 | # 1164.639 us | } /* tpm_transmit_cmd */
1.302418 | 3) swapper-1 | | free_pages() {
1.302418 | 3) swapper-1 | 0.715 us | __free_pages();
1.302419 | 3) swapper-1 | 1.154 us | } /* free_pages */
1.302419 | 3) swapper-1 | # 1169.348 us | } /* tpm1_pcr_read */
1.302420 | 3) swapper-1 | | tpm_put_ops() {
1.302420 | 3) swapper-1 | | tpm_chip_stop() {
1.302420 | 3) swapper-1 | 0.331 us | tpm_relinquish_locality();
1.302420 | 3) swapper-1 | 0.185 us | tpm_tis_clkrun_enable();
1.302421 | 3) swapper-1 | 1.094 us | } /* tpm_chip_stop */
1.302421 | 3) swapper-1 | 0.180 us | mutex_unlock();
1.302421 | 3) swapper-1 | 0.159 us | up_read();
1.302422 | 3) swapper-1 | 0.177 us | put_device();
1.302422 | 3) swapper-1 | 2.493 us | } /* tpm_put_ops */
1.302422 | 3) swapper-1 | # 1182.716 us | } /* tpm_pcr_read */
1.302422 | 3) swapper-1 | | crypto_shash_update() {
1.302423 | 3) swapper-1 | 0.751 us | crypto_sha1_update();
1.302423 | 3) swapper-1 | 1.103 us | } /* crypto_shash_update */
1.302424 | 3) swapper-1 | | tpm_pcr_read() {
1.302424 | 3) swapper-1 | | tpm_find_get_ops() {
1.302424 | 3) swapper-1 | | tpm_try_get_ops() {
1.302424 | 3) swapper-1 | 0.178 us | get_device();
1.302425 | 3) swapper-1 | 0.250 us | down_read();
1.302425 | 3) swapper-1 | 0.232 us | mutex_lock();
1.302425 | 3) swapper-1 | 7.807 us | tpm_chip_start();
1.302433 | 3) swapper-1 | 9.333 us | } /* tpm_try_get_ops */
1.302433 | 3) swapper-1 | 9.656 us | } /* tpm_find_get_ops */
1.302434 | 3) swapper-1 | | tpm1_pcr_read() {
1.302434 | 3) swapper-1 | | __get_free_pages() {
1.302434 | 3) swapper-1 | 1.314 us | alloc_pages();
1.302436 | 3) swapper-1 | 1.672 us | } /* __get_free_pages */
1.302436 | 3) swapper-1 | | tpm_transmit_cmd() {
1.302436 | 3) swapper-1 | # 1185.055 us | tpm_transmit();
1.303622 | 3) swapper-1 | # 1186.412 us | } /* tpm_transmit_cmd */
1.303623 | 3) swapper-1 | | free_pages() {
1.303623 | 3) swapper-1 | 1.623 us | __free_pages();
1.303625 | 3) swapper-1 | 2.188 us | } /* free_pages */
1.303625 | 3) swapper-1 | # 1191.170 us | } /* tpm1_pcr_read */
1.303625 | 3) swapper-1 | | tpm_put_ops() {
1.303625 | 3) swapper-1 | | tpm_chip_stop() {
1.303626 | 3) swapper-1 | 0.391 us | tpm_relinquish_locality();
1.303626 | 3) swapper-1 | 0.263 us | tpm_tis_clkrun_enable();
1.303627 | 3) swapper-1 | 1.360 us | } /* tpm_chip_stop */
1.303627 | 3) swapper-1 | 0.172 us | mutex_unlock();
1.303627 | 3) swapper-1 | 0.159 us | up_read();
1.303628 | 3) swapper-1 | 0.228 us | put_device();
1.303628 | 3) swapper-1 | 2.958 us | } /* tpm_put_ops */
1.303628 | 3) swapper-1 | # 1204.582 us | } /* tpm_pcr_read */
1.303629 | 3) swapper-1 | | crypto_shash_update() {
1.303629 | 3) swapper-1 | 0.183 us | crypto_sha1_update();
1.303630 | 3) swapper-1 | 0.974 us | } /* crypto_shash_update */
1.303630 | 3) swapper-1 | | crypto_shash_final() {
1.303630 | 3) swapper-1 | 0.720 us | sha1_final();
1.303631 | 3) swapper-1 | 1.155 us | } /* crypto_shash_final */
1.303631 | 3) swapper-1 | * 24661.94 us | } /* ima_calc_boot_aggregate_tfm */
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: init_ima() adds 8 % to boot time
2022-02-19 9:44 init_ima() adds 8 % to boot time Paul Menzel
@ 2022-02-20 15:19 ` Mimi Zohar
2022-02-20 22:57 ` Jarkko Sakkinen
2022-02-22 6:25 ` Petr Vorel
0 siblings, 2 replies; 6+ messages in thread
From: Mimi Zohar @ 2022-02-20 15:19 UTC (permalink / raw)
To: Paul Menzel, Dmitry Kasatkin, Jarkko Sakkinen
Cc: linux-integrity, LKML, Petr Vorel
[Cc'ing Jarkko, Petr Vorel]
Hi Paul,
On Sat, 2022-02-19 at 10:44 +0100, Paul Menzel wrote:
> Dear Linux folks,
>
>
> Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
> 5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
> around 33 ms, adding 8 % to the boot time up to loading the initrd.
>
> [ 0.000000] Linux version 5.17.0-rc4-amd64
> (debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
> ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
> (2022-02-18)
> […]
> [ 0.238520] calling init_tis+0x0/0xde @ 1
> [ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
> [ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
> […]
> [ 0.301327] calling init_ima+0x0/0xb5 @ 1
> [ 0.301332] ima: Allocated hash algorithm: sha256
> [ 0.335502] ima: No architecture policies found
> [ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
> […]
> [ 0.447312] Run /init as init process
>
> Tracing `init_ima` with a depth of 5 shows
> `ima_calc_boot_aggregate_tfm()` takes 24 ms, and
> `ima_add_template_entry()` takes 10 ms.
>
> 1.282630 | 1) swapper-1 | |
> ima_add_boot_aggregate() {
> 1.282631 | 1) swapper-1 | |
> ima_calc_boot_agg:0regate() {
> 1.282631 | 1) swapper-1 | 0.153 us |
> ima_alloc_tfm();
> 1.282631 | 1) swapper-1 | * 24404.59 us |
> ima_calc_boot_aggregate_tfm();
> 1.307037 | 1) swapper-1 | 0.482 us |
> ima_free_tfm.part.0();
> 1.307038 | 1) swapper-1 | * 24407.06 us | } /*
> ima_calc_boot_aggregate */
> 1.307038 | 1) swapper-1 | |
> ima_alloc_init_template() {
> 1.307038 | 1) swapper-1 | 0.173 us |
> ima_template_desc_current();
> 1.307039 | 1) swapper-1 | 0.836 us |
> __kmalloc();
> 1.307040 | 1) swapper-1 | 0.580 us |
> __kmalloc();
> 1.307041 | 1) swapper-1 | 1.555 us |
> ima_eventdigest_ng_init();
> 1.307043 | 1) swapper-1 | 1.275 us |
> ima_eventname_ng_init();
> 1.307044 | 1) swapper-1 | 0.256 us |
> ima_eventsig_init();
> 1.307045 | 1) swapper-1 | 6.618 us | } /*
> ima_alloc_init_template */
> 1.307045 | 1) swapper-1 | |
> ima_store_template() {
> 1.307045 | 1) swapper-1 | 5.049 us |
> ima_calc_field_array_hash();
> 1.307051 | 1) swapper-1 | # 9316.953 us |
> ima_add_template_entry();
> 1.316369 | 1) swapper-1 | # 9323.728 us | } /*
> ima_store_template */
> 1.316369 | 1) swapper-1 | * 33738.54 us | } /*
> ima_add_boot_aggregate */
>
> Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
> `tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
> the TPM supposed to be that slow?
>
> In the last years, Linux decreased it’s boot time a lot, so do you see a
> way to move things out of the hot path and get `init_ima` well below 10
> ms? (As systems get faster and faster, having systems with standard
> distributions to be up below two seconds after pressing the power button
> should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
> Linux kernel + 1 s user space).
>
>
> [1]:
> https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
Thank you including the initial and other TPM delays. The main reason
for the "boot_aggregate" is to tie the pre-OS measurements to the post
OS measurement list. Without the TPM based 'boot_aggregate', any IMA
measurement list could be used to verify a TPM quote. The
'boot_aggregate' is calculated, originally, based on PCRs 0 - 7 and
more recently may include PCRs 8 & 9 as well. The 'boot_aggregate' is
the first record in the IMA measurement list and the first record after
a soft reboot (kexec). It is the one and only IMA measurement record
not dependent on policy.
There are TPM 1.2 & 2.0 standards' requirements, but there are also
buggy TPMs which don't adhere to them to such an extent that IMA goes
into 'TPM-bypass' mode. Perhaps for those not interested in extending
the concepts of trusted boot to the running OS, defining a new boot
command line option to force IMA into this 'TPM-bypass' mode would be
an acceptable alternative to the delay. The IMA measurement list would
still include a 'boot_aggregate' record, but one containing 0's.
thanks,
Mimi
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: init_ima() adds 8 % to boot time
2022-02-20 15:19 ` Mimi Zohar
@ 2022-02-20 22:57 ` Jarkko Sakkinen
2022-02-20 23:19 ` Mimi Zohar
2022-02-22 6:25 ` Petr Vorel
1 sibling, 1 reply; 6+ messages in thread
From: Jarkko Sakkinen @ 2022-02-20 22:57 UTC (permalink / raw)
To: Mimi Zohar
Cc: Paul Menzel, Dmitry Kasatkin, linux-integrity, LKML, Petr Vorel
On Sun, Feb 20, 2022 at 10:19:37AM -0500, Mimi Zohar wrote:
> [Cc'ing Jarkko, Petr Vorel]
>
> Hi Paul,
>
> On Sat, 2022-02-19 at 10:44 +0100, Paul Menzel wrote:
> > Dear Linux folks,
> >
> >
> > Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
> > 5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
> > around 33 ms, adding 8 % to the boot time up to loading the initrd.
> >
> > [ 0.000000] Linux version 5.17.0-rc4-amd64
> > (debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
> > ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
> > (2022-02-18)
> > […]
> > [ 0.238520] calling init_tis+0x0/0xde @ 1
> > [ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
> > [ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
> > […]
> > [ 0.301327] calling init_ima+0x0/0xb5 @ 1
> > [ 0.301332] ima: Allocated hash algorithm: sha256
> > [ 0.335502] ima: No architecture policies found
> > [ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
> > […]
> > [ 0.447312] Run /init as init process
> >
> > Tracing `init_ima` with a depth of 5 shows
> > `ima_calc_boot_aggregate_tfm()` takes 24 ms, and
> > `ima_add_template_entry()` takes 10 ms.
> >
> > 1.282630 | 1) swapper-1 | |
> > ima_add_boot_aggregate() {
> > 1.282631 | 1) swapper-1 | |
> > ima_calc_boot_agg:0regate() {
> > 1.282631 | 1) swapper-1 | 0.153 us |
> > ima_alloc_tfm();
> > 1.282631 | 1) swapper-1 | * 24404.59 us |
> > ima_calc_boot_aggregate_tfm();
> > 1.307037 | 1) swapper-1 | 0.482 us |
> > ima_free_tfm.part.0();
> > 1.307038 | 1) swapper-1 | * 24407.06 us | } /*
> > ima_calc_boot_aggregate */
> > 1.307038 | 1) swapper-1 | |
> > ima_alloc_init_template() {
> > 1.307038 | 1) swapper-1 | 0.173 us |
> > ima_template_desc_current();
> > 1.307039 | 1) swapper-1 | 0.836 us |
> > __kmalloc();
> > 1.307040 | 1) swapper-1 | 0.580 us |
> > __kmalloc();
> > 1.307041 | 1) swapper-1 | 1.555 us |
> > ima_eventdigest_ng_init();
> > 1.307043 | 1) swapper-1 | 1.275 us |
> > ima_eventname_ng_init();
> > 1.307044 | 1) swapper-1 | 0.256 us |
> > ima_eventsig_init();
> > 1.307045 | 1) swapper-1 | 6.618 us | } /*
> > ima_alloc_init_template */
> > 1.307045 | 1) swapper-1 | |
> > ima_store_template() {
> > 1.307045 | 1) swapper-1 | 5.049 us |
> > ima_calc_field_array_hash();
> > 1.307051 | 1) swapper-1 | # 9316.953 us |
> > ima_add_template_entry();
> > 1.316369 | 1) swapper-1 | # 9323.728 us | } /*
> > ima_store_template */
> > 1.316369 | 1) swapper-1 | * 33738.54 us | } /*
> > ima_add_boot_aggregate */
> >
> > Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
> > `tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
> > the TPM supposed to be that slow?
> >
> > In the last years, Linux decreased it’s boot time a lot, so do you see a
> > way to move things out of the hot path and get `init_ima` well below 10
> > ms? (As systems get faster and faster, having systems with standard
> > distributions to be up below two seconds after pressing the power button
> > should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
> > Linux kernel + 1 s user space).
> >
> >
> > [1]:
> > https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
>
> Thank you including the initial and other TPM delays. The main reason
> for the "boot_aggregate" is to tie the pre-OS measurements to the post
> OS measurement list. Without the TPM based 'boot_aggregate', any IMA
> measurement list could be used to verify a TPM quote. The
> 'boot_aggregate' is calculated, originally, based on PCRs 0 - 7 and
> more recently may include PCRs 8 & 9 as well. The 'boot_aggregate' is
> the first record in the IMA measurement list and the first record after
> a soft reboot (kexec). It is the one and only IMA measurement record
> not dependent on policy.
>
> There are TPM 1.2 & 2.0 standards' requirements, but there are also
> buggy TPMs which don't adhere to them to such an extent that IMA goes
> into 'TPM-bypass' mode. Perhaps for those not interested in extending
> the concepts of trusted boot to the running OS, defining a new boot
> command line option to force IMA into this 'TPM-bypass' mode would be
> an acceptable alternative to the delay. The IMA measurement list would
> still include a 'boot_aggregate' record, but one containing 0's.
I support the opt-in boot option.
If the full hardware specifications are known for a device, you might want
to use this.
/Jarkko
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: init_ima() adds 8 % to boot time
2022-02-20 22:57 ` Jarkko Sakkinen
@ 2022-02-20 23:19 ` Mimi Zohar
2022-02-21 20:06 ` Jarkko Sakkinen
0 siblings, 1 reply; 6+ messages in thread
From: Mimi Zohar @ 2022-02-20 23:19 UTC (permalink / raw)
To: Jarkko Sakkinen
Cc: Paul Menzel, Dmitry Kasatkin, linux-integrity, LKML, Petr Vorel
On Sun, 2022-02-20 at 23:57 +0100, Jarkko Sakkinen wrote:
> On Sun, Feb 20, 2022 at 10:19:37AM -0500, Mimi Zohar wrote:
> > [Cc'ing Jarkko, Petr Vorel]
> >
> > Hi Paul,
> >
> > On Sat, 2022-02-19 at 10:44 +0100, Paul Menzel wrote:
> > > Dear Linux folks,
> > >
> > >
> > > Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
> > > 5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
> > > around 33 ms, adding 8 % to the boot time up to loading the initrd.
> > >
> > > [ 0.000000] Linux version 5.17.0-rc4-amd64
> > > (debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
> > > ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
> > > (2022-02-18)
> > > […]
> > > [ 0.238520] calling init_tis+0x0/0xde @ 1
> > > [ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
> > > [ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
> > > […]
> > > [ 0.301327] calling init_ima+0x0/0xb5 @ 1
> > > [ 0.301332] ima: Allocated hash algorithm: sha256
> > > [ 0.335502] ima: No architecture policies found
> > > [ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
> > > […]
> > > [ 0.447312] Run /init as init process
> > >
> > > Tracing `init_ima` with a depth of 5 shows
> > > `ima_calc_boot_aggregate_tfm()` takes 24 ms, and
> > > `ima_add_template_entry()` takes 10 ms.
> > >
> > > 1.282630 | 1) swapper-1 | |
> > > ima_add_boot_aggregate() {
> > > 1.282631 | 1) swapper-1 | |
> > > ima_calc_boot_agg:0regate() {
> > > 1.282631 | 1) swapper-1 | 0.153 us |
> > > ima_alloc_tfm();
> > > 1.282631 | 1) swapper-1 | * 24404.59 us |
> > > ima_calc_boot_aggregate_tfm();
> > > 1.307037 | 1) swapper-1 | 0.482 us |
> > > ima_free_tfm.part.0();
> > > 1.307038 | 1) swapper-1 | * 24407.06 us | } /*
> > > ima_calc_boot_aggregate */
> > > 1.307038 | 1) swapper-1 | |
> > > ima_alloc_init_template() {
> > > 1.307038 | 1) swapper-1 | 0.173 us |
> > > ima_template_desc_current();
> > > 1.307039 | 1) swapper-1 | 0.836 us |
> > > __kmalloc();
> > > 1.307040 | 1) swapper-1 | 0.580 us |
> > > __kmalloc();
> > > 1.307041 | 1) swapper-1 | 1.555 us |
> > > ima_eventdigest_ng_init();
> > > 1.307043 | 1) swapper-1 | 1.275 us |
> > > ima_eventname_ng_init();
> > > 1.307044 | 1) swapper-1 | 0.256 us |
> > > ima_eventsig_init();
> > > 1.307045 | 1) swapper-1 | 6.618 us | } /*
> > > ima_alloc_init_template */
> > > 1.307045 | 1) swapper-1 | |
> > > ima_store_template() {
> > > 1.307045 | 1) swapper-1 | 5.049 us |
> > > ima_calc_field_array_hash();
> > > 1.307051 | 1) swapper-1 | # 9316.953 us |
> > > ima_add_template_entry();
> > > 1.316369 | 1) swapper-1 | # 9323.728 us | } /*
> > > ima_store_template */
> > > 1.316369 | 1) swapper-1 | * 33738.54 us | } /*
> > > ima_add_boot_aggregate */
> > >
> > > Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
> > > `tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
> > > the TPM supposed to be that slow?
> > >
> > > In the last years, Linux decreased it’s boot time a lot, so do you see a
> > > way to move things out of the hot path and get `init_ima` well below 10
> > > ms? (As systems get faster and faster, having systems with standard
> > > distributions to be up below two seconds after pressing the power button
> > > should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
> > > Linux kernel + 1 s user space).
> > >
> > >
> > > [1]:
> > > https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
> >
> > Thank you including the initial and other TPM delays. The main reason
> > for the "boot_aggregate" is to tie the pre-OS measurements to the post
> > OS measurement list. Without the TPM based 'boot_aggregate', any IMA
> > measurement list could be used to verify a TPM quote. The
> > 'boot_aggregate' is calculated, originally, based on PCRs 0 - 7 and
> > more recently may include PCRs 8 & 9 as well. The 'boot_aggregate' is
> > the first record in the IMA measurement list and the first record after
> > a soft reboot (kexec). It is the one and only IMA measurement record
> > not dependent on policy.
> >
> > There are TPM 1.2 & 2.0 standards' requirements, but there are also
> > buggy TPMs which don't adhere to them to such an extent that IMA goes
> > into 'TPM-bypass' mode. Perhaps for those not interested in extending
> > the concepts of trusted boot to the running OS, defining a new boot
> > command line option to force IMA into this 'TPM-bypass' mode would be
> > an acceptable alternative to the delay. The IMA measurement list would
> > still include a 'boot_aggregate' record, but one containing 0's.
>
> I support the opt-in boot option.
>
> If the full hardware specifications are known for a device, you might want
> to use this.
The default would be to extend the TPM with the 'boot_aggregate', with
an option to opt-out of extending the TPM.
--
thanks,
Mimi
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: init_ima() adds 8 % to boot time
2022-02-20 23:19 ` Mimi Zohar
@ 2022-02-21 20:06 ` Jarkko Sakkinen
0 siblings, 0 replies; 6+ messages in thread
From: Jarkko Sakkinen @ 2022-02-21 20:06 UTC (permalink / raw)
To: Mimi Zohar
Cc: Paul Menzel, Dmitry Kasatkin, linux-integrity, LKML, Petr Vorel
On Sun, Feb 20, 2022 at 06:19:59PM -0500, Mimi Zohar wrote:
> On Sun, 2022-02-20 at 23:57 +0100, Jarkko Sakkinen wrote:
> > On Sun, Feb 20, 2022 at 10:19:37AM -0500, Mimi Zohar wrote:
> > > [Cc'ing Jarkko, Petr Vorel]
> > >
> > > Hi Paul,
> > >
> > > On Sat, 2022-02-19 at 10:44 +0100, Paul Menzel wrote:
> > > > Dear Linux folks,
> > > >
> > > >
> > > > Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
> > > > 5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
> > > > around 33 ms, adding 8 % to the boot time up to loading the initrd.
> > > >
> > > > [ 0.000000] Linux version 5.17.0-rc4-amd64
> > > > (debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
> > > > ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
> > > > (2022-02-18)
> > > > […]
> > > > [ 0.238520] calling init_tis+0x0/0xde @ 1
> > > > [ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
> > > > [ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
> > > > […]
> > > > [ 0.301327] calling init_ima+0x0/0xb5 @ 1
> > > > [ 0.301332] ima: Allocated hash algorithm: sha256
> > > > [ 0.335502] ima: No architecture policies found
> > > > [ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
> > > > […]
> > > > [ 0.447312] Run /init as init process
> > > >
> > > > Tracing `init_ima` with a depth of 5 shows
> > > > `ima_calc_boot_aggregate_tfm()` takes 24 ms, and
> > > > `ima_add_template_entry()` takes 10 ms.
> > > >
> > > > 1.282630 | 1) swapper-1 | |
> > > > ima_add_boot_aggregate() {
> > > > 1.282631 | 1) swapper-1 | |
> > > > ima_calc_boot_agg:0regate() {
> > > > 1.282631 | 1) swapper-1 | 0.153 us |
> > > > ima_alloc_tfm();
> > > > 1.282631 | 1) swapper-1 | * 24404.59 us |
> > > > ima_calc_boot_aggregate_tfm();
> > > > 1.307037 | 1) swapper-1 | 0.482 us |
> > > > ima_free_tfm.part.0();
> > > > 1.307038 | 1) swapper-1 | * 24407.06 us | } /*
> > > > ima_calc_boot_aggregate */
> > > > 1.307038 | 1) swapper-1 | |
> > > > ima_alloc_init_template() {
> > > > 1.307038 | 1) swapper-1 | 0.173 us |
> > > > ima_template_desc_current();
> > > > 1.307039 | 1) swapper-1 | 0.836 us |
> > > > __kmalloc();
> > > > 1.307040 | 1) swapper-1 | 0.580 us |
> > > > __kmalloc();
> > > > 1.307041 | 1) swapper-1 | 1.555 us |
> > > > ima_eventdigest_ng_init();
> > > > 1.307043 | 1) swapper-1 | 1.275 us |
> > > > ima_eventname_ng_init();
> > > > 1.307044 | 1) swapper-1 | 0.256 us |
> > > > ima_eventsig_init();
> > > > 1.307045 | 1) swapper-1 | 6.618 us | } /*
> > > > ima_alloc_init_template */
> > > > 1.307045 | 1) swapper-1 | |
> > > > ima_store_template() {
> > > > 1.307045 | 1) swapper-1 | 5.049 us |
> > > > ima_calc_field_array_hash();
> > > > 1.307051 | 1) swapper-1 | # 9316.953 us |
> > > > ima_add_template_entry();
> > > > 1.316369 | 1) swapper-1 | # 9323.728 us | } /*
> > > > ima_store_template */
> > > > 1.316369 | 1) swapper-1 | * 33738.54 us | } /*
> > > > ima_add_boot_aggregate */
> > > >
> > > > Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
> > > > `tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
> > > > the TPM supposed to be that slow?
> > > >
> > > > In the last years, Linux decreased it’s boot time a lot, so do you see a
> > > > way to move things out of the hot path and get `init_ima` well below 10
> > > > ms? (As systems get faster and faster, having systems with standard
> > > > distributions to be up below two seconds after pressing the power button
> > > > should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
> > > > Linux kernel + 1 s user space).
> > > >
> > > >
> > > > [1]:
> > > > https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
> > >
> > > Thank you including the initial and other TPM delays. The main reason
> > > for the "boot_aggregate" is to tie the pre-OS measurements to the post
> > > OS measurement list. Without the TPM based 'boot_aggregate', any IMA
> > > measurement list could be used to verify a TPM quote. The
> > > 'boot_aggregate' is calculated, originally, based on PCRs 0 - 7 and
> > > more recently may include PCRs 8 & 9 as well. The 'boot_aggregate' is
> > > the first record in the IMA measurement list and the first record after
> > > a soft reboot (kexec). It is the one and only IMA measurement record
> > > not dependent on policy.
> > >
> > > There are TPM 1.2 & 2.0 standards' requirements, but there are also
> > > buggy TPMs which don't adhere to them to such an extent that IMA goes
> > > into 'TPM-bypass' mode. Perhaps for those not interested in extending
> > > the concepts of trusted boot to the running OS, defining a new boot
> > > command line option to force IMA into this 'TPM-bypass' mode would be
> > > an acceptable alternative to the delay. The IMA measurement list would
> > > still include a 'boot_aggregate' record, but one containing 0's.
> >
> > I support the opt-in boot option.
> >
> > If the full hardware specifications are known for a device, you might want
> > to use this.
>
> The default would be to extend the TPM with the 'boot_aggregate', with
> an option to opt-out of extending the TPM.
Ah, right, thanks for correction. By "opt-in" I meant "opt-out" :-)
BR, Jarkko
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: init_ima() adds 8 % to boot time
2022-02-20 15:19 ` Mimi Zohar
2022-02-20 22:57 ` Jarkko Sakkinen
@ 2022-02-22 6:25 ` Petr Vorel
1 sibling, 0 replies; 6+ messages in thread
From: Petr Vorel @ 2022-02-22 6:25 UTC (permalink / raw)
To: Mimi Zohar
Cc: Paul Menzel, Dmitry Kasatkin, Jarkko Sakkinen, linux-integrity, LKML
Hi Mimi,
> [Cc'ing Jarkko, Petr Vorel]
Thanks!
> Hi Paul,
> On Sat, 2022-02-19 at 10:44 +0100, Paul Menzel wrote:
> > Dear Linux folks,
> > Debian builds its Linux kernel image with `CONFIG_IMA=y` since version
> > 5.13.9 [1]. Unfortunately, on the Dell Latitude E7250 `init_ima` takes
> > around 33 ms, adding 8 % to the boot time up to loading the initrd.
> > [ 0.000000] Linux version 5.17.0-rc4-amd64
> > (debian-kernel@lists.debian.org) (gcc-11 (Debian 11.2.0-16) 11.2.0, GNU
> > ld (GNU Binutils for Debian) 2.38) #1 SMP PREEMPT Debian 5.17~rc4-1~exp1
> > (2022-02-18)
> > […]
> > [ 0.238520] calling init_tis+0x0/0xde @ 1
> > [ 0.254749] tpm_tis 00:08: 1.2 TPM (device-id 0x3205, rev-id 80)
> > [ 0.285665] initcall init_tis+0x0/0xde returned 0 after 46038 usecs
> > […]
> > [ 0.301327] calling init_ima+0x0/0xb5 @ 1
> > [ 0.301332] ima: Allocated hash algorithm: sha256
> > [ 0.335502] ima: No architecture policies found
> > [ 0.335520] initcall init_ima+0x0/0xb5 returned 0 after 33389 usecs
> > […]
> > [ 0.447312] Run /init as init process
> > Tracing `init_ima` with a depth of 5 shows
> > `ima_calc_boot_aggregate_tfm()` takes 24 ms, and
> > `ima_add_template_entry()` takes 10 ms.
> > 1.282630 | 1) swapper-1 | |
> > ima_add_boot_aggregate() {
> > 1.282631 | 1) swapper-1 | |
> > ima_calc_boot_agg:0regate() {
> > 1.282631 | 1) swapper-1 | 0.153 us |
> > ima_alloc_tfm();
> > 1.282631 | 1) swapper-1 | * 24404.59 us |
> > ima_calc_boot_aggregate_tfm();
> > 1.307037 | 1) swapper-1 | 0.482 us |
> > ima_free_tfm.part.0();
> > 1.307038 | 1) swapper-1 | * 24407.06 us | } /*
> > ima_calc_boot_aggregate */
> > 1.307038 | 1) swapper-1 | |
> > ima_alloc_init_template() {
> > 1.307038 | 1) swapper-1 | 0.173 us |
> > ima_template_desc_current();
> > 1.307039 | 1) swapper-1 | 0.836 us |
> > __kmalloc();
> > 1.307040 | 1) swapper-1 | 0.580 us |
> > __kmalloc();
> > 1.307041 | 1) swapper-1 | 1.555 us |
> > ima_eventdigest_ng_init();
> > 1.307043 | 1) swapper-1 | 1.275 us |
> > ima_eventname_ng_init();
> > 1.307044 | 1) swapper-1 | 0.256 us |
> > ima_eventsig_init();
> > 1.307045 | 1) swapper-1 | 6.618 us | } /*
> > ima_alloc_init_template */
> > 1.307045 | 1) swapper-1 | |
> > ima_store_template() {
> > 1.307045 | 1) swapper-1 | 5.049 us |
> > ima_calc_field_array_hash();
> > 1.307051 | 1) swapper-1 | # 9316.953 us |
> > ima_add_template_entry();
> > 1.316369 | 1) swapper-1 | # 9323.728 us | } /*
> > ima_store_template */
> > 1.316369 | 1) swapper-1 | * 33738.54 us | } /*
> > ima_add_boot_aggregate */
> > Tracing `ima_calc_boot_aggregate_tfm()` (attached) shows that the first
> > `tpm1_pcr_read()` takes 16 ms in `tpm_transmit()`. Is communicating with
> > the TPM supposed to be that slow?
> > In the last years, Linux decreased it’s boot time a lot, so do you see a
> > way to move things out of the hot path and get `init_ima` well below 10
> > ms? (As systems get faster and faster, having systems with standard
> > distributions to be up below two seconds after pressing the power button
> > should be a reasonable goal (500 ms firmware (like coreboot) + 500 ms
> > Linux kernel + 1 s user space).
> > [1]:
> > https://salsa.debian.org/kernel-team/linux/-/commit/6e679322d7d98d30b4a8a3d1b659c899a6e9d4df
> Thank you including the initial and other TPM delays. The main reason
> for the "boot_aggregate" is to tie the pre-OS measurements to the post
> OS measurement list. Without the TPM based 'boot_aggregate', any IMA
> measurement list could be used to verify a TPM quote. The
> 'boot_aggregate' is calculated, originally, based on PCRs 0 - 7 and
> more recently may include PCRs 8 & 9 as well. The 'boot_aggregate' is
> the first record in the IMA measurement list and the first record after
> a soft reboot (kexec). It is the one and only IMA measurement record
> not dependent on policy.
> There are TPM 1.2 & 2.0 standards' requirements, but there are also
> buggy TPMs which don't adhere to them to such an extent that IMA goes
> into 'TPM-bypass' mode. Perhaps for those not interested in extending
> the concepts of trusted boot to the running OS, defining a new boot
> command line option to force IMA into this 'TPM-bypass' mode would be
> an acceptable alternative to the delay. The IMA measurement list would
> still include a 'boot_aggregate' record, but one containing 0's.
This sounds reasonable.
Kind regards,
Petr
> thanks,
> Mimi
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2022-02-22 6:25 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-02-19 9:44 init_ima() adds 8 % to boot time Paul Menzel
2022-02-20 15:19 ` Mimi Zohar
2022-02-20 22:57 ` Jarkko Sakkinen
2022-02-20 23:19 ` Mimi Zohar
2022-02-21 20:06 ` Jarkko Sakkinen
2022-02-22 6:25 ` Petr Vorel
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).