Re: [PATCH v5 3/4] LSM: Define SELinux function to measure state and policy

[Lakshmi Ramasubramanian <nramas@linux.microsoft.com>]

On 8/3/20 1:29 PM, Stephen Smalley wrote:
> On 8/3/20 4:00 PM, Stephen Smalley wrote:
> 
>> On Mon, Aug 3, 2020 at 12:14 PM Lakshmi Ramasubramanian
>> <nramas@linux.microsoft.com> wrote:
>>> On 8/3/20 8:11 AM, Stephen Smalley wrote:
>>>> Possibly I'm missing something but with these patches applied on top of
>>>> next-integrity, and the following lines added to /etc/ima/ima-policy:
>>>>
>>>> measure func=LSM_STATE template=ima-buf
>>>> measure func=LSM_POLICY
>>>>
>>>> I still don't get the selinux-state or selinux-policy-hash entries in
>>>> the ascii_runtime_measurements file.  No errors during loading of the
>>>> ima policy as far as I can see.
>>>>
>>> Could you please check if the following config is set?
>>> CONFIG_IMA_QUEUE_EARLY_BOOT_DATA=y
>> Yes, I have that set.
>>
>>> Try changing /sys/fs/selinux/checkreqprot and check
>>> ascii_runtime_measurements file again?
>> No change.  Likewise for changing enforce or running load_policy again.
>>
>>> Also, could you please check if
>>> /sys/kernel/security/integrity/ima/policy contains LSM_STATE and
>>> LSM_POLICY entries?
>> Yes, it does.  However, I noticed that if I reduce the policy to only
>> contain those entries and no others and reboot, then I get
>> measurements.  Whereas if I append them to an existing policy like the
>> one below, they seem to be ignored:
>> dont_measure fsmagic=0x9fa0
>> dont_measure fsmagic=0x62656572
>> dont_measure fsmagic=0x64626720
>> dont_measure fsmagic=0x1021994
>> dont_measure fsmagic=0x858458f6
>> dont_measure fsmagic=0x73636673
>> measure func=BPRM_CHECK
>> measure func=MMAP_CHECK mask=MAY_EXEC
>> measure func=MODULE_CHECK uid=0
>> measure func=LSM_STATE template=ima-buf
>> measure func=LSM_POLICY
>>
>> Also, I noticed the following in my dmesg output:
>> [   68.870715] ------------[ cut here ]------------
>> [   68.870715] WARNING: CPU: 2 PID: 1 at mm/page_alloc.c:4826
>> __alloc_pages_nodemask+0x627/0x700
>> [   68.870715] Modules linked in: 8139too crct10dif_pclmul
>> crc32_pclmul crc32c_intel ghash_clmulni_intel qxl serio_raw
>> drm_ttm_helper ttm drm_kms_helper virtio_console cec drm 8139cp
>> ata_generic mii pata_acpi floppy qemu_fw_cfg fuse
>> [   68.870715] CPU: 2 PID: 1 Comm: systemd Not tainted 5.8.0-rc2+ #44
>> [   68.870715] RIP: 0010:__alloc_pages_nodemask+0x627/0x700
>> [   68.870715] Code: ff ff 75 6c 48 8b 85 48 ff ff ff 4c 89 c2 44 89
>> e6 44 89 ff 41 c6 45 d0 00 49 89 45 b8 e8 41 e2 ff ff 49 89 c6 e9 9d
>> fc ff ff <0f> 0b e9 d4 fd ff ff 0f 0b e9 bc fc ff ff 0f 0b e9 f9 fd ff
>> ff e8
>> [   68.870715] RSP: 0000:ffff8881e82a7a18 EFLAGS: 00010246
>> [   68.870715] RAX: ffffed103d054f48 RBX: 1ffff1103d054f48 RCX: 
>> 0000000000000000
>> [   68.870715] RDX: 0000000000000000 RSI: 000000000000000b RDI: 
>> 0000000000000000
>> [   68.870715] RBP: ffff8881e82a7ae8 R08: ffffffffaa3fe2d5 R09: 
>> 0000000000000001
>> [   68.870715] R10: fffffbfff5a88f0f R11: 0000000000000001 R12: 
>> 00000000007eef6a
>> [   68.870715] R13: 0000000000040cc0 R14: 000000000000000b R15: 
>> ffffffffadde766b
>> [   68.870715] FS:  00007fdeb168c600(0000) GS:ffff8881e9800000(0000)
>> knlGS:0000000000000000
>> [   68.870715] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   68.870715] CR2: 00007fdeb17dd1d6 CR3: 00000001cc2d2002 CR4: 
>> 00000000003606e0
>> [   68.870715] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 
>> 0000000000000000
>> [   68.870715] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 
>> 0000000000000400
>> [   68.870715] Call Trace:
>> [   68.870715]  ? sched_clock_cpu+0xf5/0x110
>> [   68.870715]  ? __alloc_pages_slowpath.constprop.0+0x17a0/0x17a0
>> [   68.870715]  ? match_held_lock+0x2e/0x240
>> [   68.870715]  ? policy_nodemask+0x1a/0xa0
>> [   68.870715]  ? policy_node+0x56/0x60
>> [   68.870715]  kmalloc_order+0x25/0xc0
>> [   68.870715]  kmalloc_order_trace+0x1d/0x140
>> [   68.870715]  kmemdup+0x1a/0x40
>> [   68.870715]  ima_queue_data+0x61/0x370
>> [   68.870715]  ima_measure_lsm_data+0x32/0x60
>> [   68.870715]  selinux_measure_state+0x2b8/0x2bd
>> [   68.870715]  ? selinux_event_name+0xe0/0xe0
>> [   68.870715]  ? rcu_is_watching+0x39/0x50
>> [   68.870715]  security_load_policy+0x44c/0x8e0
>> [   68.870715]  ? mark_lock+0xa6/0xbd0
>> [   68.870715]  ? security_change_sid+0x90/0x90
>> [   68.870715]  ? mark_held_locks+0x3e/0xa0
>> [   68.870715]  ? lockdep_hardirqs_on_prepare+0x100/0x260
>> [   68.870715]  ? asm_exc_page_fault+0x1e/0x30
>> [   68.870715]  ? lockdep_hardirqs_on+0xc5/0x1b0
>> [   68.870715]  ? asm_exc_page_fault+0x1e/0x30
>> [   68.870715]  ? copy_user_enhanced_fast_string+0xe/0x30
>> [   68.870715]  sel_write_load+0x157/0x260
>> [   68.870715]  vfs_write+0x135/0x290
>> [   68.870715]  ksys_write+0xb1/0x140
>> [   68.870715]  ? __ia32_sys_read+0x50/0x50
>> [   68.870715]  ? lockdep_hardirqs_on_prepare+0x100/0x260
>> [   68.870715]  ? do_syscall_64+0x12/0xb0
>> [   68.870715]  do_syscall_64+0x52/0xb0
>> [   68.870715]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
>> [   68.870715] RIP: 0033:0x7fdeb2539497
>> [   68.870715] Code: Bad RIP value.
>> [   68.870715] RSP: 002b:00007fff6352b308 EFLAGS: 00000246 ORIG_RAX:
>> 0000000000000001
>> [   68.870715] RAX: ffffffffffffffda RBX: 0000000000000020 RCX: 
>> 00007fdeb2539497
>> [   68.870715] RDX: 00000000007eef6a RSI: 00007fdeb0de1000 RDI: 
>> 0000000000000004
>> [   68.870715] RBP: 0000000000000004 R08: 00007fdeb25d0040 R09: 
>> 00007fff6352b1a0
>> [   68.870715] R10: 0000000000000000 R11: 0000000000000246 R12: 
>> 00007fdeb0de1000
>> [   68.870715] R13: 00000000007eef6a R14: 000000000000000f R15: 
>> 0000000000000003
>> [   68.870715] irq event stamp: 23486085
>> [   68.870715] hardirqs last  enabled at (23486085):
>> [<ffffffffaa419406>] _raw_spin_unlock_irqrestore+0x46/0x60
>> [   68.870715] hardirqs last disabled at (23486084):
>> [<ffffffffaa419443>] _raw_spin_lock_irqsave+0x23/0x90
>> [   68.870715] softirqs last  enabled at (23486074):
>> [<ffffffffaa8004f3>] __do_softirq+0x4f3/0x662
>> [   68.870715] softirqs last disabled at (23486067):
>> [<ffffffffaa601072>] asm_call_on_stack+0x12/0x20
>> [   68.870715] ---[ end trace fb02740ff6f4d0cd ]---
> 
> I think one issue here is that systemd loads SELinux policy first, then 
> IMA policy, so it doesn't know whether it needs to measure SELinux 
> policy on first policy load, and another issue is that the policy is too 
> large to just queue the policy data itself this way (or you need to use 
> an allocator that can handle larger sizes).
> 

The problem seems to be that a lock is held when the IMA hook to measure 
the LSM state is called. So memory allocation is not allowed, but the 
hook is doing an allocation. I'll address this - thanks for catching it.

I have the following CONFIGs enabled, but I still don't see the above 
issue on my machine.

Could you please let me know what CONFIG(s) to enable?

#
# Lock Debugging (spinlocks, mutexes, etc...)
#
CONFIG_LOCK_DEBUGGING_SUPPORT=y
CONFIG_PROVE_LOCKING=y
CONFIG_DEBUG_RT_MUTEXES=y
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_MUTEXES=y
CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y
CONFIG_DEBUG_RWSEMS=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_LOCKDEP=y
CONFIG_DEBUG_ATOMIC_SLEEP=y

I'll also try with the policy you have, check why the LSM policy is 
ignored when there are other policy entries.

thanks,
  -lakshmi