Skip to content

Instantly share code, notes, and snippets.

@oleavr

oleavr/frida-logging.md

Last active April 7, 2023 08:53
Show Gist options
  • Save oleavr/00d71868d88d597ee322a5392db17af6 to your computer and use it in GitHub Desktop.
Save oleavr/00d71868d88d597ee322a5392db17af6 to your computer and use it in GitHub Desktop.
Download ZIP

Revisions

  1. oleavr revised this gist Nov 3, 2020. 1 changed file with 114 additions and 0 deletions.
    114 changes: 114 additions & 0 deletions nativecallback-uaf.patch
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,114 @@
    diff --git a/bindings/gumjs/gumquickcore.c b/bindings/gumjs/gumquickcore.c
    index b0b54c3e..6ffa7179 100644
    --- a/bindings/gumjs/gumquickcore.c
    +++ b/bindings/gumjs/gumquickcore.c
    @@ -139,6 +139,10 @@ struct _GumQuickNativeCallback
    ffi_type ** atypes;
    GSList * data;

    + gboolean destroyed;
    + gchar * ctor_stack;
    + gchar * dtor_stack;
    +
    GumQuickCore * core;
    };

    @@ -1131,6 +1135,8 @@ _gum_quick_core_dispose (GumQuickCore * self)
    self->weak_map_delete_method = JS_NULL;

    gum_quick_core_teardown_atoms (self);
    +
    + self->disposed = TRUE;
    }

    void
    @@ -3437,6 +3443,33 @@ invalid_value:
    }
    }

    +static gchar *
    +gum_quick_capture_js_stack_here (GumQuickCore * core)
    +{
    + gchar * result;
    + JSContext * ctx = core->ctx;
    + JSValue exception_val, stack_val;
    + const char * stack, * newline;
    +
    + if (core->disposed)
    + return g_strdup ("<teardown>");
    +
    + JS_ThrowInternalError (ctx, "oops");
    + exception_val = JS_GetException (ctx);
    +
    + stack_val = JS_GetPropertyStr (ctx, exception_val, "stack");
    + stack = JS_ToCString (ctx, stack_val);
    +
    + newline = strchr (stack, '\n');
    + result = g_strdup ((newline != NULL) ? newline + 1 : stack);
    +
    + JS_FreeCString (ctx, stack);
    + JS_FreeValue (ctx, stack_val);
    + JS_FreeValue (ctx, exception_val);
    +
    + return result;
    +}
    +
    GUMJS_DEFINE_CONSTRUCTOR (gumjs_native_callback_construct)
    {
    JSValue wrapper = JS_NULL;
    @@ -3518,6 +3551,8 @@ GUMJS_DEFINE_CONSTRUCTOR (gumjs_native_callback_construct)
    JS_DupValue (ctx, func),
    0);

    + cb->ctor_stack = gum_quick_capture_js_stack_here (core);
    +
    return wrapper;

    alloc_failed:
    @@ -3560,6 +3595,10 @@ GUMJS_DEFINE_FINALIZER (gumjs_native_callback_finalize)
    static void
    gum_quick_native_callback_finalize (GumQuickNativeCallback * callback)
    {
    + callback->destroyed = TRUE;
    + callback->dtor_stack = gum_quick_capture_js_stack_here (callback->core);
    +
    +#if 0
    ffi_closure_free (callback->closure);

    while (callback->data != NULL)
    @@ -3571,6 +3610,7 @@ gum_quick_native_callback_finalize (GumQuickNativeCallback * callback)
    g_free (callback->atypes);

    g_slice_free (GumQuickNativeCallback, callback);
    +#endif
    }

    static void
    @@ -3592,6 +3632,15 @@ gum_quick_native_callback_invoke (ffi_cif * cif,
    JSValue * argv;
    JSValue result;

    + if (self->destroyed)
    + {
    + g_critical ("NativeCallback use-after-free detected!\n\nCreated here:\n%s"
    + "\n\nDestroyed here:\n%s",
    + self->ctor_stack,
    + self->dtor_stack);
    + return;
    + }
    +
    _gum_quick_scope_enter (&scope, core);

    JS_DupValue (ctx, self->wrapper);
    diff --git a/bindings/gumjs/gumquickcore.h b/bindings/gumjs/gumquickcore.h
    index 43cbd355..136b7c8c 100644
    --- a/bindings/gumjs/gumquickcore.h
    +++ b/bindings/gumjs/gumquickcore.h
    @@ -63,6 +63,7 @@ struct _GumQuickCore
    JSContext * ctx;
    GHashTable * module_data;
    GumQuickScope * current_scope;
    + gboolean disposed;

    GRecMutex * mutex;
    volatile guint usage_count;
  2. oleavr revised this gist Sep 4, 2020. 1 changed file with 8 additions and 1 deletion.
    9 changes: 8 additions & 1 deletion frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -6,4 +6,11 @@ impractical to use Frida to instrument Frida.
    Choose one of these and copy-paste it into e.g. `lib/interfaces/session.vala`,
    then use `log_event ("name='%s'", name);` to log.

    When something appears to be hanging, try applying: `x-async-debug.patch`.
    When something appears to be hanging, try applying: `x-async-debug.patch`.

    For `logging-hack-file.vala`, add the following line to `lib/interfaces/meson.build`
    right after the line specifying the `vala_header` option:

    ```
    vala_args: ['--pkg=posix'],
    ```
  3. oleavr revised this gist Oct 16, 2019. 2 changed files with 1 addition and 1 deletion.
    2 changes: 1 addition & 1 deletion frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -6,4 +6,4 @@ impractical to use Frida to instrument Frida.
    Choose one of these and copy-paste it into e.g. `lib/interfaces/session.vala`,
    then use `log_event ("name='%s'", name);` to log.

    When something appears to be hanging, try applying: `frida-core-async-debug.patch`.
    When something appears to be hanging, try applying: `x-async-debug.patch`.
    0 frida-core-async-debug.patch → x-async-debug.patch
    View file
    File renamed without changes.
  4. oleavr revised this gist Oct 16, 2019. 2 changed files with 19 additions and 1 deletion.
    16 changes: 16 additions & 0 deletions frida-core-async-debug.patch
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,16 @@
    diff --git a/src/frida.vala b/src/frida.vala
    index eb431593..11002e37 100644
    --- a/src/frida.vala
    +++ b/src/frida.vala
    @@ -2602,8 +2602,11 @@ namespace Frida {

    private async void do_perform_operation () {
    try {
    + printerr (">>> %s\n", this.get_type ().name ());
    result = yield perform_operation ();
    + printerr ("<<< %s\n", this.get_type ().name ());
    } catch (GLib.Error e) {
    + printerr ("<<< %s error=\"%s\"\n", this.get_type ().name (), e.message);
    error = e;
    }

    4 changes: 3 additions & 1 deletion frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -4,4 +4,6 @@ For adding temporary logging to help understand behavior. For when it is
    impractical to use Frida to instrument Frida.

    Choose one of these and copy-paste it into e.g. `lib/interfaces/session.vala`,
    then use `log_event ("name='%s'", name);` to log.
    then use `log_event ("name='%s'", name);` to log.

    When something appears to be hanging, try applying: `frida-core-async-debug.patch`.
  5. oleavr renamed this gist Aug 21, 2019. 1 changed file with 0 additions and 0 deletions.
    0 gum-logging.patch → x-gum-logging.patch
    View file
    File renamed without changes.
  6. oleavr revised this gist Aug 21, 2019. 1 changed file with 179 additions and 0 deletions.
    179 changes: 179 additions & 0 deletions gum-logging.patch
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,179 @@
    commit 1251a7f314022f126266127fd174a472ac7b9710
    Author: Ole André Vadla Ravnås <[email protected]>
    Date: Tue Aug 20 23:21:49 2019 +0200

    Add temporary logging to investigate Interceptor issue

    diff --git a/gum/backend-arm/guminterceptor-arm.c b/gum/backend-arm/guminterceptor-arm.c
    index 2be32087..cf878acf 100644
    --- a/gum/backend-arm/guminterceptor-arm.c
    +++ b/gum/backend-arm/guminterceptor-arm.c
    @@ -420,6 +420,8 @@ _gum_interceptor_backend_create_trampoline (GumInterceptorBackend * self,
    ctx->overwritten_prologue_len = reloc_bytes;
    memcpy (ctx->overwritten_prologue, function_address, reloc_bytes);

    + gum_log ("\t[ctx=%p] Generated on_enter=%p on_leave=%p", ctx, ctx->on_enter_trampoline, ctx->on_leave_trampoline);
    +
    return TRUE;
    }

    @@ -459,6 +461,7 @@ _gum_interceptor_backend_activate_trampoline (GumInterceptorBackend * self,
    gum_emit_push_cpu_context_high_part (tw);
    gum_thumb_writer_put_bl_imm (tw,
    GUM_ADDRESS (ctx->trampoline_deflector->trampoline));
    + gum_log ("\t[ctx=%p] Using shared Thumb deflector at %p", ctx, ctx->trampoline_deflector->trampoline);
    }
    else
    {
    @@ -466,12 +469,14 @@ _gum_interceptor_backend_activate_trampoline (GumInterceptorBackend * self,
    GUM_INTERCEPTOR_THUMB_TINY_REDIRECT_SIZE);
    gum_thumb_writer_put_b_imm (tw,
    GUM_ADDRESS (ctx->trampoline_deflector->trampoline));
    + gum_log ("\t[ctx=%p] Using dedicated Thumb deflector at %p", ctx, ctx->trampoline_deflector->trampoline);
    }
    }
    else
    {
    gum_thumb_writer_put_ldr_reg_address (tw, ARM_REG_PC,
    GUM_ADDRESS (ctx->on_enter_trampoline));
    + gum_log ("\t[ctx=%p] Using direct Thumb branch", ctx);
    }

    gum_thumb_writer_flush (tw);
    @@ -490,11 +495,13 @@ _gum_interceptor_backend_activate_trampoline (GumInterceptorBackend * self,
    GUM_INTERCEPTOR_ARM_TINY_REDIRECT_SIZE);
    gum_arm_writer_put_b_imm (aw,
    GUM_ADDRESS (ctx->trampoline_deflector->trampoline));
    + gum_log ("\t[ctx=%p] Using dedicated ARM deflector at %p", ctx, ctx->trampoline_deflector->trampoline);
    }
    else
    {
    gum_arm_writer_put_ldr_reg_address (aw, ARM_REG_PC,
    GUM_ADDRESS (ctx->on_enter_trampoline));
    + gum_log ("\t[ctx=%p] Using direct ARM branch", ctx);
    }

    gum_arm_writer_flush (aw);
    @@ -508,6 +515,7 @@ _gum_interceptor_backend_deactivate_trampoline (GumInterceptorBackend * self,
    gpointer prologue)
    {
    memcpy (prologue, ctx->overwritten_prologue, ctx->overwritten_prologue_len);
    + gum_log ("\t[ctx=%p] Deactivated", ctx);
    }

    gpointer
    diff --git a/gum/gum.c b/gum/gum.c
    index 06539a12..b3eda4f7 100644
    --- a/gum/gum.c
    +++ b/gum/gum.c
    @@ -602,6 +602,44 @@ gum_on_log_message (const gchar * log_domain,
    #endif
    }

    +void
    +gum_log (const gchar * format,
    + ...)
    +{
    + static GumInterceptor * interceptor = NULL;
    + gchar * path, * message;
    + va_list args;
    + FILE * file;
    +
    + if (interceptor == NULL)
    + {
    + interceptor = gum_interceptor_obtain ();
    + }
    +
    + gum_interceptor_ignore_current_thread (interceptor);
    +
    + path = g_strdup_printf ("/data/local/tmp/frida-debug/pid_%u-uid_%u.log", getpid (), getuid ());
    +
    + va_start (args, format);
    + message = g_strdup_vprintf (format, args);
    + va_end (args);
    +
    + file = fopen (path, "a");
    + if (file != NULL)
    + {
    + fputs (message, file);
    + fputc ('\n', file);
    +
    + fclose (file);
    + }
    +
    + g_free (message);
    +
    + g_free (path);
    +
    + gum_interceptor_unignore_current_thread (interceptor);
    +}
    +
    static GumAddress *
    gum_address_copy (const GumAddress * address)
    {
    diff --git a/gum/gumdefs.h b/gum/gumdefs.h
    index 57e19414..a2b7c25f 100644
    --- a/gum/gumdefs.h
    +++ b/gum/gumdefs.h
    @@ -447,6 +447,8 @@ GUM_API void gum_cpu_context_replace_return_value (GumCpuContext * self,
    GUM_API GType gum_address_get_type (void) G_GNUC_CONST;
    GUM_API GType gum_cpu_type_get_type (void) G_GNUC_CONST;

    +GUM_API void gum_log (const gchar * format, ...);
    +
    G_END_DECLS

    #endif
    diff --git a/gum/guminterceptor.c b/gum/guminterceptor.c
    index 00d08790..14f9e171 100644
    --- a/gum/guminterceptor.c
    +++ b/gum/guminterceptor.c
    @@ -15,6 +15,7 @@
    #include "gumprocess.h"
    #include "gumtls.h"

    +#include <dlfcn.h>
    #include <string.h>

    #ifdef HAVE_MIPS
    @@ -665,6 +666,22 @@ gum_interceptor_instrument (GumInterceptor * self,
    if (ctx == NULL)
    return NULL;

    + {
    + Dl_info info;
    + const gchar * name;
    +
    + if (dladdr (function_address, &info) != 0 && info.dli_sname != NULL)
    + {
    + name = info.dli_sname;
    + }
    + else
    + {
    + name = "(unknown)";
    + }
    +
    + gum_log ("Hooking %p (%s) => ctx=%p", function_address, name, ctx);
    + }
    +
    if (!_gum_interceptor_backend_create_trampoline (self->backend, ctx))
    {
    gum_function_context_finalize (ctx);
    @@ -1204,6 +1221,8 @@ _gum_function_context_begin_invocation (GumFunctionContext * function_ctx,
    system_error = gum_thread_get_system_error ();
    #endif

    + gum_log ("[ctx=%p] begin_invocation()", function_ctx);
    +
    if (interceptor->selected_thread_id != 0)
    {
    invoke_listeners =
    @@ -1322,6 +1341,8 @@ _gum_function_context_end_invocation (GumFunctionContext * function_ctx,
    GPtrArray * listener_entries;
    guint i;

    + gum_log ("[ctx=%p] end_invocation()", function_ctx);
    +
    #ifdef G_OS_WIN32
    system_error = gum_thread_get_system_error ();
    #endif
  7. oleavr revised this gist Aug 6, 2019. 1 changed file with 1 addition and 1 deletion.
    2 changes: 1 addition & 1 deletion frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -3,5 +3,5 @@
    For adding temporary logging to help understand behavior. For when it is
    impractical to use Frida to instrument Frida.

    Choose one of these and copy-paste it into e.g. lib/interfaces/session.vala,
    Choose one of these and copy-paste it into e.g. `lib/interfaces/session.vala`,
    then use `log_event ("name='%s'", name);` to log.
  8. oleavr revised this gist Aug 6, 2019. 1 changed file with 1 addition and 1 deletion.
    2 changes: 1 addition & 1 deletion frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -1,6 +1,6 @@
    # Frida logging helper

    For adding temporary logging to help understand behavior. For cases when it is
    For adding temporary logging to help understand behavior. For when it is
    impractical to use Frida to instrument Frida.

    Choose one of these and copy-paste it into e.g. lib/interfaces/session.vala,
  9. oleavr revised this gist Aug 6, 2019. 2 changed files with 7 additions and 4 deletions.
    7 changes: 7 additions & 0 deletions frida-logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,7 @@
    # Frida logging helper

    For adding temporary logging to help understand behavior. For cases when it is
    impractical to use Frida to instrument Frida.

    Choose one of these and copy-paste it into e.g. lib/interfaces/session.vala,
    then use `log_event ("name='%s'", name);` to log.
    4 changes: 0 additions & 4 deletions logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -1,4 +0,0 @@
    = Frida debugging snippets

    Choose one of these and copy-paste it into e.g. frida-core/lib/interfaces/session.vala,
    then use `log_event ("name='%s'", name);` to log.
  10. oleavr revised this gist Aug 6, 2019. 3 changed files with 4 additions and 0 deletions.
    0 file-logging-hack.vala → logging-hack-file.vala
    View file
    File renamed without changes.
    0 stderr-logging-hack.vala → logging-hack-stderr.vala
    View file
    File renamed without changes.
    4 changes: 4 additions & 0 deletions logging.md
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,4 @@
    = Frida debugging snippets

    Choose one of these and copy-paste it into e.g. frida-core/lib/interfaces/session.vala,
    then use `log_event ("name='%s'", name);` to log.
  11. oleavr renamed this gist Aug 6, 2019. 1 changed file with 0 additions and 0 deletions.
    0 android-file-logging-hack.vala → file-logging-hack.vala
    View file
    File renamed without changes.
  12. oleavr revised this gist Mar 28, 2019. 2 changed files with 52 additions and 0 deletions.
    52 changes: 52 additions & 0 deletions android-file-logging-hack.vala
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,52 @@
    namespace Frida {
    private static Mutex log_mutex;
    private static Timer log_timer = null;
    private static Gee.HashMap<uint, uint> log_threads = null;
    private const uint[] log_palette = { 36, 35, 33, 32, 31, 34 };
    private static uint log_palette_offset = 0;

    public void log_event (string format, ...) {
    var builder = new StringBuilder ();

    log_mutex.lock ();

    uint time_delta;
    if (log_timer == null) {
    log_timer = new Timer ();
    log_threads = new Gee.HashMap<uint, uint> ();

    time_delta = 0;
    } else {
    time_delta = (uint) (log_timer.elapsed () * 1000.0);
    log_timer.reset ();
    }
    if (time_delta > 0) {
    builder.append_printf ("\n*** +%u ms\n", time_delta);
    }

    var tid = (uint) Gum.Process.get_current_thread_id ();

    var color = log_threads[tid];
    if (color == 0) {
    color = log_palette[log_palette_offset];
    log_palette_offset = (log_palette_offset + 1) % log_palette.length;
    log_threads[tid] = color;
    }
    builder.append_printf ("\033[0;%um", color);

    builder.append_printf ("[thread %04x] ", tid);

    var args = va_list ();
    builder.append_vprintf (format, args);

    builder.append ("\033[0m\n");

    var logfile = FileStream.open ("/data/local/tmp/frida-debug/pid_%u-uid_%u.log".printf (Posix.getpid (), (uint) Posix.getuid ()), "a");
    if (logfile != null) {
    logfile.write (builder.str.data);
    logfile = null;
    }

    log_mutex.unlock ();
    }
    }
    0 logging-hack.vala → stderr-logging-hack.vala
    View file
    File renamed without changes.
  13. oleavr created this gist Jan 11, 2019.
    48 changes: 48 additions & 0 deletions logging-hack.vala
    View file
    Original file line number Diff line number Diff line change
    @@ -0,0 +1,48 @@
    namespace Frida {
    private static Mutex log_mutex;
    private static Timer log_timer = null;
    private static Gee.HashMap<uint, uint> log_threads = null;
    private const uint[] log_palette = { 36, 35, 33, 32, 31, 34 };
    private static uint log_palette_offset = 0;

    public void log_event (string format, ...) {
    var builder = new StringBuilder ();

    log_mutex.lock ();

    uint time_delta;
    if (log_timer == null) {
    log_timer = new Timer ();
    log_threads = new Gee.HashMap<uint, uint> ();

    time_delta = 0;
    } else {
    time_delta = (uint) (log_timer.elapsed () * 1000.0);
    log_timer.reset ();
    }
    if (time_delta > 0) {
    builder.append_printf ("\n*** +%u ms\n", time_delta);
    }

    var tid = (uint) Gum.Process.get_current_thread_id ();

    var color = log_threads[tid];
    if (color == 0) {
    color = log_palette[log_palette_offset];
    log_palette_offset = (log_palette_offset + 1) % log_palette.length;
    log_threads[tid] = color;
    }
    builder.append_printf ("\033[0;%um", color);

    builder.append_printf ("[thread %04x] ", tid);

    var args = va_list ();
    builder.append_vprintf (format, args);

    builder.append ("\033[0m\n");

    stderr.write (builder.str.data);

    log_mutex.unlock ();
    }
    }