SELinuxProject / setools

SELinux Policy Analysis Tools
https://github.com/SELinuxProject/setools/wiki
Other
163 stars 67 forks source link

sediff huge memory usage #21

Closed n2N8Z closed 5 years ago

n2N8Z commented 5 years ago

OS: Fedora release 30 (Thirty) MemTotal: 12293456 kB

sediff from setools-console-4.1.1-14.fc30.x86_64

Trying to compare two binary policy files grabbed from a Red Hat 7 system after adding a port to a type.

cat /sys/fs/selinux/policy > policy.kern.28 semanage port -a ... cat /sys/fs/selinux/policy > policy.kern.28.2

[root@localhost ~]# file policy.kern.28 policy.kern.28.2 policy.kern.28: SE Linux policy v28 8 symbols 7 ocons policy.kern.28.2: SE Linux policy v28 8 symbols 7 ocons

-rw-r--r--. 1 root root 3726029 Jun 28 16:52 policy.kern.28 -rw-r--r--. 1 root root 3726073 Jun 28 16:56 policy.kern.28.2

sediff runs for about 1.5 hours using 97% memory, and then is killed:

[root@localhost ~]# sediff policy.kern.28 policy.kern.28.2 Policy Properties (0 Modified)

Killed

[root@localhost ~]# grep -i sediff /var/log/messages Jun 28 19:26:17 localhost kernel: sediff invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0 Jun 28 19:26:17 localhost kernel: CPU: 3 PID: 1183 Comm: sediff Not tainted 5.1.12-300.fc30.x86_64 #1 Jun 28 19:26:17 localhost kernel: [ 1183] 0 1183 3176496 2980396 25505792 192189 0 sediff Jun 28 19:26:17 localhost kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/user.slice/user-0.slice/session-1.scope,task=sediff,pid=1183,uid=0 Jun 28 19:26:17 localhost kernel: Out of memory: Killed process 1183 (sediff) total-vm:12705984kB, anon-rss:11921584kB, file-rss:0kB, shmem-rss:0kB Jun 28 19:26:17 localhost kernel: oom_reaper: reaped process 1183 (sediff), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

ghost commented 5 years ago

On Fri, Jun 28, 2019 at 10:48:38AM -0700, n2N8Z wrote:

OS: Fedora release 30 (Thirty) MemTotal: 12293456 kB

sediff from setools-console-4.1.1-14.fc30.x86_64

Trying to compare two binary policy files grabbed from a Red Hat 7 system after adding a port to a type.

cat /sys/fs/selinux/policy > policy.kern.28 semanage port -a ... cat /sys/fs/selinux/policy > policy.kern.28.2

[root@localhost ~]# file policy.kern.28 policy.kern.28.2 policy.kern.28: SE Linux policy v28 8 symbols 7 ocons policy.kern.28.2: SE Linux policy v28 8 symbols 7 ocons

-rw-r--r--. 1 root root 3726029 Jun 28 16:52 policy.kern.28 -rw-r--r--. 1 root root 3726073 Jun 28 16:56 policy.kern.28.2

sediff runs for about 1.5 hours using 97% memory, and then is killed:

[root@localhost ~]# sediff policy.kern.28 policy.kern.28.2 Policy Properties (0 Modified)

Killed

[root@localhost ~]# grep -i sediff /var/log/messages Jun 28 19:26:17 localhost kernel: sediff invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0 Jun 28 19:26:17 localhost kernel: CPU: 3 PID: 1183 Comm: sediff Not tainted 5.1.12-300.fc30.x86_64 #1 Jun 28 19:26:17 localhost kernel: [ 1183] 0 1183 3176496 2980396 25505792 192189 0 sediff Jun 28 19:26:17 localhost kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/user.slice/user-0.slice/session-1.scope,task=sediff,pid=1183,uid=0 Jun 28 19:26:17 localhost kernel: Out of memory: Killed process 1183 (sediff) total-vm:12705984kB, anon-rss:11921584kB, file-rss:0kB, shmem-rss:0kB Jun 28 19:26:17 localhost kernel: oom_reaper: reaped process 1183 (sediff), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

I noticed this as well but setools 4-1 is old. setools 4-2 is already released but for some reason it is not packaged in fedora

I think its probably a better idea to report that a newer version of setools is available to Fedora

-- You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub: https://github.com/SELinuxProject/setools/issues/21

