gen/stack_logging.c

   1 /*
   2  * Copyright (c) 1999 Apple Computer, Inc. All rights reserved.
   3  *
   4  * @APPLE_LICENSE_HEADER_START@
   5  *
   6  * This file contains Original Code and/or Modifications of Original Code
   7  * as defined in and that are subject to the Apple Public Source License
   8  * Version 2.0 (the 'License'). You may not use this file except in
   9  * compliance with the License. Please obtain a copy of the License at
  10  * http://www.opensource.apple.com/apsl/ and read it before using this
  11  * file.
  12  *
  13  * The Original Code and all software distributed under the License are
  14  * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER
  15  * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,
  16  * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,
  17  * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT.
  18  * Please see the License for the specific language governing rights and
  19  * limitations under the License.
  20  *
  21  * @APPLE_LICENSE_HEADER_END@
  22  */
  23
  24 /*      Bertrand from vmutils -> CF -> System */
  25
  26 #import "stack_logging.h"
  27
  28 #import <libc.h>
  29 #import <pthread.h>
  30 #import <mach/mach.h>
  31 #include <mach/vm_statistics.h>
  32 #import <malloc/malloc.h>
  33 #import <stdlib.h>
  34
  35 extern void spin_lock(int *);
  36
  37 static inline void *allocate_pages(unsigned) __attribute__((always_inline));
  38 static inline void *allocate_pages(unsigned bytes) {
  39     void *address;
  40     if (vm_allocate(mach_task_self(), (vm_address_t *)&address, bytes,
  41                     VM_MAKE_TAG(VM_MEMORY_ANALYSIS_TOOL)| TRUE)) {
  42         malloc_printf("*** out of memory while stack logging\n");
  43         abort();
  44     }
  45     return (void *)address;
  46 }
  47
  48 static inline void deallocate_pages(void *, unsigned) __attribute__((always_inline));
  49 static inline void deallocate_pages(void *ptr, unsigned bytes) {
  50     vm_deallocate(mach_task_self(), (vm_address_t)ptr, bytes);
  51 }
  52
  53 static inline void copy_pages(const void *, void *, unsigned) __attribute__((always_inline));
  54 static inline void copy_pages(const void *source, void *dest, unsigned bytes) {
  55     if (vm_copy(mach_task_self(), (vm_address_t)source, bytes, (vm_address_t)dest)) memmove(dest, source, bytes);
  56 }
  57
  58 /***************        Recording stack         ***********/
  59
  60 // The three functions below are marked as noinline to ensure consistent inlining across
  61 // all versions of GCC and all compiler flags.  The malloc stack logging code expects
  62 // these functions to not be inlined.
  63 // For details, see <rdar://problem/4199620>.
  64 //
  65 // The performance cost of not inlining these functions is negligible, and they're only
  66 // called when MallocStackLogging is set anyway, so they won't affect normal usage.
  67
  68 static __attribute__((noinline)) void *first_frame_address(void) {
  69 #if defined(__i386__) || defined(__x86_64__)
  70     return __builtin_frame_address(0);
  71 #elif defined(__ppc__) || defined(__ppc64__)
  72     void *addr;
  73 #warning __builtin_frame_address IS BROKEN IN BEAKER: RADAR #2340421
  74     __asm__ volatile("mr %0, r1" : "=r" (addr));
  75     return addr;
  76 #else
  77 #warning first_frame_address WILL NOT BE FUNCTIONAL ON THIS ARCHITECTURE
  78     return NULL;
  79 #endif
  80 }
  81
  82 static __attribute__((noinline)) void *next_frame_address(void *addr) {
  83     void *ret;
  84 #if defined(__MACH__) && (defined(__i386__) || defined(__x86_64__))
  85     __asm__ volatile("mov (%1),%0" : "=r" (ret) : "r" (addr));
  86 #elif defined(__MACH__) && (defined(__ppc__) || defined(__ppc64__))
  87     __asm__ volatile("lwz %0,0x0(%1)" : "=r" (ret) : "b" (addr));
  88 #elif defined(__hpux__)
  89     __asm__ volatile("ldw 0x0(%1),%0" : "=r" (ret) : "r" (addr));
  90 #elif defined(__svr4__)
  91     __asm__ volatile("ta 0x3");
  92     __asm__ volatile("ld [%1 + 56],%0" : "=r" (ret) : "r" (addr));
  93 #else
  94 #error Unknown architecture
  95 #endif
  96     return ret;
  97 }
  98
  99 #if defined(__i386__) || defined(__x86_64__) || defined (__m68k__)
 100 #define FP_LINK_OFFSET 1
 101 #elif defined(__ppc__) || defined(__ppc64__)
 102 #define FP_LINK_OFFSET 2
 103 #elif defined(__hppa__)
 104 #define FP_LINK_OFFSET -5
 105 #elif defined(__sparc__)
 106 #define FP_LINK_OFFSET 14
 107 #else
 108 #error  ********** Unimplemented architecture
 109 #endif
 110
 111 __attribute__((noinline)) void thread_stack_pcs(vm_address_t *buffer, unsigned max, unsigned *nb) {
 112     void *addr;
 113     addr = first_frame_address();
 114     *nb = 0;
 115     while ((addr >= (void *)0x800) && (max--)) {
 116         vm_address_t    fp_link = (vm_address_t)(((unsigned *)addr)+FP_LINK_OFFSET);
 117         void    *addr2;
 118         buffer[*nb] = *((vm_address_t *)fp_link);
 119         (*nb)++;
 120         addr2 = next_frame_address(addr);
 121 #if defined(__ppc__) || defined(__ppc64__)
 122         if ((unsigned)addr2 <= (unsigned)addr) break; // catch bozo frames
 123 #endif
 124         addr = addr2;
 125     }
 126 }
 127
 128 /***************        Uniquing stack          ***********/
 129
 130 #define MAX_COLLIDE     8
 131
 132 #define MAX_NUM_PC      512
 133
 134 static int enter_pair_in_table(unsigned *table, unsigned numPages, unsigned *uniquedParent, unsigned thisPC) {
 135     // uniquedParent is in-out; return 1 is collisions max not exceeded
 136     unsigned    base = numPages * vm_page_size / (sizeof(int)*2*2);
 137     unsigned    hash = base + (((*uniquedParent) << 4) ^ (thisPC >> 2)) % (base - 1); // modulo odd number for hashing
 138     unsigned    collisions = MAX_COLLIDE;
 139     while (collisions--) {
 140         unsigned        *head = table + hash*2;
 141         if (! head[0] && !head[1]) {
 142             /* end of chain; store this entry! */
 143             /* Note that we need to test for both head[0] and head[1] as (0, -1) is a valid entry */
 144             head[0] = thisPC;
 145             head[1] = *uniquedParent;
 146             *uniquedParent = hash;
 147             return 1;
 148         }
 149         if ((head[0] == thisPC) && (head[1] == *uniquedParent)) {
 150             /* we found the proper entry, the value for the pair is the entry offset */
 151             *uniquedParent = hash;
 152             return 1;
 153         }
 154         hash++;
 155         if (hash == base*2) hash = base;
 156     }
 157     return 0;
 158 }
 159
 160 unsigned stack_logging_get_unique_stack(unsigned **table, unsigned *table_num_pages, unsigned *stack_entries, unsigned count, unsigned num_hot_to_skip) {
 161     unsigned    uniquedParent = (unsigned)-1;
 162     // we skip the warmest entries that are an artefact of the code
 163     while (num_hot_to_skip--) {
 164         if (count > 0) { stack_entries++; count--; }
 165     }
 166     while (count--) {
 167         unsigned        thisPC = stack_entries[count];
 168         while (!enter_pair_in_table(*table, *table_num_pages, &uniquedParent, thisPC)) {
 169             unsigned    *newTable;
 170             unsigned    oldBytes = (*table_num_pages) * vm_page_size;
 171             newTable = allocate_pages(oldBytes*2);
 172             copy_pages(*table, newTable, oldBytes);
 173             deallocate_pages(*table, oldBytes);
 174             *table_num_pages *= 2;
 175             *table = newTable;
 176         }
 177     }
 178     return uniquedParent;
 179 }
 180
 181 /***************        Logging stack and arguments             ***********/
 182
 183 stack_logging_record_list_t *stack_logging_the_record_list = NULL;
 184
 185 int stack_logging_enable_logging = 0;
 186
 187 int stack_logging_dontcompact = 0;
 188
 189 static stack_logging_record_list_t *GrowLogRecords(stack_logging_record_list_t *records, unsigned desiredNumRecords) {
 190     stack_logging_record_list_t *new_records;
 191     unsigned    old_size = records->overall_num_bytes;
 192     if (desiredNumRecords*sizeof(stack_logging_record_t)+sizeof(stack_logging_record_list_t) < records->overall_num_bytes) return records;
 193     records->overall_num_bytes += records->overall_num_bytes + vm_page_size; // in order to always get an even number of pages
 194     new_records = allocate_pages(records->overall_num_bytes);
 195     copy_pages(records, new_records, old_size);
 196     deallocate_pages(records, old_size);
 197     return new_records;
 198 }
 199
 200 static void prepare_to_log_stack(void) {
 201     if (!stack_logging_the_record_list) {
 202         unsigned        totalSize = 4 * vm_page_size;
 203         stack_logging_the_record_list = allocate_pages(totalSize);
 204         memset(stack_logging_the_record_list, 0, sizeof(stack_logging_record_list_t));
 205         stack_logging_the_record_list->overall_num_bytes = totalSize;
 206         stack_logging_the_record_list->uniquing_table_num_pages = 128;
 207         stack_logging_the_record_list->uniquing_table = allocate_pages(stack_logging_the_record_list->uniquing_table_num_pages * vm_page_size);
 208     }
 209 }
 210
 211 void stack_logging_log_stack(unsigned type, unsigned arg1, unsigned arg2, unsigned arg3, unsigned result, unsigned num_hot_to_skip) {
 212     stack_logging_record_t      *rec;
 213     if (!stack_logging_enable_logging) return;
 214     // printf("stack_logging_log_stack 0x%x 0x%x 0x%x 0x%x -> 0x%x\n", type, arg1, arg2, arg3, result);
 215     if (type & stack_logging_flag_zone) {
 216         // just process it now and be done with it!
 217         arg1 = arg2; arg2 = arg3; arg3 = 0; type &= ~stack_logging_flag_zone;
 218     }
 219     if (type & stack_logging_flag_calloc) {
 220         // just process it now and be done with it!
 221         arg1 *= arg2; arg2 = arg3; arg3 = 0; type &= ~stack_logging_flag_calloc;
 222     }
 223     if (type & stack_logging_flag_object) {
 224         unsigned        *class = (unsigned *)arg1;
 225         arg1 = arg2 + class[5]; // corresponds to the instance_size field
 226         arg2 = 0; arg3 = 0; type = stack_logging_type_alloc;
 227     }
 228     if (type & stack_logging_flag_cleared) {
 229         type &= ~stack_logging_flag_cleared;
 230     }
 231     if (type & stack_logging_flag_handle) {
 232         if (stack_logging_type_alloc) {
 233             if (!result) return;
 234             stack_logging_log_stack(stack_logging_type_alloc, 0, 0, 0, result, num_hot_to_skip+1);
 235             stack_logging_log_stack(stack_logging_type_alloc, arg1, 0, 0, *((int *)result), num_hot_to_skip+1);
 236             return;
 237         }
 238         if (stack_logging_type_dealloc) {
 239             if (!arg1) return;
 240             stack_logging_log_stack(stack_logging_type_dealloc, *((int *)arg1), 0, 0, 0, num_hot_to_skip+1);
 241             stack_logging_log_stack(stack_logging_type_dealloc, arg1, 0, 0, 0, num_hot_to_skip+1);
 242             return;
 243         }
 244         printf("*** Unknown logging type: 0x%x\n", type);
 245     }
 246     if (type == stack_logging_flag_set_handle_size) {
 247         if (!arg1) return;
 248         // Thanks to a horrible hack, arg3 contains the prvious handle value
 249         if (arg3 == *((int *)arg1)) return;
 250         stack_logging_log_stack(stack_logging_type_dealloc, arg3, 0, 0, 0, num_hot_to_skip+1);
 251         stack_logging_log_stack(stack_logging_type_alloc, arg2, 0, 0, *((int *)arg1), num_hot_to_skip+1);
 252         return;
 253     }
 254     if (type == (stack_logging_type_dealloc|stack_logging_type_alloc)) {
 255         if (arg1 == result) return; // realloc had no effect, skipping
 256         if (!arg1) {
 257             // realloc(NULL, size) same as malloc(size)
 258             type = stack_logging_type_alloc; arg1 = arg2; arg2 = arg3; arg3 = 0;
 259         } else {
 260             // realloc(arg1, arg2) -> result is same as free(arg1); malloc(arg2) -> result
 261             stack_logging_log_stack(stack_logging_type_dealloc, arg1, 0, 0, 0, num_hot_to_skip+1);
 262             stack_logging_log_stack(stack_logging_type_alloc, arg2, 0, 0, result, num_hot_to_skip+1);
 263             return;
 264         }
 265     }
 266     if (type == stack_logging_type_dealloc) {
 267         // simple free
 268         if (!arg1) return; // free(nil)
 269     }
 270     prepare_to_log_stack();
 271     spin_lock(&stack_logging_the_record_list->lock);
 272     stack_logging_enable_logging = 0;
 273     stack_logging_the_record_list = GrowLogRecords(stack_logging_the_record_list, stack_logging_the_record_list->num_records + 1);
 274     rec = stack_logging_the_record_list->records + stack_logging_the_record_list->num_records;
 275     // We take care of the common case of alloc-dealloc
 276     if (!stack_logging_dontcompact && stack_logging_the_record_list->num_records && (type == stack_logging_type_dealloc) && arg1 && ((rec-1)->type == stack_logging_type_alloc) && (arg1 == STACK_LOGGING_DISGUISE((rec-1)->address))) {
 277         stack_logging_the_record_list->num_records--;
 278         // printf("Erased previous record in alloc-dealloc sequence\n");
 279     } else {
 280         unsigned        stack_entries[MAX_NUM_PC];
 281         unsigned        count = 0;
 282         rec->type = type;
 283         if (type == stack_logging_type_dealloc) {
 284             rec->argument = 0;
 285             rec->address = STACK_LOGGING_DISGUISE(arg1); // we disguise the address
 286         } else if (type == stack_logging_type_alloc) {
 287             rec->argument = arg1;
 288             rec->address = STACK_LOGGING_DISGUISE(result); // we disguise the address
 289         } else {
 290             rec->argument = arg2;
 291             rec->address = STACK_LOGGING_DISGUISE(arg1); // we disguise the address
 292         }
 293         // printf("Before getting samples  0x%x 0x%x 0x%x 0x%x -> 0x%x\n", type, arg1, arg2, arg3, result);
 294         thread_stack_pcs(stack_entries, MAX_NUM_PC - 1, &count);
 295         // We put at the bottom of the stack a marker that denotes the thread (+1 for good measure...)
 296         stack_entries[count++] = (int)pthread_self() + 1;
 297         /* now let's unique the sample */
 298         // printf("Uniquing 0x%x 0x%x 0x%x 0x%x -> 0x%x\n", type, arg1, arg2, arg3, result);
 299         rec->uniqued_stack = stack_logging_get_unique_stack(&stack_logging_the_record_list->uniquing_table, &stack_logging_the_record_list->uniquing_table_num_pages, stack_entries, count, num_hot_to_skip+2); // we additionally skip the warmest 2 entries that are an artefact of the code
 300         stack_logging_the_record_list->num_records++;
 301     }
 302     stack_logging_enable_logging = 1;
 303     stack_logging_the_record_list->lock = 0;
 304 }
 305
 306 static kern_return_t default_reader(task_t task, vm_address_t address, vm_size_t size, void **ptr) {
 307     *ptr = (void *)address;
 308     return 0;
 309 }
 310
 311 static kern_return_t get_remote_records(task_t task, memory_reader_t reader, stack_logging_record_list_t **records) {
 312     // sets records
 313     vm_address_t        *remote_records_address_ref;
 314     kern_return_t       err;
 315     *records = NULL;
 316     err = reader(task, (vm_address_t)&stack_logging_the_record_list, sizeof(vm_address_t), (void **)&remote_records_address_ref);
 317     if (err) return err;
 318     if (!*remote_records_address_ref) {
 319         // printf("stack_logging: no stack record\n");
 320         return 0;
 321     }
 322     // printf("stack_logging: stack records at %p\n", (void *)(*remote_records_address_ref));
 323     // printf("stack_logging: reading %d bytes\n", sizeof(stack_logging_record_list_t));
 324     err = reader(task, *remote_records_address_ref, sizeof(stack_logging_record_list_t), (void **)records); // get the list head
 325     if (err) return err;
 326     // printf("stack_logging: overall num bytes = %d\n", records->overall_num_bytes);
 327     return reader(task, *remote_records_address_ref, (*records)->overall_num_bytes, (void **)records);
 328 }
 329
 330 kern_return_t stack_logging_get_frames(task_t task, memory_reader_t reader, vm_address_t address, vm_address_t *stack_frames_buffer, unsigned max_stack_frames, unsigned *num_frames) {
 331     stack_logging_record_list_t *records;
 332     kern_return_t       err;
 333     unsigned            index;
 334     unsigned            disguised = STACK_LOGGING_DISGUISE(address);
 335     if (!reader) reader = default_reader;
 336     *num_frames = 0;
 337     err = get_remote_records(task, reader, &records);
 338     if (err || !records) return err;
 339     // printf("stack_logging: %d records\n", records->num_records);
 340     index = 0;
 341     while (index < records->num_records) {
 342         stack_logging_record_t  *record = records->records + index;
 343         if (record->address == disguised) {
 344             return stack_logging_frames_for_uniqued_stack(task, reader, record->uniqued_stack, stack_frames_buffer, max_stack_frames, num_frames);
 345         }
 346         index++;
 347     }
 348     fprintf(stderr, "*** stack_logging: no record found for 0x%x\n", address);
 349     return 0;
 350 }
 351
 352 kern_return_t stack_logging_enumerate_records(task_t task, memory_reader_t reader, vm_address_t address, void enumerator(stack_logging_record_t, void *), void *context) {
 353     stack_logging_record_list_t *records;
 354     kern_return_t       err;
 355     unsigned            index;
 356     unsigned            disguised = STACK_LOGGING_DISGUISE(address);
 357     if (!reader) reader = default_reader;
 358     err = get_remote_records(task, reader, &records);
 359     if (err || !records) return err;
 360     // printf("stack_logging: %d records\n", records->num_records);
 361     index = 0;
 362     while (index < records->num_records) {
 363         stack_logging_record_t  *record = records->records + index;
 364         if (!address || (record->address == disguised)) enumerator(*record, context);
 365         index++;
 366     }
 367     return 0;
 368 }
 369
 370 kern_return_t stack_logging_frames_for_uniqued_stack(task_t task, memory_reader_t reader, unsigned uniqued_stack, vm_address_t *stack_frames_buffer, unsigned max_stack_frames, unsigned *num_frames) {
 371     stack_logging_record_list_t *records;
 372     unsigned            *uniquing_table;
 373     kern_return_t       err;
 374     if (!reader) reader = default_reader;
 375     *num_frames = 0;
 376     err = get_remote_records(task, reader, &records);
 377     if (err || !records) return err;
 378     err = reader(task, (vm_address_t)records->uniquing_table, records->uniquing_table_num_pages * vm_page_size, (void **)&uniquing_table);
 379     if (err) return err;
 380     while (max_stack_frames && (uniqued_stack != -1)) {
 381         unsigned        thisPC;
 382         if ((uniqued_stack * 2 + 1) * sizeof(unsigned) >= records->uniquing_table_num_pages * vm_page_size) {
 383             fprintf(stderr, "*** stack_logging: Invalid uniqued stack 0x%x", uniqued_stack);
 384             break;
 385         }
 386         thisPC = uniquing_table[uniqued_stack * 2];
 387         uniqued_stack = uniquing_table[uniqued_stack * 2 + 1];
 388         if (!thisPC && !uniqued_stack) {
 389             // Invalid entry
 390             fprintf(stderr, "*** stack_logging: Invalid entry 0x%x", thisPC);
 391             break;
 392         }
 393         stack_frames_buffer[0] = thisPC;
 394         stack_frames_buffer++;
 395         (*num_frames)++;
 396         max_stack_frames--;
 397     }
 398     return 0;
 399 }