Merge pull request #643 from tjhance/disasm

add -a flag which outputs assembly of ICs

src/CMakeLists.txt

@@ -23,6 +23,7 @@ add_library(PYSTON_OBJECTS OBJECT ${OPTIONAL_SRCS}
 		analysis/scoping_analysis.cpp
 		analysis/type_analysis.cpp
 		asm_writing/assembler.cpp
+		asm_writing/disassemble.cpp
 		asm_writing/icinfo.cpp
 		asm_writing/mc_writer.cpp
 		asm_writing/rewriter.cpp

src/asm_writing/assembler.h

@@ -17,9 +17,11 @@
 
 #include <unordered_set>
 
+#include "asm_writing/disassemble.h"
 #include "asm_writing/types.h"
 #include "codegen/stackmaps.h"
 #include "core/ast.h"
+#include "core/options.h"
 
 namespace pyston {
 namespace assembler {
@@ -74,6 +76,10 @@ private:
     static const uint8_t OPCODE_ADD = 0b000, OPCODE_SUB = 0b101;
     static const uint8_t REX_B = 1, REX_X = 2, REX_R = 4, REX_W = 8;
 
+#ifndef NDEBUG
+    AssemblyLogger logger;
+#endif
+
 private:
     void emitByte(uint8_t b);
     void emitInt(int64_t n, int bytes);
@@ -85,6 +91,24 @@ private:
 public:
     Assembler(uint8_t* start, int size) : start_addr(start), end_addr(start + size), addr(start_addr), failed(false) {}
 
+#ifndef NDEBUG
+    inline void comment(std::string msg) {
+        if (ASSEMBLY_LOGGING) {
+            logger.log_comment(msg, addr - start_addr);
+        }
+    }
+    inline std::string dump() {
+        if (ASSEMBLY_LOGGING) {
+            return logger.finalize_log(start_addr, addr);
+        } else {
+            return "";
+        }
+    }
+#else
+    inline void comment(std::string msg) {}
+    inline std::string dump() { return ""; }
+#endif
+
     bool hasFailed() { return failed; }
 
     void nop() { emitByte(0x90); }

src/asm_writing/disassemble.cpp

+// Copyright (c) 2014-2015 Dropbox, Inc.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#include "asm_writing/disassemble.h"
+
+#include "llvm/CodeGen/MachineFunction.h"
+#include "llvm/CodeGen/TargetLoweringObjectFileImpl.h"
+#include "llvm/IR/Mangler.h"
+#include "llvm/MC/MCAsmInfo.h"
+#include "llvm/MC/MCContext.h"
+#include "llvm/MC/MCDisassembler.h"
+
+#ifdef __clang__
+#pragma clang diagnostic push
+#pragma clang diagnostic ignored "-Wnon-virtual-dtor"
+#endif
+#ifdef __GNUC__
+#pragma GCC diagnostic push
+#pragma GCC diagnostic ignored "-Wnon-virtual-dtor"
+#endif
+#include "llvm/MC/MCInstPrinter.h"
+#ifdef __clang__
+#pragma clang diagnostic pop
+#endif
+#ifdef GCC
+#pragma GCC diagnostic pop
+#endif
+
+#include "llvm/MC/MCInstrInfo.h"
+#include "llvm/MC/MCStreamer.h"
+#include "llvm/MC/MCSymbol.h"
+#include "llvm/Support/FormattedStream.h"
+#include "llvm/Support/MemoryObject.h"
+#include "llvm/Support/TargetRegistry.h"
+#include "llvm/Support/TargetSelect.h"
+#include "llvm/Target/TargetMachine.h"
+
+#include "codegen/codegen.h"
+
+void LLVMInitializeX86Disassembler();
+
+namespace pyston {
+namespace assembler {
+
+void disassemblyInitialize() {
+    LLVMInitializeX86Disassembler();
+    llvm::InitializeNativeTargetAsmPrinter();
+    llvm::InitializeNativeTargetAsmParser();
+}
+
+void AssemblyLogger::log_comment(const std::string& comment, size_t offset) {
+    comments[offset].push_back(comment);
+}
+
+void AssemblyLogger::append_comments(llvm::raw_string_ostream& stream, size_t pos) const {
+    if (comments.count(pos) > 0) {
+        for (const std::string& comment : comments.at(pos)) {
+            stream << "; " << comment << "\n";
+        }
+    }
+}
+
+std::string AssemblyLogger::finalize_log(uint8_t const* start_addr, uint8_t const* end_addr) const {
+    static __thread llvm::MCDisassembler* DisAsm = NULL;
+    static __thread llvm::MCInstPrinter* IP = NULL;
+
+    if (!DisAsm) {
+        const llvm::StringRef triple = g.tm->getTargetTriple();
+        std::string err;
+        const llvm::Target* target = llvm::TargetRegistry::lookupTarget(triple, err);
+        assert(target);
+        const llvm::MCRegisterInfo* MRI = target->createMCRegInfo(triple);
+        assert(MRI);
+        const llvm::MCAsmInfo* MAI = target->createMCAsmInfo(*MRI, triple);
+        assert(MAI);
+        const llvm::MCInstrInfo* MII = target->createMCInstrInfo();
+        assert(MII);
+        std::string FeaturesStr;
+        const llvm::StringRef CPU = "";
+        const llvm::MCSubtargetInfo* STI = target->createMCSubtargetInfo(triple, CPU, FeaturesStr);
+        assert(STI);
+        int AsmPrinterVariant = MAI->getAssemblerDialect(); // 0 is ATT, 1 is Intel
+        IP = target->createMCInstPrinter(AsmPrinterVariant, *MAI, *MII, *MRI, *STI);
+        assert(IP);
+        llvm::MCObjectFileInfo* MOFI = new llvm::MCObjectFileInfo();
+        assert(MOFI);
+        llvm::MCContext* Ctx = new llvm::MCContext(MAI, MRI, MOFI);
+        assert(Ctx);
+        DisAsm = target->createMCDisassembler(*STI, *Ctx);
+        assert(DisAsm);
+    }
+
+    std::string result = "";
+    llvm::raw_string_ostream stream(result);
+
+    size_t pos = 0;
+    append_comments(stream, pos);
+
+    while (pos < (end_addr - start_addr)) {
+        llvm::MCInst inst;
+        uint64_t size;
+        llvm::MCDisassembler::DecodeStatus s = DisAsm->getInstruction(
+            inst /* out */, size /* out */, llvm::ArrayRef<uint8_t>(start_addr + pos, end_addr), 0, llvm::nulls(),
+            llvm::nulls());
+        assert(s == llvm::MCDisassembler::Success);
+
+        IP->printInst(&inst, stream, "");
+        stream << "\n";
+
+        pos += size;
+        append_comments(stream, pos);
+    }
+
+    return stream.str();
+}
+}
+}

src/asm_writing/disassemble.h

+// Copyright (c) 2014-2015 Dropbox, Inc.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#ifndef PYSTON_ASMWRITING_DISASSEMBLE_H
+#define PYSTON_ASMWRITING_DISASSEMBLE_H
+
+#include <unordered_map>
+
+#include "llvm/Support/raw_ostream.h"
+
+namespace pyston {
+namespace assembler {
+
+void disassemblyInitialize();
+
+class AssemblyLogger {
+private:
+    std::unordered_map<size_t, std::vector<std::string>> comments;
+
+    void append_comments(llvm::raw_string_ostream&, size_t pos) const;
+
+public:
+    void log_comment(const std::string&, size_t offset);
+    std::string finalize_log(uint8_t const* start_addr, uint8_t const* end_addr) const;
+};
+}
+}
+
+#endif

src/asm_writing/rewriter.cpp

@@ -270,6 +270,8 @@ void RewriterVar::addGuard(uint64_t val) {
 }
 
 void Rewriter::_addGuard(RewriterVar* var, RewriterVar* val_constant) {
+    assembler->comment("_addGuard");
+
     assert(val_constant->is_constant);
     uint64_t val = val_constant->constant_value;
 
@@ -300,6 +302,8 @@ void RewriterVar::addGuardNotEq(uint64_t val) {
 }
 
 void Rewriter::_addGuardNotEq(RewriterVar* var, RewriterVar* val_constant) {
+    assembler->comment("_addGuardNotEq");
+
     assert(val_constant->is_constant);
     uint64_t val = val_constant->constant_value;
 
@@ -333,6 +337,8 @@ void RewriterVar::addAttrGuard(int offset, uint64_t val, bool negate) {
 }
 
 void Rewriter::_addAttrGuard(RewriterVar* var, int offset, RewriterVar* val_constant, bool negate) {
+    assembler->comment("_addAttrGuard");
+
     assert(val_constant->is_constant);
     uint64_t val = val_constant->constant_value;
 
@@ -383,6 +389,8 @@ RewriterVar* RewriterVar::getAttr(int offset, Location dest, assembler::MovType
 }
 
 void Rewriter::_getAttr(RewriterVar* result, RewriterVar* ptr, int offset, Location dest, assembler::MovType type) {
+    assembler->comment("_getAttr");
+
     // TODO if var is a constant, we will end up emitting something like
     //   mov $0x123, %rax
     //   mov $0x10(%rax), %rdi
@@ -410,6 +418,8 @@ RewriterVar* RewriterVar::getAttrDouble(int offset, Location dest) {
 }
 
 void Rewriter::_getAttrDouble(RewriterVar* result, RewriterVar* ptr, int offset, Location dest) {
+    assembler->comment("_getAttrDouble");
+
     assembler::Register ptr_reg = ptr->getInReg();
 
     ptr->bumpUse();
@@ -430,6 +440,8 @@ RewriterVar* RewriterVar::getAttrFloat(int offset, Location dest) {
 }
 
 void Rewriter::_getAttrFloat(RewriterVar* result, RewriterVar* ptr, int offset, Location dest) {
+    assembler->comment("_getAttrFloat");
+
     assembler::Register ptr_reg = ptr->getInReg();
 
     ptr->bumpUse();
@@ -454,6 +466,8 @@ RewriterVar* RewriterVar::cmp(AST_TYPE::AST_TYPE cmp_type, RewriterVar* other, L
 }
 
 void Rewriter::_cmp(RewriterVar* result, RewriterVar* v1, AST_TYPE::AST_TYPE cmp_type, RewriterVar* v2, Location dest) {
+    assembler->comment("_cmp");
+
     assembler::Register v1_reg = v1->getInReg();
     assembler::Register v2_reg = v2->getInReg();
     assert(v1_reg != v2_reg); // TODO how do we ensure this?
@@ -488,6 +502,8 @@ RewriterVar* RewriterVar::toBool(Location dest) {
 }
 
 void Rewriter::_toBool(RewriterVar* result, RewriterVar* var, Location dest) {
+    assembler->comment("_toBool");
+
     assembler::Register this_reg = var->getInReg();
 
     var->bumpUse();
@@ -509,6 +525,8 @@ void RewriterVar::setAttr(int offset, RewriterVar* val) {
 }
 
 void Rewriter::_setAttr(RewriterVar* ptr, int offset, RewriterVar* val) {
+    assembler->comment("_setAttr");
+
     assembler::Register ptr_reg = ptr->getInReg();
 
     bool is_immediate;
@@ -767,6 +785,8 @@ RewriterVar* Rewriter::call(bool has_side_effects, void* func_addr, const Rewrit
 
 void Rewriter::_call(RewriterVar* result, bool has_side_effects, void* func_addr, const RewriterVar::SmallVector& args,
                      const RewriterVar::SmallVector& args_xmm) {
+    assembler->comment("_call");
+
     if (has_side_effects)
         assert(done_guarding);
 
@@ -1056,6 +1076,8 @@ void Rewriter::commit() {
     }
 
     if (marked_inside_ic) {
+        assembler->comment("mark inside ic");
+
         // TODO this is super hacky: we don't know the address that we want to inc/dec, since
         // it depends on the slot that we end up picking, so just write out an arbitrary
         // constant an we'll rewrite it later
@@ -1067,6 +1089,8 @@ void Rewriter::commit() {
         assembler->decl(assembler::Indirect(reg, 0));
     }
 
+    assembler->comment("live outs");
+
 // Make sure that we have been calling bumpUse correctly.
 // All uses should have been accounted for, other than the live outs
 #ifndef NDEBUG
@@ -1175,6 +1199,15 @@ void Rewriter::commit() {
         return;
     }
 
+    uint64_t asm_size_bytes = assembler->bytesWritten();
+#ifndef NDEBUG
+    std::string asm_dump;
+    if (ASSEMBLY_LOGGING) {
+        assembler->comment("size in bytes: " + std::to_string(asm_size_bytes));
+        asm_dump = assembler->dump();
+    }
+#endif
+
     rewrite->commit(this);
 
     if (assembler->hasFailed()) {
@@ -1184,8 +1217,17 @@ void Rewriter::commit() {
 
     finished = true;
 
+#ifndef NDEBUG
+    if (ASSEMBLY_LOGGING) {
+        fprintf(stderr, "%s\n\n", asm_dump.c_str());
+    }
+#endif
+
     static StatCounter ic_rewrites_committed("ic_rewrites_committed");
     ic_rewrites_committed.log();
+
+    static StatCounter ic_rewrites_total_bytes("ic_rewrites_total_bytes");
+    ic_rewrites_total_bytes.log(asm_size_bytes);
 }
 
 bool Rewriter::finishAssembly(ICSlotInfo* picked_slot, int continue_offset) {
@@ -1210,6 +1252,7 @@ void Rewriter::commitReturning(RewriterVar* var) {
     STAT_TIMER(t0, "us_timer_rewriter", 10);
 
     addAction([=]() {
+        assembler->comment("commitReturning");
         var->getInReg(getReturnDestination(), true /* allow_constant_in_reg */);
         var->bumpUse();
     }, { var }, ActionType::NORMAL);
@@ -1245,6 +1288,8 @@ RewriterVar* Rewriter::add(RewriterVar* a, int64_t b, Location dest) {
 }
 
 void Rewriter::_add(RewriterVar* result, RewriterVar* a, int64_t b, Location dest) {
+    assembler->comment("_add");
+
     // TODO better reg alloc (e.g., mov `a` directly to the dest reg)
 
     assembler::Register newvar_reg = allocReg(dest);
@@ -1275,6 +1320,8 @@ RewriterVar* Rewriter::allocate(int n) {
 }
 
 int Rewriter::_allocate(RewriterVar* result, int n) {
+    assembler->comment("_allocate");
+
     assert(n >= 1);
 
     int scratch_size = rewrite->getScratchSize();
@@ -1323,6 +1370,8 @@ RewriterVar* Rewriter::allocateAndCopy(RewriterVar* array_ptr, int n) {
 }
 
 void Rewriter::_allocateAndCopy(RewriterVar* result, RewriterVar* array_ptr, int n) {
+    assembler->comment("_allocateAndCopy");
+
     // TODO smart register allocation
 
     int offset = _allocate(result, n);
@@ -1359,6 +1408,8 @@ RewriterVar* Rewriter::allocateAndCopyPlus1(RewriterVar* first_elem, RewriterVar
 }
 
 void Rewriter::_allocateAndCopyPlus1(RewriterVar* result, RewriterVar* first_elem, RewriterVar* rest_ptr, int n_rest) {
+    assembler->comment("_allocateAndCopyPlus1");
+
     int offset = _allocate(result, n_rest + 1);
 
     assembler::Register first_reg = first_elem->getInReg();

src/core/options.cpp

@@ -29,6 +29,7 @@ int PYTHON_VERSION_HEX = version_hex(PYTHON_VERSION_MAJOR, PYTHON_VERSION_MINOR,
 
 int MAX_OPT_ITERATIONS = 1;
 
+bool ASSEMBLY_LOGGING = false;
 bool CONTINUE_AFTER_FATAL = false;
 bool FORCE_INTERPRETER = false;
 bool FORCE_OPTIMIZE = false;

src/core/options.h

@@ -38,7 +38,8 @@ extern int SPECULATION_THRESHOLD;
 extern int MAX_OBJECT_CACHE_ENTRIES;
 
 extern bool SHOW_DISASM, FORCE_INTERPRETER, FORCE_OPTIMIZE, PROFILE, DUMPJIT, TRAP, USE_STRIPPED_STDLIB,
-    CONTINUE_AFTER_FATAL, ENABLE_INTERPRETER, ENABLE_PYPA_PARSER, USE_REGALLOC_BASIC, PAUSE_AT_ABORT, ENABLE_TRACEBACKS;
+    CONTINUE_AFTER_FATAL, ENABLE_INTERPRETER, ENABLE_PYPA_PARSER, USE_REGALLOC_BASIC, PAUSE_AT_ABORT, ENABLE_TRACEBACKS,
+    ASSEMBLY_LOGGING;
 
 extern bool ENABLE_ICS, ENABLE_ICGENERICS, ENABLE_ICGETITEMS, ENABLE_ICSETITEMS, ENABLE_ICDELITEMS, ENABLE_ICBINEXPS,
     ENABLE_ICNONZEROS, ENABLE_ICCALLSITES, ENABLE_ICSETATTRS, ENABLE_ICGETATTRS, ENALBE_ICDELATTRS, ENABLE_ICGETGLOBALS,

src/jit.cpp

@@ -31,6 +31,7 @@
 
 #include "osdefs.h"
 
+#include "asm_writing/disassemble.h"
 #include "capi/types.h"
 #include "codegen/entry.h"
 #include "codegen/irgen/hooks.h"
@@ -187,6 +188,8 @@ int handleArg(char code) {
         Py_InspectFlag = true;
     else if (code == 'n') {
         ENABLE_INTERPRETER = false;
+    } else if (code == 'a') {
+        ASSEMBLY_LOGGING = true;
     } else if (code == 'p') {
         PROFILE = true;
     } else if (code == 'j') {
@@ -290,7 +293,7 @@ static int main(int argc, char** argv) {
 
         // Suppress getopt errors so we can throw them ourselves
         opterr = 0;
-        while ((code = getopt(argc, argv, "+:OqdIibpjtrsSvnxEc:FuPTGm:")) != -1) {
+        while ((code = getopt(argc, argv, "+:OqdIibpjtrsSvnxEac:FuPTGm:")) != -1) {
             if (code == 'c') {
                 assert(optarg);
                 command = optarg;
@@ -329,6 +332,10 @@ static int main(int argc, char** argv) {
             setvbuf(stderr, (char*)NULL, _IONBF, BUFSIZ);
         }
 
+        if (ASSEMBLY_LOGGING) {
+            assembler::disassemblyInitialize();
+        }
+
         {
             Timer _t("for initCodegen");
             initCodegen();

tools/measure_ics.py

+# Copyright (c) 2014-2015 Dropbox, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#    http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+#!/usr/bin/env python
+
+from __future__ import division
+
+import subprocess
+import os
+
+BASE_DIR = os.path.join(os.path.dirname(__file__), "..")
+TEST_DIR = os.path.join(BASE_DIR, "test/tests/")
+EXTMODULE_DIR_PYSTON = os.path.abspath(os.path.join(BASE_DIR, "test/test_extension/"))
+
+def main():
+    tests = os.listdir(os.path.join(TEST_DIR))
+    ics_tests = [os.path.join(TEST_DIR, test) for test in tests if
+            test.endswith(".py") and "ics" in test]
+
+    results = []
+    results.append(['test', 'ics', 'total ic size', 'average ic size'])
+    totalNumIcs = 0
+    totalSizeIcs = 0
+    asm_log = []
+    for ics_test in ics_tests:
+        stats, assembly_logging = runTest(ics_test)
+        numIcs = stats['ic_rewrites_committed']
+        sizeIcs = stats['ic_rewrites_total_bytes']
+        results.append([ics_test, str(numIcs), str(sizeIcs), div(sizeIcs, numIcs)])
+        totalNumIcs += numIcs
+        totalSizeIcs += sizeIcs
+        asm_log.append(assembly_logging)
+
+    print "\n".join(asm_log)
+
+    results.append(['TOTAL', str(totalNumIcs), str(totalSizeIcs), div(totalSizeIcs, totalNumIcs)])
+
+    printTable(results)
+
+def div(a, b):
+    if b == 0:
+        return "undef"
+    else:
+        return '%.3f' % (a / b)
+
+def runTest(filename):
+    print 'running test', filename
+    pyston = os.path.join(BASE_DIR, "pyston_dbg")
+
+    env = dict(os.environ)
+
+    env["PYTHONPATH"] = EXTMODULE_DIR_PYSTON
+
+    proc = subprocess.Popen([pyston, "-a", "-s", filename],
+            stdout=subprocess.PIPE,
+            stderr=subprocess.PIPE,
+            stdin=subprocess.PIPE,
+            env=env)
+    stdout, stderr = proc.communicate()
+    if proc.wait() != 0:
+        raise Exception("%s failed" % filename)
+
+    stderr, stats_str = stderr.split("Stats:")
+    stats_str, stderr_tail = stats_str.split("(End of stats)\n")
+    other_stats_str, counter_str = stats_str.split("Counters:")
+    stats = {}
+    for l in counter_str.strip().split('\n'):
+        assert l.count(':') == 1, l
+        k, v = l.split(':')
+        stats[k.strip()] = int(v)
+
+    assembly_logging = stderr
+
+    return (stats, assembly_logging)
+
+def printTable(table):
+    widths = [3 + max(len(table[i][j]) for i in xrange(len(table))) for j in xrange(len(table[0]))]
+    for row in table:
+        for col, elem in enumerate(row):
+            print elem, ("" if col == len(row)-1 else " " * (widths[col] - len(elem))),
+        print ''
+
+if __name__ == '__main__':
+    main()