Flush profile data on demand using SIGUSR1 signal
#1751
Conversation
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewed 5 of 5 files at r1, all commit messages.
Reviewable status: all files reviewed, 8 unresolved discussions, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ) (waiting on @jkr0103)
a discussion (no related file):
This PR looks surprisingly simple. Nice! Thanks for this.
a discussion (no related file):
Could you copy-paste some examples from your experiments? I'd like to see how things look like in reality (before testing myself locally).
Also, what applications would you recommend to test?
Documentation/performance.rst line 636 at r1 (raw file):
signal which would help in cases where user would like to collect profile data only for a particular period (e.g., during benchmarks run). Send SIGUSR1 signal using command ``kill -SIGUSR1 <pid>``.
You should also mention that sending multiple SIGUSR1 will create multiple files, each containing profile data collected after the previous SIGUSR1. And that this is helpful when the application runs in clearly separated stages.
pal/src/host/linux-sgx/host_exception.c line 191 at r1 (raw file):
} static void handle_async_sigusr1_signal(int signum, siginfo_t* info, struct ucontext* uc) {
That's a too long name. SIGUSR1 is already a "signal" and already a "asynchronous" one.
So just rename to handle_sigusr1()
pal/src/host/linux-sgx/host_exception.c line 201 at r1 (raw file):
sgx_profile_init(); struct debug_map* map = g_debug_map;
Please add the same comment from here:
gramine/pal/src/host/linux-sgx/host_main.c
Line 314 in 1cf1f46
pal/src/host/linux-sgx/host_profile.c line 127 at r1 (raw file):
ret = DO_SYSCALL(clock_gettime, CLOCK_REALTIME, &ts); if (ret < 0) { log_error("sgx_profile_sample: clock_gettime failed: %s", unix_strerror(ret));
sgx_profile_init:
pal/src/host/linux-sgx/host_profile.c line 128 at r1 (raw file):
if (ret < 0) { log_error("sgx_profile_sample: clock_gettime failed: %s", unix_strerror(ret)); return false;
What is this? Should be goto out;
pal/src/host/linux-sgx/host_profile.c line 133 at r1 (raw file):
if (g_pal_enclave.profile_append_pid_to_filename) { snprintf(g_pal_enclave.profile_filename, ARRAY_SIZE(g_pal_enclave.profile_filename), SGX_PROFILE_FILENAME_WITH_PID, (int)g_host_pid, ts.tv_sec);
profile_filename is 64 chars in size. Now that we also add the number of seconds, are we sure we still fit in 64 chars limit? Please check how many chars in the filenames you see in your experiments.
I think we can increase to 128 chars in size, and this will be more than enough.
pal/src/host/linux-sgx/host_profile.c line 197 at r1 (raw file):
g_mem_fd = -1; log_always("Profile data written to %s (%lu bytes)", g_pal_enclave.profile_filename, size);
Why this change?
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 1 of 5 files reviewed, 8 unresolved discussions, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv)
a discussion (no related file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Could you copy-paste some examples from your experiments? I'd like to see how things look like in reality (before testing myself locally).
Also, what applications would you recommend to test?
Done.
Documentation/performance.rst line 636 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
You should also mention that sending multiple SIGUSR1 will create multiple files, each containing profile data collected after the previous SIGUSR1. And that this is helpful when the application runs in clearly separated stages.
Done.
pal/src/host/linux-sgx/host_exception.c line 191 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
That's a too long name. SIGUSR1 is already a "signal" and already a "asynchronous" one.
So just rename to
handle_sigusr1()
Done.
pal/src/host/linux-sgx/host_exception.c line 201 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please add the same comment from here:
gramine/pal/src/host/linux-sgx/host_main.c
Line 314 in 1cf1f46
Done.
pal/src/host/linux-sgx/host_profile.c line 127 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
sgx_profile_init:
Done.
pal/src/host/linux-sgx/host_profile.c line 128 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
What is this? Should be
goto out;
Done.
pal/src/host/linux-sgx/host_profile.c line 133 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
profile_filenameis 64 chars in size. Now that we also add the number of seconds, are we sure we still fit in 64 chars limit? Please check how many chars in the filenames you see in your experiments.I think we can increase to 128 chars in size, and this will be more than enough.
Done.
pal/src/host/linux-sgx/host_profile.c line 197 at r1 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Why this change?
User might not want to enable debug logs due to performance reasons in that case user won't know the file where profile data is written. Also this log is seen only when profiling is enabled, in that case we should always inform user about the file name where profile data is written.
There was a problem hiding this comment.
Reviewed 4 of 4 files at r2, all commit messages.
Reviewable status: all files reviewed, 1 unresolved discussion, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103)
a discussion (no related file):
Previously, jkr0103 (Jitender Kumar) wrote…
Done.
Done where? UPDATE: You updated the PR description, I see now.
pal/src/host/linux-sgx/host_exception.c line 201 at r2 (raw file):
sgx_profile_init(); /* Report all ELFs already loaded (host part of PAL and dynamic libraries used by it) */
Ah, sorry, the text in parenthesis is incorrect in this case -- it's not only the PAL binary and its dynamic-lib dependencies. It's also the application executable itself, the LibOS binary, etc.
So please shorten to just: /* Report all ELFs already loaded */
pal/src/host/linux-sgx/host_profile.c line 133 at r1 (raw file):
Previously, jkr0103 (Jitender Kumar) wrote…
Done.
Btw, I looked at the sizes of the longest possible strings (sgx-perf- prefix + PID + timestamp + .data suffix). Typically you'll get ~32 chars. So 64 chars would also be enough.
Nevertheless, I don't see any harm in increasing from 64 chars to 128 chars.
pal/src/host/linux-sgx/host_profile.c line 197 at r1 (raw file):
Previously, jkr0103 (Jitender Kumar) wrote…
User might not want to enable debug logs due to performance reasons in that case user won't know the file where profile data is written. Also this log is seen only when profiling is enabled, in that case we should always inform user about the file name where profile data is written.
You're right, that's a good point.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 4 of 5 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv)
pal/src/host/linux-sgx/host_exception.c line 201 at r2 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Ah, sorry, the text in parenthesis is incorrect in this case -- it's not only the PAL binary and its dynamic-lib dependencies. It's also the application executable itself, the LibOS binary, etc.
So please shorten to just:
/* Report all ELFs already loaded */
Done.
There was a problem hiding this comment.
Reviewed 1 of 1 files at r3, all commit messages.
Reviewable status: all files reviewed, all discussions resolved, not enough approvals from maintainers (2 more required), not enough approvals from different teams (1 more required, approved so far: Intel), "fixup! " found in commit messages' one-liners
|
Jenkins, test this please |
There was a problem hiding this comment.
Reviewable status: all files reviewed, all discussions resolved, not enough approvals from maintainers (2 more required), not enough approvals from different teams (1 more required, approved so far: Intel), "fixup! " found in commit messages' one-liners
a discussion (no related file):
I tested the PR, looks like it's working. I followed the instructions in the PR description and tested Redis on my local machine.
I did 4 steps:
- Start Redis and perform
kill -SIGUSR1after 15 seconds; this is the enclave startup time. - Wait for 15 seconds and perform
kill -SIGUSR1again; this is the do-nothing idle time. - Start
./src/src/redis-benchmark -t set,get, wait till it finishes (around 15 seconds) and performkill -SIGUSR1again; this is the actual benchmark-working time. - Wait for 15 seconds and finally terminate Redis via
kill -SIGTERM; this is the do-nothing idle time.
So, a total of 1 minute.
sgx-perf-1707208751.data (178147 bytes) -- startup (15s)
Samples: 21
- 76.19% pal-sgx libpal.so [.] copy_u64s
copy_u64s
copy_u64s_from_untrusted
sgx_copy_to_enclave_verified
- sgx_copy_to_enclave
+ 66.67% load_trusted_or_allowed_file
+ 9.52% copy_and_verify_trusted_file
- 19.05% pal-sgx libpal.so [.] memset
_real_memset (inlined)
_PalVirtualMemoryAlloc
PalVirtualMemoryAlloc
libos_syscall_mmap
+ 4.76% pal-sgx libsysdb.so [.] snprintf_callback
sgx-perf-1707208766.data (18547 bytes) -- idle before bench run (15s)
Samples: 2
- 50.00% pal-sgx libpal.so [.] copy_u64s
copy_u64s
copy_u64s_from_untrusted
sgx_copy_to_enclave_verified
alloc_untrusted_futex_word
_PalEventCreate
PalEventCreate
create_lock
get_new_handle
libos_syscall_openat
- 50.00% pal-sgx libpal.so [.] slab_alloc
slab_alloc
malloc
calloc
_PalEventCreate
PalEventCreate
create_lock
get_new_handle
libos_syscall_openat
sgx-perf-1707208782.data (2059747 bytes) -- benchmark run (15s)
Samples: 245
+ 38.37% pal-sgx libpal.so [.] enclave_entry
+ 4.08% pal-sgx libpal.so [.] copy_u64s
+ 2.45% pal-sgx libpal.so [.] sgx_ocall
+ 2.04% pal-sgx libpal.so [.] __save_xregs
+ 2.04% pal-sgx redis-server [.] je_malloc_usable_size
+ 1.63% pal-sgx libpal.so [.] __restore_xregs
+ 1.63% pal-sgx libpal.so [.] sgx_copy_from_enclave_verified
+ 1.63% pal-sgx libsysdb.so [.] _return_from_syscall
+ 1.63% pal-sgx redis-server [.] siphash_nocase
+ 1.22% pal-sgx libpal.so [.] sgx_exitless_ocall
+ 1.22% pal-sgx libpal.so [.] sgx_reset_ustack
+ 1.22% pal-sgx libsysdb.so [.] cmp_addr_to_vma
+ 1.22% pal-sgx libsysdb.so [.] libos_syscall_gettimeofday
+ 1.22% pal-sgx libsysdb.so [.] truncate_file_name
+ 0.82% pal-sgx libc.so.6 [.] __GI___libc_write
+ 0.82% pal-sgx libc.so.6 [.] __strcasecmp_l_avx2
+ 0.82% pal-sgx libc.so.6 [.] read
+ 0.82% pal-sgx libpal.so [.] PalSocketSend
+ 0.82% pal-sgx libpal.so [.] copy_u64s_to_untrusted
+ 0.82% pal-sgx libpal.so [.] memcpy
+ 0.82% pal-sgx libpal.so [.] ocall_send
+ 0.82% pal-sgx libpal.so [.] sgx_is_valid_untrusted_ptr
+ 0.82% pal-sgx libsysdb.so [.] avl_tree_lower_bound_fn
sgx-perf-1707208796.data (18547 bytes) -- idle after bench run (15s)
Samples: 2
- 100.00% pal-sgx libpal.so [.] copy_u64s
copy_u64s
copy_u64s_from_untrusted
sgx_copy_to_enclave_verified
alloc_untrusted_futex_word
_PalEventCreate
PalEventCreate
create_lock
get_new_handle
libos_syscall_openat
There was a problem hiding this comment.
Reviewable status: all files reviewed, 1 unresolved discussion, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103)
pal/src/host/linux-sgx/host_exception.c line 198 at r3 (raw file):
#ifdef DEBUG if (g_pal_enclave.profile_enable) { sgx_profile_finish();
This PR breaks on multi-threaded apps. I tested on Memcached and got SIGSEGV.
That's because some other thread may be in the middle of saving something into the profile, and the profile data/metadata is "swept" from its feet.
We already have a global spinlock that protects all operations on profiling, so we just need to surround all this logic with a single lock/unlock. Let me prepare a fixup.
Signed-off-by: Dmitrii Kuvaiskii <dmitrii.kuvaiskii@intel.com>
There was a problem hiding this comment.
Reviewable status: 1 of 6 files reviewed, 1 unresolved discussion, not enough approvals from maintainers (3 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners
pal/src/host/linux-sgx/host_exception.c line 198 at r3 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
This PR breaks on multi-threaded apps. I tested on Memcached and got SIGSEGV.
That's because some other thread may be in the middle of saving something into the profile, and the profile data/metadata is "swept" from its feet.
We already have a global spinlock that protects all operations on profiling, so we just need to surround all this logic with a single lock/unlock. Let me prepare a fixup.
Done. The code is pretty ugly and will need some re-arrangements, and because we don't protect g_mem_fd with a lock, we sometimes see (rather benign) error messages. Someone (me?) will need to make the code look better. But functionality-wise seems to be ok.
There was a problem hiding this comment.
Reviewed 1 of 4 files at r2, all commit messages.
Reviewable status: 1 of 6 files reviewed, 5 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @jkr0103)
a discussion (no related file):
Why is this implemented in PAL-SGX? Profiling is a generic feature in Gramine, not SGX-specific.
-- commits line 2 at r4:
missing component tag
Documentation/performance.rst line 639 at r4 (raw file):
multiple files, each containing profile data collected after the previous ``SIGUSR1`` which is helpful when the application runs in clearly separated stages.
This has to be rewritten, it's hard to read.
pal/src/host/linux-sgx/host_exception.c line 198 at r4 (raw file):
#ifdef DEBUG if (g_pal_enclave.profile_enable) { sgx_profile_reinit();
You can't call this from a signal handler for like 10 different reasons, e.g. because it tries to take a lock which could have been already taken by the current thread when SIGUSR1 arrived, causing a deadlock.
There was a problem hiding this comment.
Reviewable status: 1 of 6 files reviewed, 5 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv, @jkr0103, and @mkow)
pal/src/host/linux-sgx/host_exception.c line 198 at r4 (raw file):
Previously, mkow (Michał Kowalczyk) wrote…
You can't call this from a signal handler for like 10 different reasons, e.g. because it tries to take a lock which could have been already taken by the current thread when SIGUSR1 arrived, causing a deadlock.
Indeed. I think the best way would be to just set an atomic flag in the signal, and do the flush the next time profile data is collected (eg. in sgx_profile_sample_aex), which should happen often enough.
There was a problem hiding this comment.
Reviewable status: 1 of 6 files reviewed, 5 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
a discussion (no related file):
Previously, mkow (Michał Kowalczyk) wrote…
Why is this implemented in PAL-SGX? Profiling is a generic feature in Gramine, not SGX-specific.
There is nothing required for non-SGX PAL (gramine-direct). This kind of profiling just works, it doesn't require any additional features.
So we're augmenting already-existing SGX PAL support for profiling. See https://gramine.readthedocs.io/en/stable/performance.html#profiling-with-perf
pal/src/host/linux-sgx/host_exception.c line 198 at r4 (raw file):
Previously, mwkmwkmwk (Marcelina Kościelnicka) wrote…
Indeed. I think the best way would be to just set an atomic flag in the signal, and do the flush the next time profile data is collected (eg. in
sgx_profile_sample_aex), which should happen often enough.
Yeah, I agree...
The code got super-ugly now, @jkr0103 or me will need to sort this all out.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 1 of 6 files reviewed, 5 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
pal/src/host/linux-sgx/host_exception.c line 198 at r4 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Yeah, I agree...
The code got super-ugly now, @jkr0103 or me will need to sort this all out.
Done.
There was a problem hiding this comment.
Reviewed 5 of 5 files at r5, all commit messages.
Reviewable status: all files reviewed, 16 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
Previously, mkow (Michał Kowalczyk) wrote…
missing component tag
Previously we had a prefix like this: [Pal/Linux-SGX] SGX perf:
So I suggest to change the commit message to
[Pal/Linux-SGX] SGX perf: flush profile data on SIGUSR1 signal
This allows to collect profile data only for a particular period
(e.g., during Gramine startup or during an actual benchmark run).
Documentation/performance.rst line 639 at r4 (raw file):
Previously, mkow (Michał Kowalczyk) wrote…
This has to be rewritten, it's hard to read.
Proposed text:
It is also possible to flush the collected profile data interactively, using the
``SIGUSR1`` signal. This helps to collect profile data only for a particular
period, e.g., skipping the Gramine startup and application initialization time
and concentrating only on the actual application processing. Send ``SIGUSR1``
using command ``kill -SIGUSR1 <gramine-pid>``. Sending multiple ``SIGUSR1`` will
create multiple files, each containing profile data collected after the previous
``SIGUSR1``.
pal/src/host/linux-sgx/host_exception.c line 198 at r3 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Done. The code is pretty ugly and will need some re-arrangements, and because we don't protect
g_mem_fdwith a lock, we sometimes see (rather benign) error messages. Someone (me?) will need to make the code look better. But functionality-wise seems to be ok.
This was fixed by @jkr0103
pal/src/host/linux-sgx/host_internal.h line 134 at r5 (raw file):
#ifdef DEBUG #include "elf/elf.h"
What is this? Why is this needed in this header?
pal/src/host/linux-sgx/host_internal.h line 155 at r5 (raw file):
/* Finalize and close file */ void sgx_profile_finish(void); void sgx_profile_finish_thread_unsafe(void);
This function must be declared as static in the *.c file, and removed from here.
pal/src/host/linux-sgx/host_internal.h line 158 at r5 (raw file):
/* Re-initialize based on g_pal_enclave settings */ int sgx_profile_reinit(void);
This function must be declared as static in the *.c file, and removed from here.
pal/src/host/linux-sgx/host_internal.h line 176 at r5 (raw file):
/* Record a new mapped ELF */ void sgx_profile_report_elf(const char* filename, void* addr); void sgx_profile_report_elf_thread_unsafe(const char* filename, void* addr);
Why do you need to declare these 4 functions? You should just declare those functions as static in the *.c file, and remove from here.
pal/src/host/linux-sgx/host_profile.c line 177 at r5 (raw file):
} void sgx_profile_finish_thread_unsafe(void) {
static void
pal/src/host/linux-sgx/host_profile.c line 197 at r5 (raw file):
g_profile_enabled = false; }
Please add a newline after this
pal/src/host/linux-sgx/host_profile.c line 203 at r5 (raw file):
spinlock_unlock(&g_perf_data_lock); }
Please remove a newline
pal/src/host/linux-sgx/host_profile.c line 454 at r5 (raw file):
log_error("sgx_profile_report_elf(%s): close failed: %s", filename, unix_strerror(ret)); } }
Please add a newline after this
pal/src/host/linux-sgx/host_profile.c line 481 at r5 (raw file):
sgx_profile_report_elf_cleanup(filename, &elf_addr, elf_length, fd); } }
Sorry, this refactoring of sgx_profile_report_elf() turns out to be a complete mess...
I suggest to do the same you did with sgx_profile_finish() -- just remove the locks from the original function and rename it to _thread_unsafe(), and in the wrapper function add the locks. Yes, this will be less performant than the original code (because the critical section in-between lock and unlock becomes larger), but this function is called very rarely, only on new binaries/libraries loaded into the application.
pal/src/host/linux-sgx/host_profile.c line 484 at r5 (raw file):
int sgx_profile_reinit(void) { int ret;
Please add in the very beginning: assert(spinlock_is_locked(&g_perf_data_lock));
pal/src/host/linux-sgx/host_profile.c line 489 at r5 (raw file):
ret = sgx_profile_init(); if (ret < 0) { log_error("sgx_profile_reinit: initializing again failed: %s", unix_strerror(ret));
Actually no need for "initializing again", as the name of the func already explains the issue. So: sgx_profile_reinit failed: %s
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 3 of 6 files reviewed, 16 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Previously we had a prefix like this:
[Pal/Linux-SGX] SGX perf:So I suggest to change the commit message to
[Pal/Linux-SGX] SGX perf: flush profile data on SIGUSR1 signal This allows to collect profile data only for a particular period (e.g., during Gramine startup or during an actual benchmark run).
Could you please add it while rebasing the PR?
Documentation/performance.rst line 639 at r4 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Proposed text:
It is also possible to flush the collected profile data interactively, using the ``SIGUSR1`` signal. This helps to collect profile data only for a particular period, e.g., skipping the Gramine startup and application initialization time and concentrating only on the actual application processing. Send ``SIGUSR1`` using command ``kill -SIGUSR1 <gramine-pid>``. Sending multiple ``SIGUSR1`` will create multiple files, each containing profile data collected after the previous ``SIGUSR1``.
Done.
pal/src/host/linux-sgx/host_exception.c line 198 at r3 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
This was fixed by @jkr0103
Done.
pal/src/host/linux-sgx/host_internal.h line 134 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
What is this? Why is this needed in this header?
It was required for elf_ehdr_t but not required anymore as those function declarations are moved out of this file.
pal/src/host/linux-sgx/host_internal.h line 155 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
This function must be declared as
staticin the*.cfile, and removed from here.
Done.
pal/src/host/linux-sgx/host_internal.h line 158 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
This function must be declared as
staticin the*.cfile, and removed from here.
Done.
pal/src/host/linux-sgx/host_internal.h line 176 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Why do you need to declare these 4 functions? You should just declare those functions as
staticin the*.cfile, and remove from here.
These functions are not required now, hence deleted.
pal/src/host/linux-sgx/host_profile.c line 177 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
static void
Done.
pal/src/host/linux-sgx/host_profile.c line 197 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please add a newline after this
Done.
pal/src/host/linux-sgx/host_profile.c line 203 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please remove a newline
Done.
pal/src/host/linux-sgx/host_profile.c line 454 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please add a newline after this
Done.
pal/src/host/linux-sgx/host_profile.c line 481 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Sorry, this refactoring of
sgx_profile_report_elf()turns out to be a complete mess...I suggest to do the same you did with
sgx_profile_finish()-- just remove the locks from the original function and rename it to_thread_unsafe(), and in the wrapper function add the locks. Yes, this will be less performant than the original code (because the critical section in-between lock and unlock becomes larger), but this function is called very rarely, only on new binaries/libraries loaded into the application.
Done.
pal/src/host/linux-sgx/host_profile.c line 484 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please add in the very beginning:
assert(spinlock_is_locked(&g_perf_data_lock));
Done.
pal/src/host/linux-sgx/host_profile.c line 489 at r5 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Actually no need for "initializing again", as the name of the func already explains the issue. So:
sgx_profile_reinit failed: %s
Done.
There was a problem hiding this comment.
Reviewed 3 of 3 files at r6, all commit messages.
Reviewable status: all files reviewed, 8 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv, @jkr0103, and @mkow)
Previously, jkr0103 (Jitender Kumar) wrote…
Could you please add it while rebasing the PR?
Yes I will
pal/src/host/linux-sgx/host_internal.h line 165 at r6 (raw file):
/* Record a sample during OCALL (function to be executed) */ void sgx_profile_sample_ocall_outer(void* ocall_func);
Please re-add the accidentally removed line
pal/src/host/linux-sgx/host_profile.c line 206 at r6 (raw file):
static void sgx_profile_report_elf_thread_unsafe(const char* filename, void* addr) { int ret;
Can you add assert(spinlock_is_locked(&g_perf_data_lock)); as the very first line?
pal/src/host/linux-sgx/host_profile.c line 324 at r6 (raw file):
if (ret < 0) { log_error("sgx_profile_reinit failed: %s", unix_strerror(ret)); goto out;
There seems to be no reason to have out: label. Just return ret here, and return 0 at the end of the func.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 4 of 6 files reviewed, 8 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
pal/src/host/linux-sgx/host_internal.h line 165 at r6 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please re-add the accidentally removed line
Done.
pal/src/host/linux-sgx/host_profile.c line 206 at r6 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Can you add
assert(spinlock_is_locked(&g_perf_data_lock));as the very first line?
This function is file-scope only and callers grabed or assert on lock, hence adding this assert seems redundant.
pal/src/host/linux-sgx/host_profile.c line 324 at r6 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
There seems to be no reason to have
out:label. Justreturn rethere, andreturn 0at the end of the func.
Done.
There was a problem hiding this comment.
Reviewed 2 of 2 files at r7, all commit messages.
Reviewable status: all files reviewed, 6 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
pal/src/host/linux-sgx/host_profile.c line 206 at r6 (raw file):
Previously, jkr0103 (Jitender Kumar) wrote…
This function is file-scope only and callers grabed or assert on lock, hence adding this assert seems redundant.
LGTM, I'm ok with this explanation. (Indeed, very easy to verify that the lock is taken.)
pal/src/host/linux-sgx/host_profile.c line 57 at r7 (raw file):
while (total < size) { ret = DO_SYSCALL(pread64, g_mem_fd, (uint8_t*)dest + total, size - total,
Technically accessing g_mem_fd must be under the g_perf_data_lock spinlock, because this variable can become -1 during re-opening of the file.
On the other hand, adding locking here would lead to tremendous overheads of profiling, which will seriously distort the perf results. So I'm very reluctant to do proper thread safety here...
In the worst case, pread64() will return smth like EBADF, and the sample will be lost. That's what I observe in practice when testing this PR. Sounds like a small correctness price to pay, so I would leave as is.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewed 4 of 4 files at r8, all commit messages.
Reviewable status: all files reviewed, 7 unresolved discussions, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: Intel), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
a discussion (no related file):
Bar the (non-blocking) discussion point, I am fine with this PR.
I would like to test it again after all reviews are done and before merge.
There was a problem hiding this comment.
Reviewable status: all files reviewed, 7 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
pal/src/host/linux-sgx/host_profile.c line 57 at r7 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Technically accessing
g_mem_fdmust be under theg_perf_data_lockspinlock, because this variable can become-1during re-opening of the file.On the other hand, adding locking here would lead to tremendous overheads of profiling, which will seriously distort the perf results. So I'm very reluctant to do proper thread safety here...
In the worst case,
pread64()will return smth likeEBADF, and the sample will be lost. That's what I observe in practice when testing this PR. Sounds like a small correctness price to pay, so I would leave as is.
I thought about this a bit more, and I have the following compromise solution:
- We introduce a global
g_null_mem_fdwhich is opened at init time and points to the pseudo-file "/dev/null" (i.e., all writes to this FD are no-ops). - Instead of closing previous
g_mem_fd, wedup2()theg_null_mem_fdinto the previous mem FD. In other words, all writes to the previous mem FD do not return with error, but instead are silently dropped. Note thatdup2()is an atomic operation, which is what we want. - So all threads that are still using the previous mem FD will not fail but instead just do nothing. At some point these threads will notice the new mem FD and will start writing their samples into this new mem FD.
This also solves the problem that I didn't realize when I wrote my previous comment (and that problem is very serious):
- One thread closes
g_mem_fd, now the FD number (say10) that was used for mem FD is available to any other usage. - Another thread still wants to use this old mem FD (i.e.
pread(10)), and is preempted. - Yet another thread wants to open some unrelated file. It notices that FD
10is available and assigns10to this new file. - Second thread is scheduled again. It now performs
pread()from a completely irrelevant file. Gramine state becomes silently corrupted. Oops.
There is a problem that we will leak g_mem_fd and g_perf_data::pd on every SIGUSR1 signal, but it's a small price to pay. (I think the only alternative would be to use spinlocks everywhere, which is very expensive.)
All the above also applies to g_perf_data::pd FD.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 5 of 7 files reviewed, 7 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
pal/src/host/linux-sgx/host_profile.c line 57 at r7 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
I thought about this a bit more, and I have the following compromise solution:
- We introduce a global
g_null_mem_fdwhich is opened at init time and points to the pseudo-file "/dev/null" (i.e., all writes to this FD are no-ops).- Instead of closing previous
g_mem_fd, wedup2()theg_null_mem_fdinto the previous mem FD. In other words, all writes to the previous mem FD do not return with error, but instead are silently dropped. Note thatdup2()is an atomic operation, which is what we want.- So all threads that are still using the previous mem FD will not fail but instead just do nothing. At some point these threads will notice the new mem FD and will start writing their samples into this new mem FD.
This also solves the problem that I didn't realize when I wrote my previous comment (and that problem is very serious):
- One thread closes
g_mem_fd, now the FD number (say10) that was used for mem FD is available to any other usage.- Another thread still wants to use this old mem FD (i.e.
pread(10)), and is preempted.- Yet another thread wants to open some unrelated file. It notices that FD
10is available and assigns10to this new file.- Second thread is scheduled again. It now performs
pread()from a completely irrelevant file. Gramine state becomes silently corrupted. Oops.There is a problem that we will leak
g_mem_fdandg_perf_data::pdon every SIGUSR1 signal, but it's a small price to pay. (I think the only alternative would be to use spinlocks everywhere, which is very expensive.)
All the above also applies to
g_perf_data::pdFD.
g_mem_fd need not be closed/open again and again on SIGUSR1, we can keep it open for the lifetime of the process. @dimakuv do you see any issue with this approach?
I have implemented the solution (using dup2) suggestion above for g_perf_data::pd.
There was a problem hiding this comment.
Reviewed 2 of 2 files at r9, all commit messages.
Reviewable status: all files reviewed, 13 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
pal/src/host/linux-sgx/host_perf_data.c line 155 at r9 (raw file):
} // File `/dev/null` is open once and remain open during the lifecycle of the process
I would rephrase to this:
/* `/dev/null` is opened once and is kept open for the whole runtime of Gramine */
pal/src/host/linux-sgx/host_perf_data.c line 158 at r9 (raw file):
if (g_dev_null_fd < 0) { ret = DO_SYSCALL(open, "/dev/null", O_WRONLY | O_TRUNC | O_CREAT | O_CLOEXEC, PERM_rw_r__r__);
Please align O_WRONLY ... line to be exactly under open, ...
pal/src/host/linux-sgx/host_perf_data.c line 158 at r9 (raw file):
if (g_dev_null_fd < 0) { ret = DO_SYSCALL(open, "/dev/null", O_WRONLY | O_TRUNC | O_CREAT | O_CLOEXEC, PERM_rw_r__r__);
Please remove O_TRUNC and O_CREAT -- they don't make sense in this context
pal/src/host/linux-sgx/host_perf_data.c line 160 at r9 (raw file):
O_WRONLY | O_TRUNC | O_CREAT | O_CLOEXEC, PERM_rw_r__r__); if (ret < 0) { log_error("pd_open: cannot open `/dev/null` for writing: %s", unix_strerror(fd));
Not fd but ret
pal/src/host/linux-sgx/host_perf_data.c line 298 at r9 (raw file):
out: if ((dup2_ret = dup2(g_dev_null_fd, pd->fd)) < 0)
We don't use Glibc wrappers here (dup2()) but instead raw syscalls (DO_SYSCALL(dup2, g_dev_null_fd, pd->fd)). Please fix.
pal/src/host/linux-sgx/host_profile.c line 57 at r7 (raw file):
g_mem_fdneed not be closed/open again and again onSIGUSR1, we can keep it open for the lifetime of the process. @dimakuv do you see any issue with this approach?
Yes, you are right. This is good how you implemented it.
I have implemented the solution (using
dup2) suggestion above forg_perf_data::pd.
Yes, looks like what I wanted.
pal/src/host/linux-sgx/host_profile.c line 116 at r9 (raw file):
g_profile_mode = g_pal_enclave.profile_mode; // File `/proc/self/mem` is open once and remain open during the lifecycle of the process
I would rephrase to this:
/* `/proc/self/mem` is opened once and is kept open for the whole runtime of Gramine */
pal/src/host/linux-sgx/host_profile.c line 121 at r9 (raw file):
if (ret < 0) { log_error("sgx_profile_init: opening /proc/self/mem failed: %s", unix_strerror(ret)); return ret;
Why did you replace all goto out with return ret? This looked reasonable before. Now we have sometimes return ret and sometimes goto out, which is more confusing.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 5 of 7 files reviewed, 13 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
pal/src/host/linux-sgx/host_perf_data.c line 155 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
I would rephrase to this:
/* `/dev/null` is opened once and is kept open for the whole runtime of Gramine */
Done.
pal/src/host/linux-sgx/host_perf_data.c line 158 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please align
O_WRONLY ...line to be exactly underopen, ...
Done.
pal/src/host/linux-sgx/host_perf_data.c line 158 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Please remove
O_TRUNCandO_CREAT-- they don't make sense in this context
Done.
pal/src/host/linux-sgx/host_perf_data.c line 160 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Not
fdbutret
Done.
pal/src/host/linux-sgx/host_perf_data.c line 298 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
We don't use Glibc wrappers here (
dup2()) but instead raw syscalls (DO_SYSCALL(dup2, g_dev_null_fd, pd->fd)). Please fix.
Done.
pal/src/host/linux-sgx/host_profile.c line 116 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
I would rephrase to this:
/* `/proc/self/mem` is opened once and is kept open for the whole runtime of Gramine */
Done.
pal/src/host/linux-sgx/host_profile.c line 121 at r9 (raw file):
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Why did you replace all
goto outwithreturn ret? This looked reasonable before. Now we have sometimesreturn retand sometimesgoto out, which is more confusing.
reverted now.
There was a problem hiding this comment.
Reviewed 2 of 2 files at r10, all commit messages.
Reviewable status: all files reviewed, 6 unresolved discussions, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: Intel), "fixup! " found in commit messages' one-liners (waiting on @jkr0103 and @mkow)
There was a problem hiding this comment.
Reviewed 1 of 5 files at r5, 1 of 4 files at r8, all commit messages.
Reviewable status: all files reviewed, 7 unresolved discussions, not enough approvals from maintainers (1 more required), not enough approvals from different teams (1 more required, approved so far: Intel), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @jkr0103)
Previously, dimakuv (Dmitrii Kuvaiskii) wrote…
Yes I will
[Pal/Linux-SGX] SGX perf -> [Pal/Linux-SGX] perf
Documentation/performance.rst line 638 at r10 (raw file):
initialization time and concentrating only on the actual application processing. Send ``SIGUSR1`` using command ``kill -SIGUSR1 -<gramine-pid>`` (note the minus sign before <gramine-pid>). Sending multiple ``SIGUSR1`` will
Do we want this? Why?
Also, then it's not gramine-pid, but PGID.
Code quote:
(note the minus sign before <gramine-pid>).pal/src/host/linux-sgx/host_profile.c line 164 at r10 (raw file):
} static void sgx_profile_finish_thread_unsafe(void) {
What does "unsafe" mean in this context?
pal/src/host/linux-sgx/host_profile.c line 186 at r10 (raw file):
} static void sgx_profile_report_elf_thread_unsafe(const char* filename, void* addr) {
Could you move this function down where it was before? It obscures the diff and it's hard to review. If you want to move functions around, I'd prefer if you did that in a follow-up PR where you only change the order of them.
Signed-off-by: jkr0103 <jitender.kumar@intel.com>
There was a problem hiding this comment.
Reviewable status: 5 of 7 files reviewed, 7 unresolved discussions, not enough approvals from maintainers (2 more required), not enough approvals from different teams (2 more required, approved so far: ), "fixup! " found in commit messages' one-liners (waiting on @dimakuv and @mkow)
Previously, mkow (Michał Kowalczyk) wrote…
[Pal/Linux-SGX] SGX perf->[Pal/Linux-SGX] perf
will be done while rebasing.
Documentation/performance.rst line 638 at r10 (raw file):
Previously, mkow (Michał Kowalczyk) wrote…
Do we want this? Why?
Also, then it's notgramine-pid, but PGID.
Some workloads create multiple child process e.g. nginx have option worker_processes 4; which means it will create 4 child process. Minus sign is required to send the signal to all the processes in the group.
pal/src/host/linux-sgx/host_profile.c line 164 at r10 (raw file):
Previously, mkow (Michał Kowalczyk) wrote…
What does "unsafe" mean in this context?
unsafe means it's not safe for multiple thread, hence require locking,. User of this function should take care of locking before using this function if expecting multiple threads to enter at the same time.
pal/src/host/linux-sgx/host_profile.c line 186 at r10 (raw file):
Previously, mkow (Michał Kowalczyk) wrote…
Could you move this function down where it was before? It obscures the diff and it's hard to review. If you want to move functions around, I'd prefer if you did that in a follow-up PR where you only change the order of them.
That required forward declaration. Anyways moved it down and added forward declaration.
Description of the changes
Currently Gramine don't support flushing sgx profiling data if user wants to collect only for a particular duraion (e.g., only during perf benchmarking runs). This PR add feature to flush the profile data on demand using
SIGUSR1signal. That way user can collect data only for a particular duration. This also eliminates the noise added in profile data duing start and stop of the process.Partially fixes issue #1711
How to test this PR?
Please follow the instruction here to enable SGX profiling. Now execute the workload in Gramine SGX. Send
SIGUSR1signal using commandkill -SIGUSR1 <pid>to flush the profile data. This should create a sgx profile data file which can be opened usingperf reportcommand.Example:
gramine/CI-Examples/redis/redis-server.manifest.template.sgx.profile.enable = "main"sgx.profile.with_stack = truemake clean && make SGX=1gramine-sgx redis-server &kill -SIGUSR1 <pid>to flush. Gramine flush the profile data in a file as indicated by below log line:Profile data written to sgx-perf-1707196865.data (161042 bytes)src/src/redis-benchmarkSIGUSR1signal to flush profile data using commandkill -SIGUSR1 <pid>. Again profile data is written to a new file as indicated by below log line:Profile data written to sgx-perf-1707196952.data (15096242 bytes)sgx-perf-1707196952.datahave the profile data collected during benchmarks run.perf report --no-children -i sgx-perf-1707196952.dataSame steps can be tried with MongoDB, MySQL etc..
This change is