Long load time on log in and restart of web server

We have a new Open Ondemand instance 1.8.20 running on RHEL 8.3. Everything works great except there is about a one minute delay between authenticating with DUO/LDAP and the home page appearing. It also takes roughly one minute to refresh the home page when clicking the “Restart Web Server” button.

It seems to me that this is in the PUN part of the system because of where it occurs. The DUO push is rapid and there appears to be no lag there.

Is this delay common or am I running up against something else?

Jack
University of Colorado- Boulder

Log files from a login attempt and a restart of web server

/var/log/httpd/error_log

[Thu Aug 19 08:01:14.647087 2021] [lua:warn] [pid 146085:tid 139956274067200] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:14.875841 2021] [lua:warn] [pid 146085:tid 139956257281792] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:15.094346 2021] [lua:warn] [pid 146311:tid 139955980453632] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:15.163096 2021] [lua:warn] [pid 146085:tid 139956240496384] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:15.368496 2021] [lua:warn] [pid 146085:tid 139956232103680] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:15.519949 2021] [lua:warn] [pid 146085:tid 139956005631744] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)
[Thu Aug 19 08:01:19.397011 2021] [lua:warn] [pid 146311:tid 139955359688448] AH01471: Lua error: /opt/ood/mod_ood_proxy/lib/logger.lua:22: bad argument #2 to 'date' (number has no integer representation)

/var/log/httpd/ondemand.rc.colorado.edu_access_ssl.log

128.138.138.145 - - [19/Aug/2021:08:00:32 -0600] "GET /pun/sys/files/fs/home/jasw8470 HTTP/1.1" 302 474 "https://ondemand.rc.colorado.edu/pun/sys/dashboard/batch_connect/sys/my_matlab/session_contexts/new" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0"
128.138.138.145 - jasw8470 [19/Aug/2021:08:00:45 -0600] "GET /oidc?code=xstplesbshkzrep2fw4fuhif2&state=fkzk6OQD7ebcyGZYvg1BjDCImbE HTTP/1.1" 302 247 "https://ondemand.rc.colorado.edu:5554/" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0"
128.138.138.145 - - [19/Aug/2021:08:04:27 -0600] "GET /public/rc_logo.png?timestamp=1629381867 HTTP/1.1" 200 9674 "https://ondemand.rc.colorado.edu/pun/sys/dashboard/" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0"
128.138.138.145 - - [19/Aug/2021:08:04:27 -0600] "GET /public/ralphie-logo-small.png HTTP/1.1" 200 2838 "https://ondemand.rc.colorado.edu/pun/sys/dashboard/" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0"
128.138.138.145 - - [19/Aug/2021:08:04:28 -0600] "GET /public/favicon.ico HTTP/1.1" 200 1150 "https://ondemand.rc.colorado.edu/pun/sys/dashboard/" "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0"
80.82.77.192 - - [19/Aug/2021:08:11:07 -0600] "GET / HTTP/1.1" 301 245 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.190 Safari/537.36"
80.82.77.192 - - [19/Aug/2021:08:11:08 -0600] "GET / HTTP/1.1" 302 234 "https://198.59.51.26:443/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.190 Safari/537.36"
80.82.77.192 - - [19/Aug/2021:08:11:08 -0600] "GET /pun/sys/dashboard HTTP/1.1" 302 474 "https://ondemand.rc.colorado.edu:443/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.190 Safari/537.36"

If I log out and then log back in the system returns very quickly (no delay). However, “Restart Web Server” still takes about one minute.

Jack

Hi sorry we never responded to your query. Do you have a test system you can hack around on shows the same behaviour?

Yes I do. It was where I originally noticed the problem.

You can override your nginx_bin in nginx_stage.yml with a wrapper script with something like this. This is something I just had on hand, but you could tweak the strace arguements to get timing information. That’ll at least indicate how long it takes the Nginx to startup.

If the Nginx startup is quick - then it’s the OnDemand dashboard app that’s slow, and we’ll have to figure out a way to troubleshoot that if it comes to it.

#!/bin/bash

strace -o /tmp/strace.out /opt/ood/ondemand/root/usr/sbin/nginx $@

I have tried what you suggested but am not as familiar with strace as I should be.

I configured the nginx_stage.yml file as follows (all comments removed for clarity):

[root@ondemand1 ~]# cat /etc/ood/config/nginx_stage.yml | grep -v "#"

---

 pun_custom_env:
   OOD_DASHBOARD_TITLE: "Open OnDemand"
   OOD_DASHBOARD_TITLE: "CURC Open OnDemand"
   OOD_DASHBOARD_LOGO: "/public/rc_logo.png"
   OOD_DASHBOARD_LOGO_HEIGHT: 200
   OOD_DASHBOARD_HEADER_IMG_LOGO: "/public/ralphie-logo-small.png

 nginx_bin: '/opt/ood/ondemand/root/usr/sbin/nginx-diag'

And the wrapper script:

[root@ondemand1 ~]# cat  /opt/ood/ondemand/root/sbin/nginx-diag
#!/bin/bash



strace -o /tmp/strace.out /opt/ood/ondemand/root/usr/sbin/nginx $@

I get no strace.out file but do see this in the web browser after logging in. There is a longer delay than normal between the Duo push and this appearing.

image

Yea sorry about that. I run this in a container where I add --cap-add sys_ptrace.

