More sophisticated logging system.

Can pipe logs from C++ into Python's logging (but not yet in a way
that is suitable for the performance thread).
looper
Ben Niemann 5 years ago
parent 4470d25007
commit 8373f0a636
  1. 9
      NOTES.org
  2. 3
      bin/runtests.py
  3. 7
      noisicaa/core/CMakeLists.txt
  4. 3
      noisicaa/core/__init__.py
  5. 120
      noisicaa/core/logging.cpp
  6. 106
      noisicaa/core/logging.h
  7. 34
      noisicaa/core/logging.pxd
  8. 21
      noisicaa/core/logging.pyx
  9. 42
      noisicaa/core/logging_test.pyx
  10. 4
      noisicaa/editor_main.py
  11. 13
      noisicore/audio_stream.cpp
  12. 4
      noisicore/audio_stream.h
  13. 5
      noisicore/backend.cpp
  14. 4
      noisicore/backend.h
  15. 4
      noisicore/backend_ipc.cpp
  16. 2
      noisicore/backend_null.cpp
  17. 10
      noisicore/backend_portaudio.cpp
  18. 15
      noisicore/misc.cpp
  19. 6
      noisicore/misc.h
  20. 6
      noisicore/opcodes.cpp
  21. 11
      noisicore/processor.cpp
  22. 4
      noisicore/processor.h
  23. 16
      noisicore/processor_csound.cpp
  24. 2
      noisicore/processor_csound.h
  25. 12
      noisicore/processor_fluidsynth.cpp
  26. 6
      noisicore/processor_ipc.cpp
  27. 2
      noisicore/processor_ladspa.cpp
  28. 2
      noisicore/processor_lv2.cpp
  29. 2
      noisicore/processor_null.cpp
  30. 24
      noisicore/vm.cpp
  31. 8
      noisicore/vm.h

@ -1,13 +1,16 @@
# -*- org-tags-column: -98 -*-
* VM-based pipeline engine :FR:
- playback becomes slower over time...
- reimplement sample_player
- playback becomes slower over time...
- Better handling of partial blocks in player
- control/sample tracks should always produce complete blocks, padded with zeros
- currently produces a short buffer at end of playback (triggering an assert in the VM)
- capture fluidsynth logs
- capture csound logs
- Properly handle stopped backend
- Hook up log with python logging
- should have a lockfree queue in-between
- Put a lockfree queue between C++ logging and Python logging
- only need that in the performance thread...
- capnp API is really awful. strongly consider rolling a custom format for FrameData
- are there any other places, where I care about zero-copy deserialization?
- get rid of AST

@ -94,6 +94,9 @@ def main(argv):
constants.TEST_OPTS.WRITE_PERF_STATS = args.write_perf_stats
constants.TEST_OPTS.ENABLE_PROFILER = args.profile
from noisicaa import core
core.init_pylogging()
loader = unittest.defaultTestLoader
suite = unittest.TestSuite()