-- Key fingerprint = 5F4D 3CDB D3F8 3652 FBD8 02D5 3B6C 5F1D 2C7B 6B02 https://sks-keyservers.net/pks/lookup?op=get&search=0x3B6C5F1D2C7B6B02 Dominick Grift

pebenito commented 5 years ago

I spent a lot of time improving the sediff memory usage in SETools 4.2. The full Fedora policy is massive, and takes something like 8-12GB of memory to diff 2 policies of that size with SETools 4.2.

n2N8Z commented 5 years ago

These are Red Hat 7 policies, and the system has 12GB. How much memory is required to compare them ?

n2N8Z commented 5 years ago

Same result with setools from git.

git clone https://github.com/SELinuxProject/setools.git cd setools/ python3 setup.py build_ext -i

[root@localhost setools]# date; ./sediff ../policy.kern.28 ../policy.kern.28.2 Fri 28 Jun 2019 08:11:32 PM CEST Policy Properties (0 Modified)

Killed

/var/log/messages

Jun 28 21:27:10 localhost kernel: sssd_nss invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0 Jun 28 21:27:10 localhost kernel: CPU: 5 PID: 971 Comm: sssd_nss Not tainted 5.1.12-300.fc30.x86_64 #1 Jun 28 21:27:10 localhost kernel: Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006 Jun 28 21:27:10 localhost kernel: Call Trace: Jun 28 21:27:10 localhost kernel: dump_stack+0x5c/0x80 Jun 28 21:27:10 localhost kernel: dump_header+0x51/0x2ff Jun 28 21:27:10 localhost kernel: ? kvm_sched_clock_read+0xd/0x20 Jun 28 21:27:10 localhost kernel: ? sched_clock+0x5/0x10 Jun 28 21:27:10 localhost kernel: ? oom_unkillable_task+0x9a/0xd0 Jun 28 21:27:10 localhost kernel: oom_kill_process.cold+0xb/0x10 Jun 28 21:27:10 localhost kernel: out_of_memory+0x1cd/0x470 Jun 28 21:27:10 localhost kernel: alloc_pages_slowpath+0xccb/0xdf0 Jun 28 21:27:10 localhost kernel: alloc_pages_nodemask+0x2f2/0x340 Jun 28 21:27:10 localhost kernel: pagecache_get_page+0xb4/0x370 Jun 28 21:27:10 localhost kernel: filemap_fault+0x702/0xad0 Jun 28 21:27:10 localhost kernel: ? switch_to_asm+0x41/0x70 Jun 28 21:27:10 localhost kernel: ? timerqueue_add+0x56/0x90 Jun 28 21:27:10 localhost kernel: ? page_add_file_rmap+0xfa/0x2d0 Jun 28 21:27:10 localhost kernel: ? alloc_set_pte+0x2d9/0x6b0 Jun 28 21:27:10 localhost kernel: ? _cond_resched+0x15/0x30 Jun 28 21:27:10 localhost kernel: xfs_filemap_fault+0x6d/0x200 [xfs] Jun 28 21:27:10 localhost kernel: __do_fault+0x36/0x180 Jun 28 21:27:10 localhost kernel: handle_mm_fault+0x1091/0x1ac0 Jun 28 21:27:10 localhost kernel: ? set_task_blocked+0x34/0xa0 Jun 28 21:27:10 localhost kernel: ? __hrtimer_init+0xb0/0xb0 Jun 28 21:27:10 localhost kernel: handle_mm_fault+0xdc/0x210 Jun 28 21:27:10 localhost kernel: do_user_addr_fault+0x1f6/0x450 Jun 28 21:27:10 localhost kernel: do_page_fault+0x33/0x120 Jun 28 21:27:10 localhost kernel: ? page_fault+0x8/0x30 Jun 28 21:27:10 localhost kernel: page_fault+0x1e/0x30 Jun 28 21:27:10 localhost kernel: RIP: 0033:0x7f9a1f06ff00 Jun 28 21:27:10 localhost kernel: Code: Bad RIP value. Jun 28 21:27:10 localhost kernel: RSP: 002b:00007ffe5a3957c0 EFLAGS: 00010202 Jun 28 21:27:10 localhost kernel: RAX: 0000000000000001 RBX: 000055a5a3d49b60 RCX: 00007f9a1f1335fb Jun 28 21:27:10 localhost kernel: RDX: 00007ffe5a3957c0 RSI: 00007ffe5a3958f0 RDI: 0000000000000000 Jun 28 21:27:10 localhost kernel: RBP: 000055a5a3d49a20 R08: 000000005d166a08 R09: 00007ffe5a3a80a0 Jun 28 21:27:10 localhost kernel: R10: 0000000000002706 R11: 0000000000000246 R12: 000055a5a3d49cb0 Jun 28 21:27:10 localhost kernel: R13: 0000000000002706 R14: 0000000000000000 R15: 0000000000000000 Jun 28 21:27:10 localhost kernel: Mem-Info: Jun 28 21:27:10 localhost kernel: active_anon:2712865 inactive_anon:273046 isolated_anon:0#012 active_file:22 inactive_file:13 isolated_file:0#012 unevictable:0 dirty:0 writeback:0 unstable:0#012 slab_reclaimable:9130 slab_unreclaimable:24600#012 mapped:267 shmem:1 pagetables:6875 bounce:0#012 free:29247 free_pcp:527 free_cma:0 Jun 28 21:27:10 localhost kernel: Node 0 active_anon:10851460kB inactive_anon:1092184kB active_file:88kB inactive_file:52kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:1068kB dirty:0kB writeback:0kB shmem:4kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no Jun 28 21:27:10 localhost kernel: Node 0 DMA free:15892kB min:84kB low:104kB high:124kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB Jun 28 21:27:10 localhost kernel: lowmem_reserve[]: 0 3478 11958 11958 11958 Jun 28 21:27:10 localhost kernel: Node 0 DMA32 free:53396kB min:19632kB low:24540kB high:29448kB active_anon:3525008kB inactive_anon:4kB active_file:56kB inactive_file:0kB unevictable:0kB writepending:0kB present:3653568kB managed:3588032kB mlocked:0kB kernel_stack:0kB pagetables:6892kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB Jun 28 21:27:10 localhost kernel: lowmem_reserve[]: 0 0 8479 8479 8479 Jun 28 21:27:10 localhost kernel: Node 0 Normal free:47700kB min:47860kB low:59824kB high:71788kB active_anon:7326452kB inactive_anon:1092180kB active_file:560kB inactive_file:844kB unevictable:0kB writepending:0kB present:8912896kB managed:8689516kB mlocked:0kB kernel_stack:3104kB pagetables:20608kB bounce:0kB free_pcp:2108kB local_pcp:284kB free_cma:0kB Jun 28 21:27:10 localhost kernel: lowmem_reserve[]: 0 0 0 0 0 Jun 28 21:27:10 localhost kernel: Node 0 DMA: 14kB (U) 08kB 116kB (U) 032kB 264kB (U) 1128kB (U) 1256kB (U) 0512kB 11024kB (U) 12048kB (M) 34096kB (M) = 15892kB Jun 28 21:27:10 localhost kernel: Node 0 DMA32: 1684kB (UME) 198kB (UME) 2816kB (UME) 1332kB (UME) 1564kB (UME) 6128kB (UME) 1256kB (E) 2512kB (UE) 21024kB (UM) 12048kB (E) 114096kB (M) = 53848kB Jun 28 21:27:10 localhost kernel: Node 0 Normal: 15164kB (UME) 9618kB (UME) 49816kB (UME) 26432kB (UME) 11464kB (UME) 32128kB (UE) 14256kB (UE) 0512kB 21024kB (M) 12048kB (M) 0*4096kB = 49240kB Jun 28 21:27:10 localhost kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB Jun 28 21:27:10 localhost kernel: 8495 total pagecache pages Jun 28 21:27:10 localhost kernel: 8318 pages in swap cache Jun 28 21:27:10 localhost kernel: Swap cache stats: add 467355, delete 459040, find 6560/35574 Jun 28 21:27:10 localhost kernel: Free swap = 0kB Jun 28 21:27:10 localhost kernel: Total swap = 839676kB Jun 28 21:27:10 localhost kernel: 3145614 pages RAM Jun 28 21:27:10 localhost kernel: 0 pages HighMem/MovableOnly Jun 28 21:27:10 localhost kernel: 72250 pages reserved Jun 28 21:27:10 localhost kernel: 0 pages cma reserved Jun 28 21:27:10 localhost kernel: 0 pages hwpoisoned Jun 28 21:27:10 localhost kernel: Tasks state (memory values in pages): Jun 28 21:27:10 localhost kernel: [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name Jun 28 21:27:10 localhost kernel: [ 720] 0 720 9141 70 159744 225 0 systemd-journal Jun 28 21:27:10 localhost kernel: [ 746] 0 746 11610 17 106496 831 -1000 systemd-udevd Jun 28 21:27:10 localhost kernel: [ 892] 0 892 26249 4 73728 173 -1000 auditd Jun 28 21:27:10 localhost kernel: [ 894] 0 894 1589 0 53248 97 0 sedispatch Jun 28 21:27:10 localhost kernel: [ 924] 0 924 78032 0 106496 277 0 rngd Jun 28 21:27:10 localhost kernel: [ 926] 0 926 42670 106 94208 814 0 rsyslogd Jun 28 21:27:10 localhost kernel: [ 927] 0 927 78309 0 98304 394 0 ModemManager Jun 28 21:27:10 localhost kernel: [ 930] 0 930 30572 2 147456 4966 0 firewalld Jun 28 21:27:10 localhost kernel: [ 932] 0 932 19813 29 57344 33 0 irqbalance Jun 28 21:27:10 localhost kernel: [ 933] 0 933 10901 14 98304 380 0 sssd Jun 28 21:27:10 localhost kernel: [ 934] 0 934 2818 1 49152 31 0 mcelog Jun 28 21:27:10 localhost kernel: [ 935] 0 935 2652 27 61440 310 0 smartd Jun 28 21:27:10 localhost kernel: [ 938] 0 938 65818 0 118784 507 0 abrtd Jun 28 21:27:10 localhost kernel: [ 940] 992 940 21752 32 65536 75 0 chronyd Jun 28 21:27:10 localhost kernel: [ 942] 0 942 13457 5 77824 171 0 gssproxy Jun 28 21:27:10 localhost kernel: [ 959] 81 959 67160 0 57344 186 -900 dbus-broker-lau Jun 28 21:27:10 localhost kernel: [ 964] 81 964 1396 75 49152 105 -900 dbus-broker Jun 28 21:27:10 localhost kernel: [ 966] 0 966 13071 28 110592 444 0 abrt-dump-journ Jun 28 21:27:10 localhost kernel: [ 967] 0 967 13071 34 118784 444 0 abrt-dump-journ Jun 28 21:27:10 localhost kernel: [ 968] 0 968 13074 34 110592 438 0 abrt-dump-journ Jun 28 21:27:10 localhost kernel: [ 970] 0 970 11018 18 98304 522 0 sssd_be Jun 28 21:27:10 localhost kernel: [ 971] 0 971 14279 60 135168 248 0 sssd_nss Jun 28 21:27:10 localhost kernel: [ 972] 0 972 6963 37 81920 615 0 systemd-logind Jun 28 21:27:10 localhost kernel: [ 974] 0 974 102587 64 155648 621 0 NetworkManager Jun 28 21:27:10 localhost kernel: [ 987] 0 987 6605 1 73728 217 -1000 sshd Jun 28 21:27:10 localhost kernel: [ 996] 0 996 4540 13 57344 38 0 atd Jun 28 21:27:10 localhost kernel: [ 1000] 0 1000 3933 62 53248 161 0 crond Jun 28 21:27:10 localhost kernel: [ 1001] 0 1001 2258 0 45056 32 0 agetty Jun 28 21:27:10 localhost kernel: [ 1037] 997 1037 487073 77 237568 1501 0 polkitd Jun 28 21:27:10 localhost kernel: [ 1106] 0 1106 3803 1 69632 491 0 dhclient Jun 28 21:27:10 localhost kernel: [ 1140] 0 1140 9615 1 86016 305 0 sshd Jun 28 21:27:10 localhost kernel: [ 1145] 0 1145 4961 1 77824 394 0 systemd Jun 28 21:27:10 localhost kernel: [ 1147] 0 1147 8682 0 94208 1344 0 (sd-pam) Jun 28 21:27:10 localhost kernel: [ 1152] 0 1152 9699 48 81920 315 0 sshd Jun 28 21:27:10 localhost kernel: [ 1153] 0 1153 4072 78 57344 343 0 bash Jun 28 21:27:10 localhost kernel: [ 1184] 0 1184 9615 1 81920 305 0 sshd Jun 28 21:27:10 localhost kernel: [ 1188] 0 1188 9699 88 73728 272 0 sshd Jun 28 21:27:10 localhost kernel: [ 1189] 0 1189 4006 0 61440 354 0 bash Jun 28 21:27:10 localhost kernel: [ 1214] 0 1214 4351 126 61440 72 0 top Jun 28 21:27:10 localhost kernel: [ 6815] 0 6815 3174543 2973882 25448448 190617 0 python3 Jun 28 21:27:10 localhost kernel: [ 6828] 0 6828 13788 2159 139264 1 0 dnf Jun 28 21:27:10 localhost kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/user.slice/user-0.slice/session-1.scope,task=python3,pid=6815,uid=0 Jun 28 21:27:10 localhost kernel: Out of memory: Killed process 6815 (python3) total-vm:12698172kB, anon-rss:11895528kB, file-rss:0kB, shmem-rss:0kB Jun 28 21:27:10 localhost kernel: oom_reaper: reaped process 6815 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB Jun 28 21:27:10 localhost dnf[6828]: Metadata cache refreshed recently. Jun 28 21:27:10 localhost systemd[1]: dnf-makecache.service: Succeeded. Jun 28 21:27:10 localhost systemd[1]: Started dnf makecache. Jun 28 21:27:10 localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Jun 28 21:27:10 localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