So this is running as apache and even if you added sudo here it wouldn’t allow it, because this is the only sudo rule we have.

apache ALL=(ALL) NOPASSWD: /opt/ood/nginx_stage/sbin/nginx_stage

You’ll have to allow apache to execute this script with sudo privileges (and add sudo to the nginx_bin setting).

I’m now bolding this statement because it’s important: delete this sudo file when you’re done testing. I’ve named it ‘delme’ as a reminder to do so.

# /etc/sudoers.d/delme
apache ALL=(ALL) NOPASSWD: /opt/ood/ondemand/root/sbin/nginx-diag

Still getting the same message. Tries running the command as apache and get the following error output:

[root@ondemand1 ~]# sudo -u apache /opt/ood/ondemand/root/sbin/nginx-diag 
nginx: [alert] could not open error log file: open() "/var/log/ondemand-nginx/error.log" failed (13: Permission denied)
2021/08/20 13:11:03 [emerg] 2622#0: mkdir() "/var/lib/ondemand-nginx/tmp/client_body" failed (13: Permission denied)

But I see this in a strace.out file.

[root@ondemand1 ~]# cat /tmp/strace.out.1
execve("/opt/ood/ondemand/root/usr/sbin/nginx", ["/opt/ood/ondemand/root/usr/sbin/"…], 0x7ffcf93980d0 /* 18 vars /) = 0
brk(NULL) = 0x55857ef38000
arch_prctl(0x3001 /
ARCH_??? */, 0x7ffd68c759b0) = -1 EINVAL (Invalid argument)
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, “/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=40497, …}) = 0
mmap(NULL, 40497, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f0ad64f0000
close(3) = 0
openat(AT_FDCWD, “/lib64/libdl.so.2”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\20\0\0\0\0\0\0”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=28968, …}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64ee000
mmap(NULL, 2109744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad60ce000
mprotect(0x7f0ad60d1000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad62d0000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f0ad62d0000
close(3) = 0
openat(AT_FDCWD, “/lib64/libpthread.so.0”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200n\0\0\0\0\0\0”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=320504, …}) = 0
mmap(NULL, 2225344, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad5eae000
mprotect(0x7f0ad5ec9000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad60c8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a000) = 0x7f0ad60c8000
mmap(0x7f0ad60ca000, 13504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad60ca000
close(3) = 0
openat(AT_FDCWD, “/lib64/libcrypt.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\23\0\0\0\0\0\0”…, 832) = 832
lseek(3, 127864, SEEK_SET) = 127864
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=142712, …}) = 0
lseek(3, 127864, SEEK_SET) = 127864
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2261384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad5c85000
mprotect(0x7f0ad5ca5000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad5ea4000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f000) = 0x7f0ad5ea4000
mmap(0x7f0ad5ea5000, 33160, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad5ea5000
close(3) = 0
openat(AT_FDCWD, “/lib64/libstdc++.so.6”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\373\10\0\0\0\0\0”…, 832) = 832
lseek(3, 1594712, SEEK_SET) = 1594712
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=1661376, …}) = 0
lseek(3, 1594712, SEEK_SET) = 1594712
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 3753504, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad58f0000
mprotect(0x7f0ad5a76000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad5c75000, 53248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x185000) = 0x7f0ad5c75000
mmap(0x7f0ad5c82000, 9760, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad5c82000
close(3) = 0
openat(AT_FDCWD, “/lib64/libm.so.6”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\305\0\0\0\0\0\0”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2191808, …}) = 0
mmap(NULL, 3674432, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad556e000
mprotect(0x7f0ad56ef000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad58ee000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x180000) = 0x7f0ad58ee000
close(3) = 0
openat(AT_FDCWD, “/lib64/librt.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340#\0\0\0\0\0\0”…, 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=68944, …}) = 0
mmap(NULL, 2128832, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad5366000
mprotect(0x7f0ad536d000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad556c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f0ad556c000
close(3) = 0
openat(AT_FDCWD, “/lib64/libpcre.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\27\0\0\0\0\0\0"..., 832) = 832 lseek(3, 456544, SEEK_SET) = 456544 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=471224, ...}) = 0 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64ec000 lseek(3, 456544, SEEK_SET) = 456544 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2556168, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad50f5000 mprotect(0x7f0ad5165000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad5364000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6f000) = 0x7f0ad5364000 close(3) = 0 openat(AT_FDCWD, "/lib64/libssl.so.1.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\376\1\0\0\0\0\0”…, 832) = 832
lseek(3, 549880, SEEK_SET) = 549880
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
fstat(3, {st_mode=S_IFREG|0755, st_size=615576, …}) = 0
lseek(3, 549880, SEEK_SET) = 549880
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
mmap(NULL, 2699312, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad4e61000
mprotect(0x7f0ad4ee8000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad50e7000, 53248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x86000) = 0x7f0ad50e7000
mmap(0x7f0ad50f4000, 48, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad50f4000
close(3) = 0
openat(AT_FDCWD, “/lib64/libcrypto.so.1.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\260\7\0\0\0\0\0”…, 832) = 832
lseek(3, 2827832, SEEK_SET) = 2827832
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
fstat(3, {st_mode=S_IFREG|0755, st_size=3071456, …}) = 0
lseek(3, 2827832, SEEK_SET) = 2827832
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
mmap(NULL, 5136384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad497b000
mprotect(0x7f0ad4c2e000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad4e2d000, 196608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2b2000) = 0x7f0ad4e2d000
mmap(0x7f0ad4e5d000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad4e5d000
close(3) = 0
openat(AT_FDCWD, “/lib64/libz.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@’\0\0\0\0\0\0”…, 832) = 832
lseek(3, 88664, SEEK_SET) = 88664
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
fstat(3, {st_mode=S_IFREG|0755, st_size=95416, …}) = 0
lseek(3, 88664, SEEK_SET) = 88664
read(3, “\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0”…, 48) = 48
mmap(NULL, 2187272, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad4764000
mprotect(0x7f0ad477a000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad4979000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7f0ad4979000
mmap(0x7f0ad497a000, 8, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad497a000
close(3) = 0
openat(AT_FDCWD, “/lib64/libxml2.so.2”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\364\2\0\0\0\0\0"..., 832) = 832 lseek(3, 1428056, SEEK_SET) = 1428056 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=1503376, ...}) = 0 lseek(3, 1428056, SEEK_SET) = 1428056 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 3568024, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad43fc000 mprotect(0x7f0ad4559000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad4758000, 40960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15c000) = 0x7f0ad4758000 mmap(0x7f0ad4762000, 4504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad4762000 close(3) = 0 openat(AT_FDCWD, "/lib64/libxslt.so.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\300\0\0\0\0\0\0"..., 832) = 832 lseek(3, 256800, SEEK_SET) = 256800 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=268856, ...}) = 0 lseek(3, 256800, SEEK_SET) = 256800 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2360680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad41bb000 mprotect(0x7f0ad41fa000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad43f9000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3e000) = 0x7f0ad43f9000 close(3) = 0 openat(AT_FDCWD, "/lib64/libexslt.so.0", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320G\0\0\0\0\0\0"..., 832) = 832 lseek(3, 84600, SEEK_SET) = 84600 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=95400, ...}) = 0 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64ea000 lseek(3, 84600, SEEK_SET) = 84600 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2187280, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad3fa4000 mprotect(0x7f0ad3fb9000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad41b9000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7f0ad41b9000 close(3) = 0 openat(AT_FDCWD, "/lib64/libgd.so.3", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360\364\0\0\0\0\0\0"..., 832) = 832 lseek(3, 264056, SEEK_SET) = 264056 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=419968, ...}) = 0 lseek(3, 264056, SEEK_SET) = 264056 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2526088, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad3d3b000 mprotect(0x7f0ad3d7c000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad3f7b000, 151552, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x40000) = 0x7f0ad3f7b000 mmap(0x7f0ad3fa0000, 15240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad3fa0000 close(3) = 0 openat(AT_FDCWD, "/lib64/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0.\0\0\0\0\0\0"..., 832) = 832 lseek(3, 92624, SEEK_SET) = 92624 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=99656, ...}) = 0 lseek(3, 92624, SEEK_SET) = 92624 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2192080, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad3b23000 mprotect(0x7f0ad3b3a000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad3d39000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f0ad3d39000 close(3) = 0 openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\209\2\0\0\0\0\0"..., 832) = 832 fstat(3, {st_mode=S_IFREG|0755, st_size=3154704, ...}) = 0 lseek(3, 808, SEEK_SET) = 808 read(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\330\1\0\0\0\0\0\0"..., 48) = 48 mmap(NULL, 3942144, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad3760000 mprotect(0x7f0ad3919000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad3b19000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b9000) = 0x7f0ad3b19000 mmap(0x7f0ad3b1f000, 14080, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad3b1f000 close(3) = 0 openat(AT_FDCWD, "/lib64/liblzma.so.5", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\2405\0\0\0\0\0\0"..., 832) = 832 lseek(3, 150808, SEEK_SET) = 150808 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=192016, ...}) = 0 lseek(3, 150808, SEEK_SET) = 150808 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2252808, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad3539000 mprotect(0x7f0ad355e000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad375e000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7f0ad375e000 mmap(0x7f0ad375f000, 8, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad375f000 close(3) = 0 openat(AT_FDCWD, "/lib64/libgcrypt.so.20", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\273\0\0\0\0\0\0"..., 832) = 832 lseek(3, 1143856, SEEK_SET) = 1143856 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=1188080, ...}) = 0 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64e8000 lseek(3, 1143856, SEEK_SET) = 1143856 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 3268552, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad321b000 mprotect(0x7f0ad3333000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad3532000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x117000) = 0x7f0ad3532000 close(3) = 0 openat(AT_FDCWD, "/lib64/libgpg-error.so.0", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0PH\0\0\0\0\0\0"..., 832) = 832 lseek(3, 125832, SEEK_SET) = 125832 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=144392, ...}) = 0 lseek(3, 125832, SEEK_SET) = 125832 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2228800, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad2ffa000 mprotect(0x7f0ad3019000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad3219000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f000) = 0x7f0ad3219000 close(3) = 0 openat(AT_FDCWD, "/lib64/libpng16.so.16", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240^\0\0\0\0\0\0"..., 832) = 832 lseek(3, 207344, SEEK_SET) = 207344 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=229144, ...}) = 0 lseek(3, 207344, SEEK_SET) = 207344 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2310152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad2dc5000 mprotect(0x7f0ad2df8000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad2ff8000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x33000) = 0x7f0ad2ff8000 mmap(0x7f0ad2ff9000, 8, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad2ff9000 close(3) = 0 openat(AT_FDCWD, "/lib64/libfontconfig.so.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320|\0\0\0\0\0\0"..., 832) = 832 lseek(3, 271496, SEEK_SET) = 271496 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=300680, ...}) = 0 lseek(3, 271496, SEEK_SET) = 271496 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 2376328, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad2b80000 mprotect(0x7f0ad2bc3000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad2dc2000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x42000) = 0x7f0ad2dc2000 close(3) = 0 openat(AT_FDCWD, "/lib64/libfreetype.so.6", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\326\0\0\0\0\0\0"..., 832) = 832 lseek(3, 737672, SEEK_SET) = 737672 read(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0"..., 48) = 48 fstat(3, {st_mode=S_IFREG|0755, st_size=782968, ...}) = 0 lseek(3, 737672, SEEK_SET) = 737672 read(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\1\0\0\300\4\0\0\0\30\0\0\0\0\0\0\0"..., 48) = 48 mmap(NULL, 2863112, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad28c4000 mprotect(0x7f0ad2979000, 2093056, PROT_NONE) = 0 mmap(0x7f0ad2b78000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb4000) = 0x7f0ad2b78000 mmap(0x7f0ad2b7f000, 8, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad2b7f000 close(3) = 0 openat(AT_FDCWD, "/lib64/libjpeg.so.62", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0A\0\0\0\0\0\0”…, 832) = 832
lseek(3, 419808, SEEK_SET) = 419808
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=527008, …}) = 0
lseek(3, 419808, SEEK_SET) = 419808
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2523152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad265b000
mprotect(0x7f0ad26c2000, 2097152, PROT_NONE) = 0
mmap(0x7f0ad28c2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x67000) = 0x7f0ad28c2000
close(3) = 0
openat(AT_FDCWD, “/lib64/libXpm.so.4”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0207\0\0\0\0\0\0”…, 832) = 832
lseek(3, 69896, SEEK_SET) = 69896
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=78744, …}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64e6000
lseek(3, 69896, SEEK_SET) = 69896
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2171184, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad2448000
mprotect(0x7f0ad245a000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad2659000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x11000) = 0x7f0ad2659000
close(3) = 0
openat(AT_FDCWD, “/lib64/libX11.so.6”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\t\2\0\0\0\0\0"..., 832) = 832 lseek(3, 1297800, SEEK_SET) = 1297800 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 fstat(3, {st_mode=S_IFREG|0755, st_size=1343952, ...}) = 0 lseek(3, 1297800, SEEK_SET) = 1297800 read(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32) = 32 mmap(NULL, 3422456, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad2104000 mprotect(0x7f0ad2241000, 2097152, PROT_NONE) = 0 mmap(0x7f0ad2441000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13d000) = 0x7f0ad2441000 close(3) = 0 openat(AT_FDCWD, "/lib64/libtiff.so.5", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\223\0\0\0\0\0\0”…, 832) = 832
lseek(3, 475472, SEEK_SET) = 475472
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=501640, …}) = 0
lseek(3, 475472, SEEK_SET) = 475472
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2589680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad1e8b000
mprotect(0x7f0ad1f00000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad20ff000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x74000) = 0x7f0ad20ff000
close(3) = 0
openat(AT_FDCWD, “/lib64/libwebp.so.7”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`)\0\0\0\0\0\0”…, 832) = 832
lseek(3, 433240, SEEK_SET) = 433240
read(3, “\4\0\0\0000\0\0\0\5\0\0\0GNU\0\0\0\0\300\4\0\0\0\0\6\0\0\0\0\0\0”…, 64) = 64
fstat(3, {st_mode=S_IFREG|0755, st_size=486344, …}) = 0
lseek(3, 433240, SEEK_SET) = 433240
read(3, “\4\0\0\0000\0\0\0\5\0\0\0GNU\0\0\0\0\300\4\0\0\0\0\6\0\0\0\0\0\0”…, 64) = 64
mmap(NULL, 2544536, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad1c1d000
mprotect(0x7f0ad1c87000, 2097152, PROT_NONE) = 0
mmap(0x7f0ad1e87000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6a000) = 0x7f0ad1e87000
mmap(0x7f0ad1e89000, 5016, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad1e89000
close(3) = 0
openat(AT_FDCWD, “/lib64/libexpat.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 =\0\0\0\0\0\0”…, 832) = 832
lseek(3, 227408, SEEK_SET) = 227408
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=243984, …}) = 0
lseek(3, 227408, SEEK_SET) = 227408
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2334728, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad19e2000
mprotect(0x7f0ad1a1a000, 2097152, PROT_NONE) = 0
mmap(0x7f0ad1c1a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x38000) = 0x7f0ad1c1a000
mmap(0x7f0ad1c1c000, 8, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad1c1c000
close(3) = 0
openat(AT_FDCWD, “/lib64/libuuid.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200\32\0\0\0\0\0\0”…, 832) = 832
lseek(3, 24344, SEEK_SET) = 24344
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=33232, …}) = 0
lseek(3, 24344, SEEK_SET) = 24344
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2125840, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad17da000
mprotect(0x7f0ad17e0000, 2097152, PROT_NONE) = 0
mmap(0x7f0ad19e0000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f0ad19e0000
mmap(0x7f0ad19e1000, 16, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad19e1000
close(3) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64e4000
openat(AT_FDCWD, “/lib64/libbz2.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\31\0\0\0\0\0\0”…, 832) = 832
lseek(3, 64336, SEEK_SET) = 64336
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=74744, …}) = 0
lseek(3, 64336, SEEK_SET) = 64336
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2165768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad15c9000
mprotect(0x7f0ad15d9000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad17d8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xf000) = 0x7f0ad17d8000
close(3) = 0
openat(AT_FDCWD, “/lib64/libxcb.so.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\300\0\0\0\0\0\0”…, 832) = 832
lseek(3, 161248, SEEK_SET) = 161248
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=170208, …}) = 0
lseek(3, 161248, SEEK_SET) = 161248
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2261160, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad13a0000
mprotect(0x7f0ad13c8000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad15c7000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x27000) = 0x7f0ad15c7000
close(3) = 0
openat(AT_FDCWD, “/lib64/libjbig.so.2.1”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \21\0\0\0\0\0\0”…, 832) = 832
lseek(3, 34816, SEEK_SET) = 34816
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=52504, …}) = 0
lseek(3, 34816, SEEK_SET) = 34816
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2145032, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad1194000
mprotect(0x7f0ad119d000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad139c000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x8000) = 0x7f0ad139c000
close(3) = 0
openat(AT_FDCWD, “/lib64/libXau.so.6”, O_RDONLY|O_CLOEXEC) = 3
read(3, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\20\0\0\0\0\0\0”…, 832) = 832
lseek(3, 8432, SEEK_SET) = 8432
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
fstat(3, {st_mode=S_IFREG|0755, st_size=16352, …}) = 0
lseek(3, 8432, SEEK_SET) = 8432
read(3, “\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0”, 32) = 32
mmap(NULL, 2109472, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0ad0f90000
mprotect(0x7f0ad0f93000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad1192000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f0ad1192000
mmap(0x7f0ad1193000, 32, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad1193000
close(3) = 0

Had to cut the strace.out in half to work around the character limits.

mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64e2000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64e0000
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0ad64dd000
arch_prctl(ARCH_SET_FS, 0x7f0ad64dd7c0) = 0
mprotect(0x7f0ad3b19000, 16384, PROT_READ) = 0
mprotect(0x7f0ad1192000, 4096, PROT_READ) = 0
mprotect(0x7f0ad139c000, 4096, PROT_READ) = 0
mprotect(0x7f0ad15c7000, 4096, PROT_READ) = 0
mprotect(0x7f0ad17d8000, 4096, PROT_READ) = 0
mprotect(0x7f0ad19e0000, 4096, PROT_READ) = 0
mprotect(0x7f0ad1c1a000, 8192, PROT_READ) = 0
mprotect(0x7f0ad60c8000, 4096, PROT_READ) = 0
mprotect(0x7f0ad58ee000, 4096, PROT_READ) = 0
mprotect(0x7f0ad1e87000, 4096, PROT_READ) = 0
mprotect(0x7f0ad4979000, 4096, PROT_READ) = 0
mprotect(0x7f0ad28c2000, 4096, PROT_READ) = 0
mprotect(0x7f0ad20ff000, 16384, PROT_READ) = 0
mprotect(0x7f0ad62d0000, 4096, PROT_READ) = 0
mprotect(0x7f0ad2441000, 12288, PROT_READ) = 0
mprotect(0x7f0ad2659000, 4096, PROT_READ) = 0
mprotect(0x7f0ad2ff8000, 4096, PROT_READ) = 0
mprotect(0x7f0ad2b78000, 28672, PROT_READ) = 0
mprotect(0x7f0ad2dc2000, 8192, PROT_READ) = 0
mprotect(0x7f0ad3219000, 4096, PROT_READ) = 0
mprotect(0x7f0ad3532000, 8192, PROT_READ) = 0
mprotect(0x7f0ad375e000, 4096, PROT_READ) = 0
mprotect(0x7f0ad3d39000, 4096, PROT_READ) = 0
mprotect(0x7f0ad3f7b000, 24576, PROT_READ) = 0
mprotect(0x7f0ad4758000, 36864, PROT_READ) = 0
mprotect(0x7f0ad43f9000, 8192, PROT_READ) = 0
mprotect(0x7f0ad41b9000, 4096, PROT_READ) = 0
mprotect(0x7f0ad4e2d000, 180224, PROT_READ) = 0
mprotect(0x7f0ad50e7000, 36864, PROT_READ) = 0
mprotect(0x7f0ad5364000, 4096, PROT_READ) = 0
mprotect(0x7f0ad556c000, 4096, PROT_READ) = 0
mprotect(0x7f0ad5c75000, 49152, PROT_READ) = 0
mprotect(0x7f0ad5ea4000, 4096, PROT_READ) = 0
mprotect(0x55857e33c000, 32768, PROT_READ) = 0
mprotect(0x7f0ad64fa000, 4096, PROT_READ) = 0
munmap(0x7f0ad64f0000, 40497) = 0
set_tid_address(0x7f0ad64dda90) = 2622
set_robust_list(0x7f0ad64ddaa0, 24) = 0
rt_sigaction(SIGRTMIN, {sa_handler=0x7f0ad5eb4900, sa_mask=, sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x7f0ad5ec0b30}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x7f0ad5eb4990, sa_mask=, sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0x7f0ad5ec0b30}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=81921024, rlim_max=RLIM64_INFINITY}) = 0
brk(NULL) = 0x55857ef38000
brk(0x55857ef59000) = 0x55857ef59000
access("/etc/system-fips", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/gcrypt/fips_enabled", F_OK) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, “/proc/sys/crypto/fips_enabled”, O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, …}) = 0
read(3, “0\n”, 1024) = 2
close(3) = 0
openat(AT_FDCWD, “/proc/sys/crypto/fips_enabled”, O_RDONLY) = 3
read(3, “0\n”, 2) = 2
close(3) = 0
access("/etc/system-fips", F_OK) = -1 ENOENT (No such file or directory)
futex(0x7f0ad5c8267c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad5c82688, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, “/etc/localtime”, O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2453, …}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=2453, …}) = 0
read(3, “TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\5\0\0\0\0”…, 4096) = 2453
lseek(3, -1559, SEEK_CUR) = 894
read(3, “TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\5\0\0\0\0”…, 4096) = 1559
close(3) = 0
getpid() = 2622
getppid() = 2619
openat(AT_FDCWD, “/var/log/ondemand-nginx/error.log”, O_WRONLY|O_CREAT|O_APPEND, 0644) = -1 EACCES (Permission denied)
write(2, “nginx: [alert] could not open er”…, 120) = 120
futex(0x7f0ad4e5f858, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f84c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f844, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f940, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f830, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f828, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5c7dc, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f244, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f1dc, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f1d0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
brk(NULL) = 0x55857ef59000
brk(0x55857ef7a000) = 0x55857ef7a000
futex(0x7f0ad4e5f83c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f7f8, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad4e5f7f0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, “/etc/pki/tls/openssl.cnf”, O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=11225, …}) = 0
read(3, “#\n# OpenSSL example configuratio”…, 4096) = 4096
stat("/etc/crypto-policies/back-ends/opensslcnf.config", {st_mode=S_IFREG|0644, st_size=583, …}) = 0
openat(AT_FDCWD, “/etc/crypto-policies/back-ends/opensslcnf.config”, O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=583, …}) = 0
read(4, “CipherString = @SECLEVEL=2:kEECD”…, 4096) = 583
read(4, “”, 4096) = 0
close(4) = 0
read(3, ", T61String, BMPString.\n# pkix\t "…, 4096) = 4096
read(3, "tyKeyIdentifier=keyid:always\n\n[ "…, 4096) = 3033
read(3, “”, 4096) = 0
close(3) = 0
futex(0x7f0ad4e5f820, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f0ad50f3f40, FUTEX_WAKE_PRIVATE, 2147483647) = 0
sysinfo({uptime=458, loads=[0, 7040, 5664], totalram=16602161152, freeram=15680786432, sharedram=14188544, bufferram=6545408, totalswap=8468295680, freeswap=8468295680, procs=586, totalhigh=0, freehigh=0, mem_unit=1}) = 0
futex(0x7f0ad50f4028, FUTEX_WAKE_PRIVATE, 2147483647) = 0
uname({sysname=“Linux”, nodename=“ondemand1.rc.int.colorado.edu”, …}) = 0
openat(AT_FDCWD, “/sys/devices/system/cpu/online”, O_RDONLY|O_CLOEXEC) = 3
read(3, “0-3\n”, 8192) = 4
close(3) = 0
prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=1024, rlim_max=256
1024}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2453, …}) = 0
uname({sysname=“Linux”, nodename=“ondemand1.rc.int.colorado.edu”, …}) = 0
openat(AT_FDCWD, “/opt/rh/ondemand/root/etc/nginx/nginx.conf”, O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2656, …}) = 0
pread64(3, “\n#user nobody;\nworker_processes”…, 2656, 0) = 2656
epoll_create(100) = 4
close(4) = 0
brk(NULL) = 0x55857ef7a000
brk(0x55857ef9d000) = 0x55857ef9d000
futex(0x7f0ad4762e88, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, “/opt/rh/ondemand/root/etc/nginx/mime.types”, O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=5231, …}) = 0
pread64(4, “\ntypes {\n text/html “…, 4096, 0) = 4096
pread64(4, “pplication/octet-stream “…, 1135, 4096) = 1135
close(4) = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_UNIX, sun_path=”/var/run/nscd/socket”}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_UNIX, sun_path=”/var/run/nscd/socket”}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
openat(AT_FDCWD, “/etc/nsswitch.conf”, O_RDONLY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=361, …}) = 0
read(4, “passwd: files sss\nshadow: “…, 4096) = 361
read(4, “”, 4096) = 0
close(4) = 0
openat(AT_FDCWD, “/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=40497, …}) = 0
mmap(NULL, 40497, PROT_READ, MAP_PRIVATE, 4, 0) = 0x7f0ad64f0000
close(4) = 0
openat(AT_FDCWD, “/lib64/libnss_files.so.2”, O_RDONLY|O_CLOEXEC) = 4
read(4, “\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p’\0\0\0\0\0\0”…, 832) = 832
fstat(4, {st_mode=S_IFREG|0755, st_size=76872, …}) = 0
mmap(NULL, 2168664, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 4, 0) = 0x7f0ad0d7e000
mprotect(0x7f0ad0d89000, 2093056, PROT_NONE) = 0
mmap(0x7f0ad0f88000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 4, 0xa000) = 0x7f0ad0f88000
mmap(0x7f0ad0f8a000, 22360, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0ad0f8a000
close(4) = 0
mprotect(0x7f0ad0f88000, 4096, PROT_READ) = 0
munmap(0x7f0ad64f0000, 40497) = 0
openat(AT_FDCWD, “/etc/passwd”, O_RDONLY|O_CLOEXEC) = 4
lseek(4, 0, SEEK_CUR) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=1795, …}) = 0
read(4, “root:x:0:0:root:/root:/bin/bash\n”…, 4096) = 1795
close(4) = 0
brk(NULL) = 0x55857ef9d000
brk(0x55857efbe000) = 0x55857efbe000
close(3) = 0
geteuid() = 48
mkdir(”/var/lib/ondemand-nginx/tmp/client_body”, 0700) = -1 EACCES (Permission denied)
write(2, “2021/08/20 13:11:03 [emerg] 2622”…, 117) = 117
exit_group(1) = ?
+++ exited with 1 +++

You should be able to attach txt files.

Since you have root, you can just do something like this (be sure to get rid of that sudo rule you made!). We have to be sure the Nginx is starting up with the OOD configurations - not just regular Nginx with defaults.

[root@fa0500aec078 ~]# /opt/ood/nginx_stage/sbin/nginx_stage pun --user jeff

But as a quick spot check - you can try time (instead of strace) in front of those commands to see how long it takes.

If you do continue to use strace you’d need -T to get timing information for each call.

strace.txt (707.0 KB)

I ran the following and received the following error output and the attached strace file.

[root@ondemand1 my_jupyter_app]# strace -T -o /tmp/strace.out  /opt/ood/nginx_stage/sbin/nginx_stage pun --user jasw8470
nginx: [emerg] bind() to unix:/var/run/ondemand-nginx/jasw8470/passenger.sock failed (98: Address already in use)
nginx: [emerg] bind() to unix:/var/run/ondemand-nginx/jasw8470/passenger.sock failed (98: Address already in use)
nginx: [emerg] bind() to unix:/var/run/ondemand-nginx/jasw8470/passenger.sock failed (98: Address already in use)
nginx: [emerg] bind() to unix:/var/run/ondemand-nginx/jasw8470/passenger.sock failed (98: Address already in use)
nginx: [emerg] bind() to unix:/var/run/ondemand-nginx/jasw8470/passenger.sock failed (98: Address already in use)
nginx: [emerg] still could not bind()

Running with time instead shows the same errors and times as follows:

real	0m3.454s
user	0m0.316s
sys	0m0.140s

Right - you’d need to clean the PUN before you restart it (i.e., it’s already running so it can’t start another on the same socket)

So every time you start it, you’ll have to stop it to start a new test.

[root@fa0500aec078 ~]# /opt/ood/nginx_stage/sbin/nginx_stage nginx_clean --user jeff

OK. So I cleaned the old PUN and re-ran the command

strace -T -o /tmp/strace.out /opt/ood/nginx_stage/sbin/nginx_stage pun --user jasw8470

Created the attached strace file.

strace.txt (702.6 KB)

I don’t think my problem lies in the PUN realm. It is responsive and fast when called.

It seems to be authentication related. The first time I log in it has the delay but if I use the log out button and log back in there is no delay.

Jack

It definitely involves SELinux. If I set SELinux to permissive, the delay disappears. ALthough I don’t really see anything in the audit logs but maybe somebody else can.

Login started at 9:08:20
Home screen returned at 9:08:50
Restart web server “button” at 9:09:06
Home screen returned at 9:10:04
setenforce 0 9:10:35
Restart web server “button” at 9:11:00
Home screen returned at 9:11:07

type=USER_ACCT msg=audit(08/23/2021 09:08:18.642:552) : pid=42823 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:accounting grantors=pam_unix,pam_localuser acct=apache exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_CMD msg=audit(08/23/2021 09:08:18.643:553) : pid=42823 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘cwd=/ cmd=/opt/ood/nginx_stage/sbin/nginx_stage pun -u jasw8470 -a http%3a%2f%2fondemand1.rc.int.colorado.edu%3a80%2fnginx%2finit%3fredir%3d%24http_x_forwarded_escaped_uri exe=/usr/bin/sudo terminal=? res=success’

type=CRED_REFR msg=audit(08/23/2021 09:08:18.643:554) : pid=42823 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_START msg=audit(08/23/2021 09:08:43.671:555) : pid=42823 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_END msg=audit(08/23/2021 09:08:44.284:556) : pid=42823 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=CRED_DISP msg=audit(08/23/2021 09:08:44.284:557) : pid=42823 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_ACCT msg=audit(08/23/2021 09:09:06.423:558) : pid=42930 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:accounting grantors=pam_unix,pam_localuser acct=apache exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_CMD msg=audit(08/23/2021 09:09:06.423:559) : pid=42930 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘cwd=/ cmd=/opt/ood/nginx_stage/sbin/nginx_stage nginx -u jasw8470 -s stop exe=/usr/bin/sudo terminal=? res=success’

type=CRED_REFR msg=audit(08/23/2021 09:09:06.424:560) : pid=42930 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_START msg=audit(08/23/2021 09:09:31.439:561) : pid=42930 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_END msg=audit(08/23/2021 09:09:31.784:562) : pid=42930 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=CRED_DISP msg=audit(08/23/2021 09:09:31.784:563) : pid=42930 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_ACCT msg=audit(08/23/2021 09:09:32.041:564) : pid=42965 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:accounting grantors=pam_unix,pam_localuser acct=apache exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_CMD msg=audit(08/23/2021 09:09:32.041:565) : pid=42965 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘cwd=/ cmd=/opt/ood/nginx_stage/sbin/nginx_stage pun -u jasw8470 -a http%3a%2f%2fondemand1.rc.int.colorado.edu%3a80%2fnginx%2finit%3fredir%3d%24http_x_forwarded_escaped_uri exe=/usr/bin/sudo terminal=? res=success’

type=CRED_REFR msg=audit(08/23/2021 09:09:32.042:566) : pid=42965 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_START msg=audit(08/23/2021 09:09:57.065:567) : pid=42965 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_END msg=audit(08/23/2021 09:09:57.677:568) : pid=42965 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=CRED_DISP msg=audit(08/23/2021 09:09:57.677:569) : pid=42965 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=PROCTITLE msg=audit(08/23/2021 09:10:34.824:570) : proctitle=setenforce 0
type=SYSCALL msg=audit(08/23/2021 09:10:34.824:570) : arch=x86_64 syscall=write success=yes exit=1 a0=0x3 a1=0x7ffe3bb7b860 a2=0x1 a3=0x0 items=0 ppid=39033 pid=43076 auid=root uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=pts0 ses=4 comm=setenforce exe=/usr/sbin/setenforce subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null)
type=MAC_STATUS msg=audit(08/23/2021 09:10:34.824:570) : enforcing=0 old_enforcing=1 auid=root ses=4 enabled=1 old-enabled=1 lsm=selinux res=yes

type=USER_AVC msg=audit(08/23/2021 09:10:34.824:571) : pid=1040 uid=dbus auid=unset ses=unset subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg=‘avc: received setenforce notice (enforcing=0) exe=/usr/bin/dbus-daemon sauid=dbus hostname=? addr=? terminal=?’

type=USER_ACCT msg=audit(08/23/2021 09:11:00.421:572) : pid=43092 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:accounting grantors=pam_unix,pam_localuser acct=apache exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_CMD msg=audit(08/23/2021 09:11:00.422:573) : pid=43092 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘cwd=/ cmd=/opt/ood/nginx_stage/sbin/nginx_stage nginx -u jasw8470 -s stop exe=/usr/bin/sudo terminal=? res=success’

type=CRED_REFR msg=audit(08/23/2021 09:11:00.422:574) : pid=43092 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_START msg=audit(08/23/2021 09:11:00.434:575) : pid=43092 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_END msg=audit(08/23/2021 09:11:01.267:576) : pid=43092 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=CRED_DISP msg=audit(08/23/2021 09:11:01.267:577) : pid=43092 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_ACCT msg=audit(08/23/2021 09:11:01.507:578) : pid=43116 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:accounting grantors=pam_unix,pam_localuser acct=apache exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_CMD msg=audit(08/23/2021 09:11:01.508:579) : pid=43116 uid=apache auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘cwd=/ cmd=/opt/ood/nginx_stage/sbin/nginx_stage pun -u jasw8470 -a http%3a%2f%2fondemand1.rc.int.colorado.edu%3a80%2fnginx%2finit%3fredir%3d%24http_x_forwarded_escaped_uri exe=/usr/bin/sudo terminal=? res=success’

type=CRED_REFR msg=audit(08/23/2021 09:11:01.508:580) : pid=43116 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_START msg=audit(08/23/2021 09:11:01.518:581) : pid=43116 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=USER_END msg=audit(08/23/2021 09:11:02.102:582) : pid=43116 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

type=CRED_DISP msg=audit(08/23/2021 09:11:02.102:583) : pid=43116 uid=root auid=unset ses=unset subj=system_u:system_r:httpd_t:s0 msg=‘op=PAM:setcred grantors=pam_env,pam_unix acct=root exe=/usr/bin/sudo hostname=? addr=? terminal=? res=success’

Had to disable dontaudit in SELinux to see the denials ( semodule -DB ).

New module created for SELinux that fixes the delay issue.

module ood_login 1.0;

require {
	type systemd_logind_sessions_t;
	type sshd_t;
	type httpd_t;
	type chkpwd_t;
	type initrc_var_run_t;
	type sssd_conf_t;
	class capability net_admin;
	class file { getattr read };
	class process { noatsecure rlimitinh siginh };
	class fifo_file write;
}

#============= httpd_t ==============
allow httpd_t chkpwd_t:process { noatsecure rlimitinh siginh };
allow httpd_t initrc_var_run_t:file read;
allow httpd_t self:capability net_admin;
allow httpd_t sssd_conf_t:file getattr;
allow httpd_t systemd_logind_sessions_t:fifo_file write;

#============= sshd_t ==============
allow sshd_t chkpwd_t:process { noatsecure rlimitinh siginh };