Skip to content
Permalink

Comparing changes

Choose two branches to see what’s changed or to start a new pull request. If you need to, you can also or learn more about diff comparisons.

Open a pull request

Create a new pull request by comparing changes across two branches. If you need to, you can also . Learn more about diff comparisons here.
base repository: rubinius/rubinius
Failed to load repositories. Confirm that selected base ref is valid, then try again.
Loading
base: a0a7287d1bee
Choose a base ref
...
head repository: rubinius/rubinius
Failed to load repositories. Confirm that selected head ref is valid, then try again.
Loading
compare: 1e56ff7742d3
Choose a head ref
  • 5 commits
  • 10 files changed
  • 1 contributor

Commits on Jun 6, 2016

  1. Improved logging message format.

    Generally, log messages for non-exceptional events should follow the format:
    
      object: operation: details
    
    For example: 'process: fork: child: <PID, ...'
    
    For exceptional events, the format should be:
    
      <strerror result>: object: details
    brixen committed Jun 6, 2016
    Copy the full SHA
    125baf2 View commit details

Commits on Jun 7, 2016

  1. Copy the full SHA
    b7d9a10 View commit details
  2. Improved Fiber attributes and logging.

    Fiber#source returns the non-core library source code line where the Fiber
    was created. Fiber#thread_name returns the name of the Thread that created the
    Fiber. Fiber#fiber_id returns a unique ID for the Fiber instance.
    
    The Rubinius log includes entries for the Fiber create and exit events.
    brixen committed Jun 7, 2016
    Copy the full SHA
    862a8fd View commit details
  3. Copy the full SHA
    10fea49 View commit details
  4. Copy the full SHA
    1e56ff7 View commit details
Showing with 107 additions and 25 deletions.
  1. +1 −1 core/enumerator.rb
  2. +9 −0 core/fiber.rb
  3. +5 −1 core/thread.rb
  4. +30 −0 machine/builtin/fiber.cpp
  5. +18 −0 machine/builtin/fiber.hpp
  6. +8 −8 machine/builtin/system.cpp
  7. +29 −12 machine/builtin/thread.cpp
  8. +2 −0 machine/builtin/thread.hpp
  9. +3 −3 machine/environment.cpp
  10. +2 −0 machine/memory/finalizer.cpp
2 changes: 1 addition & 1 deletion core/enumerator.rb
Original file line number Diff line number Diff line change
@@ -449,7 +449,7 @@ def zip(*lists)

if Rubinius::Fiber::ENABLED
class FiberGenerator
STACK_SIZE = 163_840
STACK_SIZE = 1_048_576

attr_reader :result

9 changes: 9 additions & 0 deletions core/fiber.rb
Original file line number Diff line number Diff line change
@@ -1,6 +1,9 @@
module Rubinius
class Fiber
attr_reader :stack_size
attr_reader :thread_name
attr_reader :fiber_id
attr_reader :source

def self.new(**kw, &block)
if block.nil?
@@ -35,5 +38,11 @@ def transfer(*args)
def alive?
!@dead
end

def inspect
str = "#<#{self.class}:0x#{object_id.to_s(16)} thread_name=#{@thread_name} fiber_id=#{@fiber_id} status=#{alive? ? "alive" : "dead"}"
str << " source=#{@source}" if @source
str << ">"
end
end
end
6 changes: 5 additions & 1 deletion core/thread.rb
Original file line number Diff line number Diff line change
@@ -8,6 +8,7 @@ class Thread
attr_reader :pid
attr_reader :exception
attr_reader :stack_size
attr_reader :source

def self.new(*args, **kw, &block)
stack_size = Rubinius::Type.try_convert kw[:stack_size], Fixnum, :to_int
@@ -132,7 +133,10 @@ def inspect
stat = status()
stat = "dead" unless stat

"#<#{self.class}:0x#{object_id.to_s(16)} id=#{@thread_id} #{stat}>"
str = "#<#{self.class}:0x#{object_id.to_s(16)} id=#{@thread_id} pid=#{@pid}"
str << " source=#{@source}" if @source
str << " status=#{stat || "dead"}"
str << ">"
end

alias_method :to_s, :inspect
30 changes: 30 additions & 0 deletions machine/builtin/fiber.cpp
Original file line number Diff line number Diff line change
@@ -12,19 +12,29 @@

#include "memory/gc.hpp"

#include <ostream>
#include <string>

