Hotfix/3.8 support (#44)

* hotfix(3.8-support): Fix broken support for Python 3.8

The _PyRuntimeState structure changed between Python 3.7 and 3.8. This hasn't been caught in tests because the fallback on BSS scanning on Linux worked. However, this broke Austin on MacOS and a fix is therefore required.

Enhanced MacOS coding by adding additional delay at startup to ensure that the VM maps have stabilised. When the maps are looked up too soon, the wrong symbol addresses are inferred.

Enhanced multi-processing tests

Fixed support for Python distributions on Mac OS that do not use a shared library

Update Mac OS instructions in the README to mention that sudo is required.

Also, metrics are now logged on STDERR too.

ChangeLog

@@ -1,3 +1,8 @@
+2020-05-16 v1.0.1
+
+  Bugfix: Fixed broken support for Python 3.8 on MacOS.
+
+
 2019-07-28 v1.0.0
 
   Austin can now profile multi-process Python application:
@@ -25,7 +30,7 @@
     - --full, -f:
 
         Generate samples with a full set of metrics, which include timing and
-        memory prifiling information. Note that the output from this mode needs
+        memory profiling information. Note that the output from this mode needs
         to be processed before it can be used with FlameGraph.
 
     - --output, -o:

README.md

@@ -27,8 +27,8 @@
     <img src="https://badges.debian.net/badges/debian/unstable/austin/version.svg"
          alt="Debian package status">
   </a>
-  <img src="https://img.shields.io/badge/version-1.0.0-blue.svg"
-       alt="Version 1.0.0">
+  <img src="https://img.shields.io/badge/version-1.0.1-blue.svg"
+       alt="Version 1.0.1">
   <a href="https://github.com/P403n1x87/austin/blob/master/LICENSE.md">
     <img src="https://img.shields.io/badge/license-GPLv3-ff69b4.svg"
          alt="LICENSE">
@@ -68,7 +68,7 @@
 
 <h3 align="center">A frame stack sampler for CPython</h3>
 
-[![Build Status](https://travis-ci.org/P403n1x87/austin.svg?branch=master)](https://travis-ci.org/P403n1x87/austin) ![Version](https://img.shields.io/badge/version-1.0.0-blue.svg) [![License](https://img.shields.io/badge/license-GPLv3-ff69b4.svg)](https://github.com/P403n1x87/austin/blob/master/LICENSE.md)
+[![Build Status](https://travis-ci.org/P403n1x87/austin.svg?branch=master)](https://travis-ci.org/P403n1x87/austin) ![Version](https://img.shields.io/badge/version-1.0.1-blue.svg) [![License](https://img.shields.io/badge/license-GPLv3-ff69b4.svg)](https://github.com/P403n1x87/austin/blob/master/LICENSE.md)
 
 -->
 
@@ -323,6 +323,12 @@ platforms and architectures
 | **arm**    | ✓ |   |   |
 | **armv7**  | ✓ |   |   |
 
+Due to the **System Integrity Protection** introduced in **MacOS** with El
+Capitan, Austin cannot profile Python processes that use an executable located
+in the `/bin` folder, even with `sudo`. Hence, either run the interpreter from a
+virtual environment or use a Python interpreter that is installed in, e.g.,
+`/Applications` or via `brew` with the default prefix (`/usr/local`). Even in
+these cases, though, the use of `sudo` is required.
 
 > **NOTE** Austin *might* work with other versions of Python on all the
 > platforms and architectures above. So it is worth giving it a try even if

configure.ac

@@ -2,7 +2,7 @@
 # Process this file with autoconf to produce a configure script.
 
 AC_PREREQ([2.69])
-AC_INIT([austin], [1.0.0], [https://github.com/p403n1x87/austin/issues])
+AC_INIT([austin], [1.0.1], [https://github.com/p403n1x87/austin/issues])
 AC_CONFIG_SRCDIR([config.h.in])
 AC_CONFIG_HEADERS([config.h])
 AM_INIT_AUTOMAKE

debian/austin.1

@@ -1,7 +1,7 @@
 .\" DO NOT MODIFY THIS FILE!  It was generated by help2man 1.47.6.
-.TH AUSTIN "1" "October 2019" "austin 1.0.0" "User Commands"
+.TH AUSTIN "16" "May 2020" "austin 1.0.1" "User Commands"
 .SH NAME
-austin \- manual page for austin 1.0.0
+austin \- manual page for austin 1.0.1
 .SH SYNOPSIS
 .B austin
 [\fI\,OPTION\/\fR...] \fI\,command \/\fR[\fI\,ARG\/\fR...]

debian/changelog

@@ -1,3 +1,10 @@
+austin (1.0.1-1) unstable; urgency=medium
+
+  * Fixed support for Python 3.8
+
+ -- Gabriele N. Tornetta <phoenix1987@gmail.com>  Sat, 16 May 2020 12:36:00 +0100
+
+
 austin (1.0.0-1) unstable; urgency=medium
 
   * Added support for multi-process Python applications

debian/copyright

@@ -4,7 +4,7 @@ Upstream-Contact: Gabriele N. Tornetta <phoenix1987@gmail.com>
 Source: https://github.com/P403n1x87/austin
 
 Files: *
-Copyright: 2018-2019 Gabriele N. Tornetta <phoenix1987@gmail.com>
+Copyright: 2018-2020 Gabriele N. Tornetta <phoenix1987@gmail.com>
 License: GPL-3+
 
 License: GPL-3+

snap/snapcraft.yaml

@@ -1,5 +1,5 @@
 name: austin
-version: '1.0.0+git'
+version: '1.0.1+git'
 summary: A Python frame stack sampler for CPython
 description: |
   Austin is a Python frame stack sampler for CPython written in pure C. It

src/austin.h

@@ -25,7 +25,7 @@
 
 
 #define PROGRAM_NAME                    "austin"
-#define VERSION                         "1.0.0"
+#define VERSION                         "1.0.1"
 
 
 #endif

src/logging.c

@@ -43,7 +43,7 @@
 #define	LOG_INFO	6	/* informational */
 #define	LOG_DEBUG	7	/* debug-level messages */
 
-FILE * lf = NULL;
+FILE * logfile = NULL;
 #endif
 
 #include "austin.h"
@@ -56,12 +56,12 @@ _log_writer(int prio, const char * fmt, va_list ap) {
   vsyslog(prio, fmt, ap);
 
   #else
-  if (lf == NULL) {
+  if (logfile == NULL) {
     vfprintf(stderr, fmt, ap); fputc('\n', stderr);
   }
   else {
-    vfprintf(lf, fmt, ap); fputc('\n', lf);
-    fflush(lf);
+    vfprintf(logfile, fmt, ap); fputc('\n', logfile);
+    fflush(logfile);
   }
 
   #endif
@@ -75,10 +75,10 @@ logger_init(void) {
   openlog ("austin", LOG_CONS | LOG_PID | LOG_NDELAY, LOG_LOCAL1);
 
   #else
-  if (lf == NULL) {
+  if (logfile == NULL) {
     char path[MAX_PATH];
     ExpandEnvironmentStrings("%TEMP%\\austin.log", path, MAX_PATH);
-    lf = fopen(path, "a");
+    logfile = fopen(path, "a");
   }
   #endif
 }
@@ -87,11 +87,13 @@ logger_init(void) {
 void
 log_f(const char * fmt, ...) {
   va_list args;
-  va_start(args, fmt);
 
-  _log_writer(LOG_CRIT, fmt, args);
-  vfprintf(stderr, fmt, args); fputc('\n', stderr);
+  va_start(args, fmt);
+    _log_writer(LOG_CRIT, fmt, args);
+  va_end(args);
 
+  va_start(args, fmt);
+    vfprintf(stderr, fmt, args); fputc('\n', stderr);
   va_end(args);
 }
 
@@ -125,7 +127,20 @@ log_i(const char * fmt, ...) {
   va_end(args);
 }
 
-#if defined(DEBUG) || defined(TRACE)
+void
+log_m(const char * fmt, ...) {
+  va_list args;
+
+  va_start(args, fmt);
+    _log_writer(LOG_INFO, fmt, args);
+  va_end(args);
+
+  va_start(args, fmt);
+    vfprintf(stderr, fmt, args); fputc('\n', stderr);
+  va_end(args);
+}
+
+#ifdef DEBUG
 void
 log_d(const char * fmt, ...) {
   va_list args;
@@ -161,7 +176,7 @@ logger_close(void) {
   closelog();
 
   #else
-  if (lf != NULL)
-    fclose(lf);
+  if (logfile != NULL)
+    fclose(logfile);
   #endif
 }

src/logging.h

@@ -48,6 +48,9 @@ log_w(const char *, ...);
 void
 log_i(const char *, ...);
 
+void
+log_m(const char *, ...);  // metrics
+
 #ifdef DEBUG
 void
 log_d(const char *, ...);

src/mac/py_proc.h

@@ -79,14 +79,18 @@ _py_proc__analyze_macho64(py_proc_t * self, void * map) {
   for (register int i = 0; cmd_cnt < 2 && i < ncmds; i++) {
     switch (cmd->cmd) {
     case LC_SEGMENT_64:
-      if (strcmp(cmd->segname, "__DATA") == 0) {
+      if (strcmp(cmd->segname, "__TEXT") == 0) {
+        img_base -= cmd->vmaddr;
+      }
+      else if (strcmp(cmd->segname, "__DATA") == 0) {
         int nsects = cmd->nsects;
         struct section_64 * sec = (struct section_64 *) ((void *) cmd + sizeof(struct segment_command_64));
         self->map.bss.size = 0;
         for (register int j = 0; j < nsects; j++) {
           if (strcmp(sec[j].sectname, "__bss") == 0) {
             self->map.bss.base += sec[j].addr;
             self->map.bss.size = sec[j].size;
+            log_d("BSS bounds [%p - %p]", self->map.bss.base, self->map.bss.base + self->map.bss.size);
             break;
           }
         }
@@ -137,14 +141,18 @@ _py_proc__analyze_macho32(py_proc_t * self, void * map) {
   for (register int i = 0; cmd_cnt < 2 && i < ncmds; i++) {
     switch (cmd->cmd) {
     case LC_SEGMENT:
-      if (strcmp(cmd->segname, "__DATA") == 0) {
+      if (strcmp(cmd->segname, "__TEXT") == 0) {
+        img_base -= cmd->vmaddr;
+      }
+      else if (strcmp(cmd->segname, "__DATA") == 0) {
         int nsects = cmd->nsects;
         struct section * sec = (struct section *) ((void *) cmd + sizeof(struct segment_command));
         self->map.bss.size = 0;
         for (register int j = 0; j < nsects; j++) {
           if (strcmp(sec[j].sectname, "__bss") == 0) {
             self->map.bss.base += sec[j].addr;
             self->map.bss.size = sec[j].size;
+            log_d("BSS bounds [%p - %p]", self->map.bss.base, self->map.bss.base + self->map.bss.size);
             break;
           }
         }
@@ -291,7 +299,9 @@ _py_proc__get_maps(py_proc_t * self) {
   mach_msg_type_number_t         count = sizeof(vm_region_basic_info_data_64_t);
   mach_port_t                    object_name;
 
-  usleep(10000);  // NOTE: Mac OS X kernel bug
+  // NOTE: Mac OS X kernel bug. This also gives time to the VM maps to
+  // stabilise.
+  usleep(100000);
 
   self->extra->task_id = pid_to_task(self->pid);
   if (self->extra->task_id == 0)
@@ -321,27 +331,44 @@ _py_proc__get_maps(py_proc_t * self) {
 
     if (size > 0 && len) {
       path[len] = 0;
-      if (self->bin_path == NULL && strstr(path, "python")) {
+      if (self->bin_path == NULL && strstr(path, "ython")) {
         if (strstr(path + path_len - 3, ".so") == NULL) {
-          // check that it is not a .so file
+          // not a .so file
           self->bin_path = strndup(path, path_len);
+          self->map.bss.base = (void *) address;  // WARNING: Image base. Not yet the BSS base!!
+          if (_py_proc__analyze_macho(self, path, (void *) address, size)) {
+            // We haven't found the symbols in the binary so we look for a library.
+            self->map.bss.base = NULL;
+          }
+          goto next_map;
         }
       }
 
-      if (self->lib_path == NULL && strstr(path, "Python")) {
+      if (self->map.bss.base == NULL && self->lib_path == NULL && strstr(path, "ython") && size > (1 << 20)) {
         if (strstr(path + path_len - 3, ".so") == NULL) {
           self->lib_path = strndup(path, path_len);
 
-          self->map.bss.base = (void *) address;  // WARNING: Partial result. Not yet the BSS base!!
+          self->map.bss.base = (void *) address;  // WARNING: Image base. Not yet the BSS base!!
           if (_py_proc__analyze_macho(self, path, (void *) address, size))
             return 1;
+          goto next_map;
         }
       }
-    }
 
+      // Make a best guess for the heap boundary. This would only work for
+      // 64-bit architectures.
+      if (address & 0x0000700000000000) {
+        if (self->map.heap.base == NULL)
+          self->map.heap.base = (void *) address;
+        self->map.heap.size += size;
+      }
+    }
+  next_map:
     address += size;
   }
 
+  log_d("HEAP bounds [%p - %p]", self->map.heap.base, self->map.heap.base + self->map.heap.size);
+
   if (self->bin_path && self->lib_path && !strcmp(self->bin_path, self->lib_path))
     self->bin_path = NULL;
 

src/mem.c

@@ -32,6 +32,7 @@
 #elif defined(PL_MACOS)
   #include <mach/mach.h>
   #include <mach/mach_vm.h>
+  #include <mach/machine/kern_return.h>
 
 #endif
 
@@ -60,14 +61,22 @@ copy_memory(pid_t pid, void * addr, ssize_t len, void * buf) {
   #elif defined(PL_MACOS)                                              /* MAC */
   mach_port_t task;
   if (task_for_pid(mach_task_self(), pid, &task) != KERN_SUCCESS) {
-    log_d("Failed to obtain task from PID. Are you running austin with the right privileges?");
+    log_d(
+      "Failed to obtain task from PID. Are you running austin with the right privileges?"
+    );
     return -1;
   }
 
   mach_vm_size_t nread;
-  mach_vm_read_overwrite(task, (mach_vm_address_t) addr, len, (mach_vm_address_t) buf, &nread);
+  kern_return_t kr = mach_vm_read_overwrite(
+    task, (mach_vm_address_t) addr, len, (mach_vm_address_t) buf, &nread
+  );
+  if (kr != KERN_SUCCESS) {
+    log_t("copy_memory: mach_vm_read_overwrite returned %d", kr);
+    return -1;
+  }
 
-  return nread == len ? nread : -1;
+  return nread;
 
   #endif
 }