@ -18,7 +18,11 @@ add_python_package(
storage_test.py
)
add_cython_module(logging_test CXX)
target_link_libraries(${logging_test.so} PRIVATE noisicaa-core)
set(LIB_SRCS
logging.cpp
perf_stats.cpp
)
@ -32,4 +36,7 @@ add_library(noisicaa-core SHARED ${LIB_SRCS} message.capnp.c++ perf_stats.capnp.
add_cython_module(perf_stats CXX)
target_link_libraries(${perf_stats.so} PRIVATE noisicaa-core)
add_cython_module(logging CXX)
target_link_libraries(${logging.so} PRIVATE noisicaa-core)
add_subdirectory(stats)

@ -27,3 +27,6 @@ from .message import (
MessageType,
MessageKey,
)
from .logging import (
init_pylogging,
)

@ -0,0 +1,120 @@
#include <assert.h>
#include <stdio.h>
#include <string.h>
#include "noisicaa/core/logging.h"
namespace noisicaa {
LogSink::~LogSink() {}
StdIOSink::StdIOSink(FILE* fp)
: _fp(fp) {}
void StdIOSink::emit(const char* logger, LogLevel level, const char* msg) {
// TODO: make this thread safe
switch (level) {
case LogLevel::DEBUG: fwrite("DEBUG:", 1, 6, _fp); break;
case LogLevel::INFO: fwrite("INFO:", 1, 5, _fp); break;
case LogLevel::WARNING: fwrite("WARNING:", 1, 8, _fp); break;
case LogLevel::ERROR: fwrite("ERROR:", 1, 6, _fp); break;
}
fwrite(logger, 1, strlen(logger), _fp);
fwrite(":", 1, 1, _fp);
fwrite(msg, 1, strlen(msg), _fp);
fwrite("\n", 1, 1, _fp);
fflush(_fp);
}
PyLogSink::PyLogSink(void* handle, callback_t callback)
: _handle(handle),
_callback(callback) {}
void PyLogSink::emit(const char* logger, LogLevel level, const char* msg) {
_callback(_handle, logger, level, msg);
}
Logger::Logger(const char* name, LoggerRegistry* registry)
: _registry(registry) {
assert(strlen(name) < NAME_LENGTH - 1);
strncpy(_name, name, NAME_LENGTH);
}
void Logger::vlog(LogLevel level, const char* fmt, va_list args) {
char msg[10000];
vsnprintf(msg, sizeof(msg), fmt, args);
_registry->sink()->emit(_name, level, msg);
}
void Logger::log(LogLevel level, const char* fmt, ...) {
va_list args;
va_start(args, fmt);
vlog(level, fmt, args);
va_end(args);
}
void Logger::debug(const char* fmt, ...) {
va_list args;
va_start(args, fmt);
vlog(LogLevel::DEBUG, fmt, args);
va_end(args);
}
void Logger::info(const char* fmt, ...) {
va_list args;
va_start(args, fmt);
vlog(LogLevel::INFO, fmt, args);
va_end(args);
}
void Logger::warning(const char* fmt, ...) {
va_list args;
va_start(args, fmt);
vlog(LogLevel::WARNING, fmt, args);
va_end(args);
}
void Logger::error(const char* fmt, ...) {
va_list args;
va_start(args, fmt);
vlog(LogLevel::ERROR, fmt, args);
va_end(args);
}
LoggerRegistry::LoggerRegistry() {}
LoggerRegistry* LoggerRegistry::_instance = nullptr;
LoggerRegistry* LoggerRegistry::get_registry() {
// TODO: make this thread safe
if (_instance == nullptr) {
_instance = new LoggerRegistry();
}
return _instance;
}
Logger* LoggerRegistry::_get_logger(const char *name) {
const auto& it = _loggers.find(name);
if (it != _loggers.end()) {
return it->second.get();
}
if (_sink.get() == nullptr) {
_sink.reset(new StdIOSink(stderr));
}
Logger* logger = new Logger(name, this);
_loggers.emplace(logger->name(), logger);
return logger;
}
void LoggerRegistry::set_sink(LogSink* sink) {
_sink.reset(sink);
}
bool LoggerRegistry::cmp_cstr::operator()(const char *a, const char *b) {
return strcmp(a, b) < 0;
}
}

@ -0,0 +1,106 @@
// -*- mode: c++ -*-
#ifndef _NOISICORE_LOGGING_H
#define _NOISICORE_LOGGING_H
#include <map>
#include <memory>
#include <stdarg.h>
namespace noisicaa {
using namespace std;
class LoggerRegistry;
enum LogLevel {
DEBUG, INFO, WARNING, ERROR
};
struct LogRecord {
LogLevel level;
size_t logger_length;
size_t msg_length;
char data[];
};
class LogSink {
public:
~LogSink();
virtual void emit(const char* logger, LogLevel level, const char* msg) = 0;
};
class StdIOSink : public LogSink {
public:
StdIOSink(FILE* fp);
void emit(const char* logger, LogLevel level, const char* msg) override;
private:
FILE* _fp;
};
class PyLogSink : public LogSink {
public:
typedef void (*callback_t)(void*, const char*, LogLevel, const char*);
PyLogSink(void* handle, callback_t callback);
void emit(const char* logger, LogLevel level, const char* msg) override;
private:
void* _handle;
callback_t _callback;
};
class Logger {
public:
static const size_t NAME_LENGTH = 128;
Logger(const char* name, LoggerRegistry* registry);
const char* name() const { return _name; }
void vlog(LogLevel level, const char* fmt, va_list args);
void log(LogLevel level, const char* fmt, ...);
void debug(const char* fmt, ...);
void info(const char* fmt, ...);
void warning(const char* fmt, ...);
void error(const char* fmt, ...);
private:
char _name[NAME_LENGTH];
LoggerRegistry* _registry;
};
class LoggerRegistry {
public:
// You shouldn't create instances yourself, use get_registry() to get a singleton instance.
// This constructor is only public for use by unittests.
LoggerRegistry();
static LoggerRegistry* get_registry();
static void reset();
static Logger* get_logger(const char* name) {
return get_registry()->_get_logger(name);
}
LogSink* sink() const { return _sink.get(); }
void set_sink(LogSink* sink);
private:
static LoggerRegistry* _instance;
Logger* _get_logger(const char* name);
struct cmp_cstr {
bool operator()(const char *a, const char *b);
};
map<const char*, unique_ptr<Logger>, cmp_cstr> _loggers;
unique_ptr<LogSink> _sink;
};
} // namespace noisicaa
#endif

@ -0,0 +1,34 @@
cdef extern from "noisicaa/core/logging.h" namespace "noisicaa" nogil:
enum LogLevel:
DEBUG
INFO
WARNING
ERROR
cppclass LoggerRegistry
cppclass Logger:
Logger(const char* name, LoggerRegistry* registry)
void log(LogLevel level, const char* fmt, ...)
void debug(const char* fmt, ...)
void info(const char* fmt, ...)
void warning(const char* fmt, ...)
void error(const char* fmt, ...)
cppclass LogSink:
void emit(const char* logger, LogLevel level, const char* msg)
cppclass PyLogSink(LogSink):
ctypedef void (*callback_t)(void*, const char*, LogLevel, const char*)
PyLogSink(void* handle, callback_t callback)
void emit(const char* logger, LogLevel level, const char* msg)
cppclass LoggerRegistry:
@staticmethod
LoggerRegistry* get_registry()
@staticmethod
Logger* get_logger(const char* name)
void set_sink(LogSink* sink)

@ -0,0 +1,21 @@
import logging
cdef void pylogging_cb(
void* handle, const char* c_logger, LogLevel c_level, const char* c_msg) with gil:
logger = bytes(c_logger).decode('utf-8')
level = {
LogLevel.DEBUG: logging.DEBUG,
LogLevel.INFO: logging.INFO,
LogLevel.WARNING: logging.WARNING,
LogLevel.ERROR: logging.ERROR,
}[c_level]
msg = bytes(c_msg).decode('utf-8')
logger = logging.getLogger(logger)
logger.log(level, msg)
def init_pylogging():
cdef LogSink* sink = new PyLogSink(NULL, pylogging_cb)
LoggerRegistry.get_registry().set_sink(sink)

@ -0,0 +1,42 @@
from cpython.ref cimport PyObject
from libcpp.memory cimport unique_ptr
from .logging cimport *
from .logging import *
import unittest
cdef void cb_proxy(void* handle, const char* logger, LogLevel level, const char* msg) with gil:
cdef object handler = <object>handle
handler(logger, level, msg)
class TestLogging(unittest.TestCase):
def test_callback(self):
cdef unique_ptr[LoggerRegistry] registry_ptr
registry_ptr.reset(new LoggerRegistry())
cdef LoggerRegistry* registry = registry_ptr.get()
msgs = []
def cb(logger, level, msg):
msgs.append((logger, level, msg))
cdef LogSink* sink = new PyLogSink(<PyObject*>cb, cb_proxy)
registry.set_sink(sink)
cdef unique_ptr[Logger] logger_ptr
logger_ptr.reset(new Logger(b"noisicaa.core.logger_test.callback", registry))
cdef Logger* logger = logger_ptr.get()
logger.debug("debug %d", 1)
logger.info("informational %d", 2)
logger.warning("warning %d", 3)
logger.error("error %d", 4)
self.assertEqual(
msgs,
[(b"noisicaa.core.logger_test.callback", LogLevel.DEBUG, b"debug 1"),
(b"noisicaa.core.logger_test.callback", LogLevel.INFO, b"informational 2"),
(b"noisicaa.core.logger_test.callback", LogLevel.WARNING, b"warning 3"),
(b"noisicaa.core.logger_test.callback", LogLevel.ERROR, b"error 4")])

@ -10,7 +10,7 @@ import time
from .constants import EXIT_SUCCESS, EXIT_RESTART, EXIT_RESTART_CLEAN
from .runtime_settings import RuntimeSettings
from . import logging
from .core import process_manager
from .core import process_manager, init_pylogging
# # Unload all noisicaa modules, so that every subprocess reloads everything
# # from scratch again.
@ -54,6 +54,8 @@ class Editor(object):
self.event_loop.add_signal_handler(
sig, functools.partial(self.handle_signal, sig))
init_pylogging()
try:
self.event_loop.run_until_complete(self.run_async())
finally:

@ -27,8 +27,9 @@ Status set_blocking(int fd, int blocking) {
namespace noisicaa {
AudioStreamBase::AudioStreamBase(const string& address)
: _address(address) {}
AudioStreamBase::AudioStreamBase(const char* logger_name, const string& address)
: _logger(LoggerRegistry::get_logger(logger_name)),
_address(address) {}
AudioStreamBase::~AudioStreamBase() {
cleanup();
@ -60,7 +61,7 @@ Status AudioStreamBase::fill_buffer() {
_buffer.append(buf, num_bytes);
return Status::Ok();
} else if (fds.revents & POLLHUP) {
log(LogLevel::WARNING, "Pipe disconnected");
_logger->warning("Pipe disconnected");
return Status::ConnectionClosed();
}
@ -147,7 +148,7 @@ Status AudioStreamBase::send_block(const capnp::BlockData::Builder& block) {
}
AudioStreamServer::AudioStreamServer(const string& address)
: AudioStreamBase(address) {}
: AudioStreamBase("noisicore.audio_stream.server", address) {}
Status AudioStreamServer::setup() {
// logger.info("Serving from %s", self._address)
@ -208,7 +209,7 @@ void AudioStreamServer::cleanup() {
}
AudioStreamClient::AudioStreamClient(const string& address)
: AudioStreamBase(address) {}
: AudioStreamBase("noisicore.audio_stream.client", address) {}
Status AudioStreamClient::setup() {
// logger.info("Connecting to %s...", self._address)
@ -242,7 +243,7 @@ void AudioStreamClient::cleanup() {
while (request.size() > 0) {
ssize_t bytes_written = write(_pipe_out, request.c_str(), request.size());
if (bytes_written < 0) {
log(LogLevel::ERROR, "Failed to write to pipe.");
_logger->error("Failed to write to pipe.");
break;
}
request.erase(0, bytes_written);

@ -6,6 +6,7 @@
#include <stdint.h>
#include <capnp/message.h>
#include <capnp/serialize.h>
#include "noisicaa/core/logging.h"
#include "noisicore/status.h"
#include "noisicore/block_data.capnp.h"
@ -15,7 +16,7 @@ using namespace std;
class AudioStreamBase {
public:
AudioStreamBase(const string& address);
AudioStreamBase(const char* logger_name, const string& address);
virtual ~AudioStreamBase();
virtual Status setup();
@ -34,6 +35,7 @@ public:
Status send_block(const capnp::BlockData::Builder& builder);
protected:
Logger* _logger;
string _address;
int _pipe_in = -1;
int _pipe_out = -1;

@ -6,8 +6,9 @@
namespace noisicaa {
Backend::Backend(const BackendSettings& settings)
: _settings(settings) {}
Backend::Backend(const char* logger_name, const BackendSettings& settings)
: _logger(LoggerRegistry::get_logger(logger_name)),
_settings(settings) {}
Backend::~Backend() {
cleanup();

@ -4,6 +4,7 @@
#define _NOISICORE_BACKEND_H
#include <string>
#include "noisicaa/core/logging.h"
#include "noisicore/status.h"
#include "noisicore/buffers.h"
@ -34,8 +35,9 @@ public:
virtual Status output(BlockContext* ctxt, const string& channel, BufferPtr samples) = 0;
protected:
Backend(const BackendSettings& settings);
Backend(const char* logger_name, const BackendSettings& settings);
Logger* _logger;
BackendSettings _settings;
VM* _vm = nullptr;
};

@ -8,7 +8,7 @@
namespace noisicaa {
IPCBackend::IPCBackend(const BackendSettings& settings)
: Backend(settings),
: Backend("noisicore.backend.ipc", settings),
_block_size(settings.block_size) {}
IPCBackend::~IPCBackend() {}
@ -81,7 +81,7 @@ Status IPCBackend::begin_block(BlockContext* ctxt) {
if (_block_size != request.getBlockSize()) {
PerfTracker tracker(ctxt->perf.get(), "resize_buffers");
log(LogLevel::INFO, "Block size changed %d -> %d", _block_size, request.getBlockSize());
_logger->info("Block size changed %d -> %d", _block_size, request.getBlockSize());
_block_size = request.getBlockSize();
for (int c = 0 ; c < 2 ; ++c) {
_samples[c].reset(new BufferData[_block_size * sizeof(float)]);

@ -5,7 +5,7 @@
namespace noisicaa {
NullBackend::NullBackend(const BackendSettings& settings)
: Backend(settings) {}
: Backend("noisicore.backend.null", settings) {}
NullBackend::~NullBackend() {}
Status NullBackend::setup(VM* vm) {

@ -6,7 +6,7 @@
namespace noisicaa {
PortAudioBackend::PortAudioBackend(const BackendSettings& settings)
: Backend(settings),
: Backend("noisicore.backend.portaudio", settings),
_initialized(false),
_block_size(settings.block_size),
_stream(nullptr),
@ -34,7 +34,7 @@ Status PortAudioBackend::setup(VM* vm) {
PaDeviceIndex device_index = Pa_GetDefaultOutputDevice();
const PaDeviceInfo* device_info = Pa_GetDeviceInfo(device_index);
log(LogLevel::INFO, "PortAudio device: %s", device_info->name);
_logger->info("PortAudio device: %s", device_info->name);
PaStreamParameters output_params;
output_params.device = device_index;
@ -83,7 +83,7 @@ void PortAudioBackend::cleanup() {
if (_stream != nullptr) {
PaError err = Pa_CloseStream(_stream);
if (err != paNoError) {
log(LogLevel::ERROR, "Failed to close portaudio stream: %s", Pa_GetErrorText(err));
_logger->error("Failed to close portaudio stream: %s", Pa_GetErrorText(err));
}
_stream = nullptr;
}
@ -91,7 +91,7 @@ void PortAudioBackend::cleanup() {
if (_initialized) {
PaError err = Pa_Terminate();
if (err != paNoError) {
log(LogLevel::ERROR, "Failed to terminate portaudio: %s", Pa_GetErrorText(err));
_logger->error("Failed to terminate portaudio: %s", Pa_GetErrorText(err));
}
_initialized = false;
}
@ -114,7 +114,7 @@ Status PortAudioBackend::end_block(BlockContext* ctxt) {
PaError err = Pa_WriteStream(_stream, _samples, _block_size);
if (err == paOutputUnderflowed) {
log(LogLevel::WARNING, "Buffer underrun.");
_logger->warning("Buffer underrun.");
} else if (err != paNoError) {
return Status::Error(
sprintf("Failed to write to portaudio stream: %s", Pa_GetErrorText(err)));

@ -17,19 +17,4 @@ string sprintf(const string &fmt, ...) {
return string(buf.get());
}
void log(LogLevel log_level, const char* fmt, ...) {
switch (log_level) {
case LogLevel::INFO: printf("INFO: "); break;
case LogLevel::WARNING: printf("WARNING: "); break;
case LogLevel::ERROR: printf("ERROR: "); break;
}
va_list args;
va_start(args, fmt);
std::vprintf(fmt, args);
std::printf("\n");
std::fflush(stdout);
}
}

@ -11,12 +11,6 @@ using namespace std;
string sprintf(const string& fmt, ...);
enum LogLevel {
INFO, WARNING, ERROR
};
void log(LogLevel log_level, const char* fmt, ...);
struct ScopeGuardBase {
ScopeGuardBase() : _active(true) {}

@ -71,7 +71,7 @@ Status run_FETCH_BUFFER(BlockContext* ctxt, ProgramState* state, const vector<Op
const auto& it = ctxt->buffers.find(in_buf_name);
if (it == ctxt->buffers.end()) {
log(LogLevel::WARNING, "Buffer %s not found in block context.", in_buf_name.c_str());
state->logger->warning("Buffer %s not found in block context.", in_buf_name.c_str());
out_buf->clear();
return Status::Ok();
}
@ -192,7 +192,7 @@ Status run_LOG_RMS(BlockContext* ctxt, ProgramState* state, const vector<OpArg>&
sum += data[i] * data[i];
}
log(LogLevel::INFO, "Block %d, rms=%.3f", idx, sum / ctxt->block_size);
state->logger->info("Block %d, rms=%.3f", idx, sum / ctxt->block_size);
return Status::Ok();
}
@ -208,7 +208,7 @@ Status run_LOG_ATOM(BlockContext* ctxt, ProgramState* state, const vector<OpArg>
LV2_Atom_Event* event = lv2_atom_sequence_begin(&seq->body);
while (!lv2_atom_sequence_is_end(&seq->body, seq->atom.size, event)) {
log(LogLevel::INFO, "Buffer %d, event %d @%d", idx, event->body.type, event->time.frames);
state->logger->info("Buffer %d, event %d @%d", idx, event->body.type, event->time.frames);
event = lv2_atom_sequence_next(event);
}

@ -12,8 +12,9 @@
namespace noisicaa {
Processor::Processor(HostData* host_data)
: _host_data(host_data),
Processor::Processor(const char* logger_name, HostData* host_data)
: _logger(LoggerRegistry::get_logger(logger_name)),
_host_data(host_data),
_id(Processor::new_id()) {
}
@ -76,7 +77,7 @@ Status Processor::set_string_parameter(const string& name, const string& value)
// sprintf("Parameter '%s' is not of type string.", name.c_str()));
// }
log(LogLevel::INFO, "Set parameter %s='%s'", name.c_str(), value.c_str());
_logger->info("Set parameter %s='%s'", name.c_str(), value.c_str());
_string_parameters[name] = value;
return Status::Ok();
@ -157,7 +158,7 @@ Status Processor::setup(const ProcessorSpec* spec) {
return Status::Error(sprintf("Processor %llx already set up.", id()));
}
log(LogLevel::INFO, "Setting up processor %llx.", id());
_logger->info("Setting up processor %llx.", id());
_spec.reset(spec_ptr.release());
return Status::Ok();
@ -166,7 +167,7 @@ Status Processor::setup(const ProcessorSpec* spec) {
void Processor::cleanup() {
if (_spec.get() != nullptr) {
_spec.reset();
log(LogLevel::INFO, "Processor %llx cleaned up.", id());
_logger->info("Processor %llx cleaned up.", id());
}
}

@ -7,6 +7,7 @@
#include <memory>
#include <string>
#include <stdint.h>
#include "noisicaa/core/logging.h"
#include "noisicore/status.h"
#include "noisicore/buffers.h"
#include "noisicore/block_context.h"
@ -20,7 +21,7 @@ class HostData;
class Processor {
public:
Processor(HostData* host_data);
Processor(const char* logger_name, HostData* host_data);
virtual ~Processor();
static StatusOr<Processor*> create(HostData* host_data, const string& name);
@ -43,6 +44,7 @@ public:
virtual Status run(BlockContext* ctxt) = 0;
protected:
Logger* _logger;
HostData* _host_data;
uint64_t _id;
unique_ptr<const ProcessorSpec> _spec;

@ -38,8 +38,8 @@ ProcessorCSoundBase::Instance::~Instance() {
}
}
ProcessorCSoundBase::ProcessorCSoundBase(HostData* host_data)
: Processor(host_data),
ProcessorCSoundBase::ProcessorCSoundBase(const char* logger_name, HostData* host_data)
: Processor(logger_name, host_data),
_next_instance(nullptr),
_current_instance(nullptr),
_old_instance(nullptr) {}
@ -71,7 +71,7 @@ Status ProcessorCSoundBase::set_code(const string& orchestra, const string& scor
return Status::Error(sprintf("Failed to set Csound options (code %d)", rc));
}
log(LogLevel::INFO, "csound orchestra:\n%s", orchestra.c_str());
_logger->info("csound orchestra:\n%s", orchestra.c_str());
rc = csoundCompileOrc(instance->csnd, orchestra.c_str());
if (rc < 0) {
return Status::Error(sprintf("Failed to compile Csound orchestra (code %d)", rc));
@ -82,7 +82,7 @@ Status ProcessorCSoundBase::set_code(const string& orchestra, const string& scor
return Status::Error(sprintf("Failed to start Csound (code %d)", rc));
}
log(LogLevel::INFO, "csound score:\n%s", score.c_str());
_logger->info("csound score:\n%s", score.c_str());
rc = csoundReadScore(instance->csnd, score.c_str());
if (rc < 0) {
return Status::Error(sprintf("Failed to read Csound score (code %d)", rc));
@ -312,10 +312,10 @@ Status ProcessorCSoundBase::run(BlockContext* ctxt) {
"csoundReadScore failed (code %d).", rc));
}
} else {
log(LogLevel::WARNING, "Ignoring unsupported midi event %d.", midi[0] & 0xf0);
_logger->warning("Ignoring unsupported midi event %d.", midi[0] & 0xf0);
}
} else {
log(LogLevel::WARNING, "Ignoring event %d in sequence.", atom.type);
_logger->warning("Ignoring event %d in sequence.", atom.type);
}
ep.event = lv2_atom_sequence_next(ep.event);
}
@ -378,7 +378,7 @@ Status ProcessorCSoundBase::run(BlockContext* ctxt) {
}
ProcessorCSound::ProcessorCSound(HostData *host_data)
: ProcessorCSoundBase(host_data) {}
: ProcessorCSoundBase("noisicore.processor.csound", host_data) {}
Status ProcessorCSound::setup(const ProcessorSpec* spec) {
Status status = ProcessorCSoundBase::setup(spec);
@ -404,7 +404,7 @@ void ProcessorCSound::cleanup() {
ProcessorCustomCSound::ProcessorCustomCSound(HostData *host_data)
: ProcessorCSoundBase(host_data) {}
: ProcessorCSoundBase("noisicore.processor.custom_csound", host_data) {}
Status ProcessorCustomCSound::setup(const ProcessorSpec* spec) {
Status status = ProcessorCSoundBase::setup(spec);

@ -23,7 +23,7 @@ class BlockContext;
class ProcessorCSoundBase : public Processor {
public:
ProcessorCSoundBase(HostData* host_data);
ProcessorCSoundBase(const char* logger_name, HostData* host_data);
~ProcessorCSoundBase() override;
Status setup(const ProcessorSpec* spec) override;

@ -6,7 +6,7 @@
namespace noisicaa {
ProcessorFluidSynth::ProcessorFluidSynth(HostData* host_data)
: Processor(host_data) {}
: Processor("noisicore.processor.fluidsynth", host_data) {}
ProcessorFluidSynth::~ProcessorFluidSynth() {}
@ -26,7 +26,7 @@ Status ProcessorFluidSynth::setup(const ProcessorSpec* spec) {
if (stor_preset.is_error()) { return stor_preset; }
int64_t preset = stor_preset.result();
log(LogLevel::INFO, "Setting up fluidsynth processor for %s, bank=%d, preset=%d",
_logger->info("Setting up fluidsynth processor for %s, bank=%d, preset=%d",
soundfont_path.c_str(), bank, preset);
_settings = new_fluid_settings();
@ -165,18 +165,18 @@ Status ProcessorFluidSynth::run(BlockContext* ctxt) {
if ((midi[0] & 0xf0) == 0x90) {
int rc = fluid_synth_noteon(_synth, 0, midi[1], midi[2]);
if (rc == FLUID_FAILED) {
log(LogLevel::WARNING, "noteon failed.");
_logger->warning("noteon failed.");
}
} else if ((midi[0] & 0xf0) == 0x80) {
int rc = fluid_synth_noteoff(_synth, 0, midi[1]);
if (rc == FLUID_FAILED) {
log(LogLevel::WARNING, "noteoff failed.");
_logger->warning("noteoff failed.");
}
} else {
log(LogLevel::WARNING, "Ignoring unsupported midi event %d.", midi[0] & 0xf0);
_logger->warning("Ignoring unsupported midi event %d.", midi[0] & 0xf0);
}
} else {
log(LogLevel::WARNING, "Ignoring event %d in sequence.", event->body.type);
_logger->warning("Ignoring event %d in sequence.", event->body.type);
}
event = lv2_atom_sequence_next(event);

@ -13,7 +13,7 @@
namespace noisicaa {
ProcessorIPC::ProcessorIPC(HostData* host_data)
: Processor(host_data) {}
: Processor("noisicore.processor.ipc", host_data) {}
ProcessorIPC::~ProcessorIPC() {}
@ -96,7 +96,7 @@ Status ProcessorIPC::run(BlockContext* ctxt) {
} else if (buffer.getId() == "output:1") {
p = 1;
} else {
log(LogLevel::WARNING, "Ignoring unexpected buffer %s", buffer.getId().cStr());
_logger->warning("Ignoring unexpected buffer %s", buffer.getId().cStr());
continue;
}
@ -107,7 +107,7 @@ Status ProcessorIPC::run(BlockContext* ctxt) {
for (int p = 0 ; p < 2 ; ++p) {
if (!ports_written[p]) {
log(LogLevel::WARNING, "Expected buffer output:%d not received", p);
_logger->warning("Expected buffer output:%d not received", p);
memset(_ports[p], 0, ctxt->block_size * sizeof(float));
}
}

@ -7,7 +7,7 @@
namespace noisicaa {
ProcessorLadspa::ProcessorLadspa(HostData* host_data)
: Processor(host_data) {}
: Processor("noisicore.processor.ladspa", host_data) {}
ProcessorLadspa::~ProcessorLadspa() {}

@ -10,7 +10,7 @@
namespace noisicaa {
ProcessorLV2::ProcessorLV2(HostData* host_data)
: Processor(host_data) {}
: Processor("noisicore.processor.lv2", host_data) {}
ProcessorLV2::~ProcessorLV2() {}

@ -3,7 +3,7 @@
namespace noisicaa {
ProcessorNull::ProcessorNull(HostData* host_data)
: Processor(host_data) {}
: Processor("noisicore.processor.null", host_data) {}
ProcessorNull::~ProcessorNull() {}
Status ProcessorNull::setup(const ProcessorSpec* spec) {

@ -14,12 +14,14 @@
namespace noisicaa {
Program::Program(uint32_t version) : version(version) {
log(LogLevel::INFO, "Created program v%d", version);
Program::Program(Logger* logger, uint32_t version)
: version(version),
_logger(logger) {
_logger->info("Created program v%d", version);
}
Program::~Program() {
log(LogLevel::INFO, "Deleted program v%d", version);
_logger->info("Deleted program v%d", version);
}
Status Program::setup(HostData* host_data, const Spec* s, uint32_t block_size) {
@ -37,7 +39,8 @@ Status Program::setup(HostData* host_data, const Spec* s, uint32_t block_size) {
}
VM::VM(HostData* host_data)
: _host_data(host_data),
: _logger(LoggerRegistry::get_logger("noisicore.vm")),
_host_data(host_data),
_block_size(256),
_next_program(nullptr),
_current_program(nullptr),
@ -80,7 +83,7 @@ Status VM::set_block_size(uint32_t block_size) {
}
Status VM::set_spec(const Spec* spec) {
unique_ptr<Program> program(new Program(_program_version++));
unique_ptr<Program> program(new Program(_logger, _program_version++));
Status status = program->setup(_host_data, spec, _block_size);
if (status.is_error()) { return status; }
@ -167,7 +170,7 @@ Status VM::process_block(BlockContext* ctxt) {
// been disposed of.
Program* program = _next_program.exchange(nullptr);
if (program != nullptr) {
log(LogLevel::INFO, "Activate program v%d", program->version);
_logger->info("Activate program v%d", program->version);
Program* old_program = _current_program.exchange(program);
old_program = _old_program.exchange(old_program);
assert(old_program == nullptr);
@ -190,7 +193,7 @@ Status VM::process_block(BlockContext* ctxt) {
auto end_block = scopeGuard([&]() {
Status status = backend->end_block(ctxt);
if (status.is_error()) {
log(LogLevel::ERROR, "Ignore error in Backend::end_block(): %s", status.message().c_str());
_logger->error("Ignore error in Backend::end_block(): %s", status.message().c_str());
}
});
@ -202,8 +205,7 @@ Status VM::process_block(BlockContext* ctxt) {
uint32_t new_block_size = _block_size.load();
if (new_block_size != program->block_size) {
log(LogLevel::INFO,
"Block size changed %d -> %d", program->block_size, new_block_size);
_logger->info("Block size changed %d -> %d", program->block_size, new_block_size);
program->block_size = new_block_size;
for(auto& buf : program->buffers) {
@ -217,10 +219,10 @@ Status VM::process_block(BlockContext* ctxt) {
if (ctxt->block_size == 0) {
return Status::Error("Invalid block_size 0");
}
log(LogLevel::INFO, "Process block [%d,%d]", ctxt->sample_pos, ctxt->block_size);
_logger->debug("Process block [%d,%d]", ctxt->sample_pos, ctxt->block_size);
const Spec* spec = program->spec.get();
ProgramState state = { _host_data, program, backend, 0, false };
ProgramState state = { _logger, _host_data, program, backend, 0, false };
while (!state.end) {
if (state.p == spec->num_ops()) {
break;

@ -8,6 +8,7 @@
#include <string>
#include <vector>
#include <stdint.h>
#include "noisicaa/core/logging.h"
#include "noisicore/spec.h"
#include "noisicore/status.h"
#include "noisicore/processor.h"
@ -22,7 +23,7 @@ class HostData;
class Program {
public:
Program(uint32_t version);
Program(Logger* logger, uint32_t version);
~Program();
Status setup(HostData* host_data, const Spec* spec, uint32_t block_size);
@ -32,9 +33,13 @@ public:
unique_ptr<const Spec> spec;
uint32_t block_size;
vector<unique_ptr<Buffer>> buffers;
private:
Logger* _logger;
};
struct ProgramState {
Logger* logger;
HostData* host_data;
Program* program;
Backend* backend;
@ -68,6 +73,7 @@ public:
Buffer* get_buffer(const string& name);
private:
Logger* _logger;
HostData* _host_data;
atomic<uint32_t> _block_size;
atomic<Program*> _next_program;

Loading…
Cancel
Save