n2N8Z commented 5 years ago

with memory increased to 16GB the comparison completes MemTotal: 16422192 kB

date; ./sediff ../policy.kern.28 ../policy.kern.28.2 Fri 28 Jun 2019 10:02:06 PM CEST Policy Properties (0 Modified)

(no differences)

unexpectedly, I have to run the labeling comparison separately, but that completes in seconds:

date; ./sediff --portcon ../policy.kern.28 ../policy.kern.28.2; date Fri 28 Jun 2019 11:01:55 PM CEST Portcons (1 Added, 0 Removed, 0 Modified) Added Portcons: 1

  • portcon tcp 65535 system_u:object_r:syslog_es_port_t:s0

Fri 28 Jun 2019 11:01:56 PM CEST

bachradsusi commented 5 years ago

I noticed this as well but setools 4-1 is old. setools 4-2 is already released but for some reason it is not packaged in fedora I think its probably a better idea to report that a newer version of setools is available to Fedora

setools-4.2.1 should be available in Fedora 30 and later in setools module in 2.4 stream since 2019-05-14. As setools is python 3 only, and some userspace tools in Fedora still requires python 2 version of policycoreutils which requires setools, we could not update the standard build.

vmojzis commented 5 years ago

@n2N8Z As Petr explained, setools 4.2 are currently only available via module on Fedora 30. To list all available modules, use: # dnf module list

