A new logger arrives

As Crimild moves towards a parallel architecture, several design problems are starting to appear due to processes running concurrently (and because my past-self was quite lazy to think about that when design some of the most important parts of the engine).

For example, after spending A LOT of time trying to find out the cause of a what appeared to be a strange behavior in the rendering pass, I realized that there was no problem at all. Instead, the logger itself was buggy and the reason for it was that the logger wasn’t thread-safe. Then, log messages were mixed together between threads making it look like a problem in another place:

screen-shot-2016-12-13-at-1-35-23-pm

The worst part was that I KNEW the logger was not thread-safe from the moment I designed it years ago (like I said, lazy programmer). It just happened that I forgot about that small detail.

A new logger was needed.

A more powerful, stable and, of course, thread-safe logger.

And so, after some rethinking and refactoring, this happened:

Log::debug( “BLOG”, “Hello New Logger” );

Yes, that’s it. What were you expecting? It’s just a logger after all.

Anyway, the line above produces the following output:

12345621313 0x2213133 D/BLOG - Hello New Logger

There’s a lot of information in there:

  • Timestamp (in microseconds)
  • Thread ID
  • Log Level (‘D’ for ‘Debug’)
  • Log Tag (‘BLOG’)
  • The actual message (“Hello…”)

If you’re thinking that it looks like the kind of logs produced by the Android Monitor, you’re right. That was one of the basis for the new logger.

The logger also support enabling or disabling levels with a single flag (instead of having to disable individual ones), and the tag argument is useful for filtering. About tags, there’s also a new function (disguised as a macro) to get the class name from within a member function. Check this out:

void StreamingSystem::loadScene( std::string filename, SceneBuilder *builder )
{
   // ...
   Log::error( CRIMILD_CURRENT_CLASS_NAME, "Undefined scene builder" );
   // ...
}

The line above will output something like this:

12345627214 0x2213215 E/crimild::StreamingSystem - Undefined scene builder

Of course, you can use the tag as you please.

This new logger is implemented using C++11 variadic templates. I preferred this method over the typical printf-like one since it allow us to pass objects (as long as they overload the flux operator) instead of having to work with individual values.

Concerning concurrency (that was the whole point of this, right?), the logger is designed so that only one lock is required at the top-most level, right when we’re printing the message (for example, to the standard output). That way, mutexes are used only when needed.

 class ConsoleOutputHandler : public OutputHandler {
 public:
    ConsoleOutputHandler( void ) { }
    virtual ~ConsoleOutputHandler( void ) { }
 
    virtual void printLine( std::string const &line ) override
    {
       std::lock_guard< std::mutex > lock( _mutex );
       std::cout << line << "\n";
    }
 
 private:
    std::mutex _mutex;
 };

Well, that’s it for the logger. I just pushed the new code to the devel branch in Github if you want to take a look at it. And while you’re at it, there might be a little Christmas present there too a little ahead of schedule 😉

Happy Holidays!

 

Progress Update – November 2016

This post summarizes all the things I’m currently working on, without any specific priority order (as usual).

Job System

Probably the biggest feature to be included in the next release (whenever that happens) is the new Job System.

Last year I implemented a Task Scheduler for asynchronous work and while it is (was?) useful, it does lack the mechanisms required for programs to properly work concurrently. In particular, there’s no way to wait for tasks to complete or group them together as one unit of work.

Enters the new Job System, in which we’re going to be able to schedule jobs (obviously), that may or may not be linked with other jobs (as in parent/child jobs) and wait for them to complete before continuing. A “work stealing” approach is being used internally and we can spawn as many worker threads as we need.

The new Job System will allow us to move to a more parallel architecture by implementing things like parallel visitors, multi-threaded render queues and more.

Surprisingly, the current state of this feature is quite advanced and looking good. I just pushed the main classes to the development branch and I expect to refactor the Simulation flow pretty soon.

Ray Tracer Improvements

I needed a way to test the new Job System before having to refactor the entire Simulation flow and the Ray Tracer seemed to be the perfect candidate.

Initial tests are promising, showing that the rendering time has been reduced by 60% (depending on the number of worker threads, of course). The image below took “only” 80 minutes to render in my Macbook using 8 worker threads.

output_800_600_100

I’ve included several fixes in the latest code and I’m going to move to phase two (actual geometry, lighting, textures, etc) probably before the end of the year.

Scripting

As it is right now, the scripting system is mostly used for scene building, specifying objects and components in script files using Lua. But I want more. I need more. I want to be able to create components from Lua files and interact between them and first class ones written in C++. I want to be able to create a whole new simulation or game without enforcing the developer to write and compile C++ code.

The improved scripting tools are still in a design phase and even when I would like to include them in the next release, I know they might not make it.

Improving Audio Support

This is something that I had in my list for a while and I’m giving it a try as a side project. At the moment, Crimild supports audio clips using OpenAL (including positional audio, of course) only in WAV format and there’s no way to play background music.

My initial goal is to work with OGG files. By the end of phase one I should be able not only to play music files but also to support some simple mixing mechanisms.

I don’t expect this feature to be included in the next release, but it should be done early next year because it’s something that I need for a different, super secret, project.

Scene Streaming

Yes, this is back. You know, that super useful thing let you save and load entire scenes to disk, using a binary file format (which was there five years ago but then disappeared one day without reason).

A working implementation for scene streaming was included in the last version (I’m not kidding, it’s there). I’m constantly revisiting it by adding support for more components and entities. The new binary file format has proven quite good, and loading times have been reduced in a great amount.

That’s it. Well, not really. There might be one or two more things in my TODO list right now, but the ones above are the most important ones. I’m planning on having a new release before the year’s done, including most of these features. So, stay tuned.

 

Going Parallel: Overture

Early this year I implemented basic multithreading support for simulations by having two threads running in parallel: the main one dealing with processing the rendering queue, while the simulation was running in the background. That was a straightforward approach and made the system more efficient, but it was hardly the best solution.

I’ve been reading a lot about concurrency lately and I wanted to give it a try, knowing that it might end up in a disaster. Truth be said, Crimild is far from being concurrency friendly, having a lot of shared, mutable data. Surprisingly, things seems to be working great so far

I’m going to write more about how the new implementation works in the future (that is, once I understand what I’m actually doing ;)). For the moment I’m just going to say that it looks promising. I know that this is going to be a long process if I want Crimild to be fully parallel (which might involve a bit of paradigm shifting), so I expect to have a lot of trial and error.

Here’s a quick look at something I’m working on right now. One of my goals is to provide a set of tools to write parallel code the easy way. For example, if a programmer needs to perform a computation in background, now he can use the newly crimild::async function, like this:

crimild::async( []() {
// do something in background
});

It may look like C++x11 std::async function but, instead of spawning new threads, crimild::async pushes tasks to the new Task Manager, which in turn executes them in parallel following a job stealing strategy.

Current implementation includes a way to provide scheduling hints when invoking crimild::async, like whether or not to run the task in the main thread, and a future-ish way to serialize task calls.

crimild::async( 
   crimild::AsyncDispatchPolicy::MAIN_QUEUE, 
   []() {
       // execute something in main queue
   },
   []() {
       // execute this code once the task is completed
   });

Before I go, here’s how the new implementation is working on Windows. Notice that it’s using four processors instead of two:

concurrency

It’s not using every available resource yet since there aren’t many parallel tasks, but that’s going to change soon. But first, I need to improve the Profiler…

Wish me luck