namespace rubinius {
std::atomic<uint32_t> Fiber::fiber_ids_;

void Fiber::bootstrap(STATE) {
GO(fiber).set(state->memory()->new_class<Class, Fiber>(
state, G(rubinius), "Fiber"));

fiber_ids_.store(0);

#ifdef RBX_FIBER_ENABLED
G(fiber)->set_const(state, "ENABLED", cTrue);
#else
G(fiber)->set_const(state, "ENABLED", cFalse);
#endif
}

double Fiber::run_time() {
return timer::time_elapsed_seconds(start_time());
}

Fiber* Fiber::current(STATE) {
#ifdef RBX_FIBER_ENABLED
Fiber* fib = state->vm()->current_fiber.get();
@@ -72,6 +82,10 @@ namespace rubinius {
fib->dead(cTrue);
fib->set_call_frame(state, 0);

logger::write("fiber: exit: %s, %d, %fs",
fib->thread_name()->c_str(state),
fib->fiber_id()->to_native(), fib->run_time());

Fiber* dest = fib->prev();

// If this fiber has already been cleaned up, just ignore this
@@ -116,6 +130,22 @@ namespace rubinius {
fib->stack_size(state, size);
}

if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
std::ostringstream source;

source << call_frame->file(state)->cpp_str(state).c_str()
<< ":" << call_frame->line(state);

logger::write("fiber: new: %s, %d, %s",
fib->thread_name()->c_str(state),
fib->fiber_id()->to_native(), source.str().c_str());

fib->source(state, String::create(state, source.str().c_str()));
} else {
logger::write("fiber: new: %s, %d",
fib->thread_name()->c_str(state), fib->fiber_id()->to_native());
}

state->vm()->metrics().system.fibers_created++;

state->memory()->native_finalizer(state, fib,
18 changes: 18 additions & 0 deletions machine/builtin/fiber.hpp
Original file line number Diff line number Diff line change
@@ -8,6 +8,12 @@
#include "builtin/exception.hpp"
#include "builtin/lookup_table.hpp"
#include "builtin/object.hpp"
#include "builtin/string.hpp"

#include "instruments/timing.hpp"

#include <stdint.h>
#include <atomic>

namespace rubinius {
class LookupTable;
@@ -16,6 +22,8 @@ namespace rubinius {
public:
const static object_type type = FiberType;

static std::atomic<uint32_t> fiber_ids_;

enum Status {
eNotStarted, eSleeping, eRunning, eDead
};
@@ -27,11 +35,15 @@ namespace rubinius {
attr_accessor(locals, LookupTable);
attr_accessor(dead, Object);
attr_accessor(stack_size, Fixnum);
attr_accessor(thread_name, String);
attr_accessor(fiber_id, Fixnum);
attr_accessor(source, String);

private:
attr_field(status, Status);
attr_field(root, bool);
attr_field(data, FiberData*);
attr_field(start_time, uint64_t);

public:
bool root_p() const {
@@ -84,15 +96,21 @@ namespace rubinius {
obj->locals(nil<LookupTable>());
obj->dead(nil<Object>());
obj->stack_size(Fixnum::from(state->shared().config.machine_fiber_stack_size.value));
obj->thread_name(String::create(state, state->vm()->name().c_str()));
obj->fiber_id(Fixnum::from(++Fiber::fiber_ids_));
obj->source(nil<String>());
obj->status(eNotStarted);
obj->root(false);
obj->data(NULL);
obj->start_time(get_current_time());
}

// Rubinius.primitive :fiber_new
static Fiber* create(STATE, Object* self, Object* stack_size, Object* callable);
static void start_on_stack();

double run_time();

// Rubinius.primitive :fiber_s_current
static Fiber* current(STATE);

16 changes: 8 additions & 8 deletions machine/builtin/system.cpp
Original file line number Diff line number Diff line change
@@ -486,13 +486,13 @@ namespace rubinius {
close(errors[1]);

if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
logger::write("spawn: %d: %s, %s, %s:%d",
logger::write("process: spawn: %d: %s, %s, %s:%d",
pid, exe.command(),
state->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
} else {
logger::write("spawn: %d: %s, %s",
logger::write("process: spawn: %d: %s, %s",
pid, exe.command(),
state->vm()->name().c_str());
}
@@ -606,13 +606,13 @@ namespace rubinius {
close(output[1]);

if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
logger::write("backtick: %d: %s, %s, %s:%d",
logger::write("process: backtick: %d: %s, %s, %s:%d",
pid, exe.command(),
state->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
} else {
logger::write("backtick: %d: %s, %s",
logger::write("process: backtick: %d: %s, %s",
pid, exe.command(),
state->vm()->name().c_str());
}
@@ -690,12 +690,12 @@ namespace rubinius {
ExecCommand exe(state, path, args);

if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
logger::write("exec: %s, %s, %s:%d", exe.command(),
logger::write("process: exec: %s, %s, %s:%d", exe.command(),
state->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
} else {
logger::write("exec: %s, %s", exe.command(),
logger::write("process: exec: %s, %s", exe.command(),
state->vm()->name().c_str());
}

@@ -844,12 +844,12 @@ namespace rubinius {
state->shared().machine_threads()->after_fork_parent(state);

if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
logger::write("fork: child: %d, %s, %s:%d", pid,
logger::write("process: fork: child: %d, %s, %s:%d", pid,
state->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
} else {
logger::write("fork: child: %d, %s", pid,
logger::write("process: fork: child: %d, %s", pid,
state->vm()->name().c_str());
}
} else if(pid == 0) {
41 changes: 29 additions & 12 deletions machine/builtin/thread.cpp
Original file line number Diff line number Diff line change
@@ -29,6 +29,9 @@

#include "missing/gettid.h"

#include <ostream>
#include <string>

/* HACK: returns a value that should identify a native thread
* for debugging threading issues. The winpthreads library
* defines pthread_t to be a structure not a pointer.
@@ -152,12 +155,19 @@ namespace rubinius {
thread->stack_size(state, size);
}

CallFrame* call_frame = state->vm()->get_ruby_frame(1);
if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
std::ostringstream source;

source << call_frame->file(state)->cpp_str(state).c_str()
<< ":" << call_frame->line(state);

logger::write("thread: new: %s, %s",
thread->vm()->name().c_str(), source.str().c_str());

logger::write("new thread: %s, %s:%d",
thread->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
thread->source(state, String::create(state, source.str().c_str()));
} else {
logger::write("thread: new: %s", thread->vm()->name().c_str());
}

if(!thread->send(state, state->symbol("initialize"), args, block, true)) {
thread->vm()->set_zombie(state);
@@ -178,12 +188,19 @@ namespace rubinius {
thread->stack_size(state, size);
}

CallFrame* call_frame = state->vm()->get_ruby_frame(1);
if(CallFrame* call_frame = state->vm()->get_noncore_frame(state)) {
std::ostringstream source;

logger::write("start thread: %s, %s:%d",
thread->vm()->name().c_str(),
call_frame->file(state)->cpp_str(state).c_str(),
call_frame->line(state));
source << call_frame->file(state)->cpp_str(state).c_str()
<< ":" << call_frame->line(state);

logger::write("thread: start: %s, %s",
thread->vm()->name().c_str(), source.str().c_str());

thread->source(state, String::create(state, source.str().c_str()));
} else {
logger::write("thread: start: %s", thread->vm()->name().c_str());
}

if(!thread->send(state, state->symbol("__thread_initialize__"), args, block, true)) {
thread->vm()->set_zombie(state);
@@ -380,7 +397,7 @@ namespace rubinius {

vm->thread->pid(state, Fixnum::from(gettid()));

logger::write("start thread: %s, %d, %#x",
logger::write("thread: run: %s, %d, %#x",
vm->name().c_str(), vm->thread->pid()->to_native(),
(unsigned int)thread_debug_self());

@@ -410,7 +427,7 @@ namespace rubinius {

NativeMethod::cleanup_thread(state);

logger::write("exit thread: %s %fs", vm->name().c_str(), vm->run_time());
logger::write("thread: exit: %s %fs", vm->name().c_str(), vm->run_time());

vm->unmanaged_phase();

2 changes: 2 additions & 0 deletions machine/builtin/thread.hpp
Original file line number Diff line number Diff line change
@@ -42,6 +42,7 @@ namespace rubinius {
attr_accessor(pid, Fixnum);
attr_accessor(initialized, Object);
attr_accessor(stack_size, Fixnum);
attr_accessor(source, String);

private:
utilities::thread::SpinLock init_lock_;
@@ -76,6 +77,7 @@ namespace rubinius {
obj->pid(Fixnum::from(0));
obj->initialized(cFalse);
obj->stack_size(Fixnum::from(state->shared().config.machine_thread_stack_size.value));
obj->source(nil<String>());

obj->init_lock_.init();
obj->join_lock_.init();
6 changes: 3 additions & 3 deletions machine/environment.cpp
Original file line number Diff line number Diff line change
@@ -532,7 +532,7 @@ namespace rubinius {
void Environment::halt(STATE, int exit_code) {
utilities::thread::Mutex::LockGuard guard(halt_lock_);

logger::write("exit process: %s %d %fs",
logger::write("process: exit: %s %d %fs",
shared->pid.c_str(), exit_code, shared->run_time());

if(Memory* om = state->memory()) {
@@ -568,12 +568,12 @@ namespace rubinius {
void Environment::load_core(STATE, std::string root) {
try {
if(CodeDB::valid_database_p(state, config.codedb_core_path.value)) {
logger::write("loading CodeDB: %s", config.codedb_core_path.value.c_str());
logger::write("codedb: loading: %s", config.codedb_core_path.value.c_str());
CodeDB::open(state, config.codedb_core_path.value.c_str());
} else {
std::string core = root + "/core";

logger::write("loading CodeDB: %s", core.c_str());
logger::write("codedb: loading: %s", core.c_str());
CodeDB::open(state, core.c_str());
}
} catch(RubyException& exc) {
2 changes: 2 additions & 0 deletions machine/memory/finalizer.cpp
Original file line number Diff line number Diff line change
@@ -175,6 +175,7 @@ namespace rubinius {
MachineThread::wakeup(state);

while(thread_running_) {
std::lock_guard<std::mutex> guard(synchronization_->list_mutex());
synchronization_->list_condition().notify_one();
}
}
@@ -336,6 +337,7 @@ namespace rubinius {
fo->mark(gc);
}

std::lock_guard<std::mutex> guard(synchronization_->list_mutex());
synchronization_->list_condition().notify_one();
}
}