For more information about the module: # dnf module info setools Name : setools Stream : 4.2.0 [e] Version : 3020190304181401 Context : a5b0195c Architecture : x86_64 Profiles : default [i] ...

You can enable the module content (make it visible to "# dnf install"): # dnf module enable setools:4.2.0

Or directly install the "default" profile (which contains python3-setools and setools-console): # dnf module install setools/default

For more information please see https://docs.fedoraproject.org/en-US/modularity/using-modules/

The 4.2 stream with setools 4.2.1 should be available soon.

n2N8Z commented 5 years ago

@vmojzis I already retested with the same results using the latest version from git (See: https://github.com/SELinuxProject/setools/issues/21#issuecomment-506858779)

pebenito commented 5 years ago

I did some testing, and I believe this is simply the result of the size of the policy. A full refpolicy policy.31 is about 2.4MB. A diff with one portcon change still takes over 5GB memory to diff. How big is the RHEL7 policy?

n2N8Z commented 5 years ago

-rw-r--r--. 1 root root 3726029 Jun 28 16:52 policy.kern.28 -rw-r--r--. 1 root root 3726073 Jun 28 16:56 policy.kern.28.2

3.7MB

pebenito commented 5 years ago

I installed a CentOS7 system to get a policy roughly equivalent to yours. The allow rules expand to 20M rules, whereas refpolicy expands to 5M. Since the memory usage is proportionate to the rule size, I see no bug here.

pebenito commented 5 years ago

I put additional debugging statements in sediff, which you can enable with the --debug option. The expanded allow rule size is typically what consumes the most size:

2019-07-13 20:20:59,120|DEBUG|setools.diff.terules|Expanded allow rules for ../refpolicy/policy.31.old: 5307847
2019-07-13 20:22:00,929|DEBUG|setools.diff.terules|Expanded allow rules for ../refpolicy/policy.31: 5320377
n2N8Z commented 5 years ago

Comparing Red Hat policy.31 requires 38GB of memory (https://github.com/SELinuxProject/setools/issues/22#issuecomment-511482911)

2019-07-15 17:00:36,286|DEBUG|setools.diff.terules|Expanded allow rules for ../policy.kern.31: 20955632 2019-07-15 17:04:53,496|DEBUG|setools.diff.terules|Expanded allow rules for ../policy.kern.31.2: 20955632