This post is a case study of an issue I faced in the form of a stuck Ruby micro-service. The Rails server would boot up and service requests for a while until it would stop responding.

The next problem was verification. How can we tell that the process is stuck? What are the conditions that contribute to it?

To verify that the process is indeed, stuck!

The primary characteristic of a stuck process is that it stops responding to interrupts, save the kill signal. Puma server has a well documented and robust interrupt behavior.

Lets send USR1 signal to the process to see what is the default behavior of Puma.

# IN TERMINAL A

master ● bundle exec rails s
=> Booting Puma
=> Rails 6.0.2.2 application starting in development
=> Run `rails server --help` for more startup options
Puma starting in single mode...
* Version 4.3.3 (ruby 2.7.0-p0), codename: Mysterious Traveller
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://127.0.0.1:3000
* Listening on tcp://[::1]:3000
Use Ctrl-C to stop

# IN TERMINAL B

● lsof -i tcp:3000 | tail -1 | cut -d' ' -f 5 
92187
● sudo kill -USR1 92187

# BACK IN TERMINAL A

...
* phased-restart called but not available, restarting normally.
* Restarting...
=> Booting Puma
=> Rails 6.0.2.2 application starting in development
=> Run `rails server --help` for more startup options
Puma starting in single mode...
* Version 4.3.3 (ruby 2.7.0-p0), codename: Mysterious Traveller
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://127.0.0.1:3000
* Listening on tcp://[::1]:3000
Use Ctrl-C to stop

I found that the microservice didn’t exhibit the above behaviour after sending a restart signal.  

To find the steps that lead to a stuck process.

dtrace via dtruss

I have had much success with strace to identify the cause of a similar problem, in the past. I tried installing it on my Mac laptop and found that strace is only available on linux but, there is an alternative, dtrace via dtruss.

sudo dtruss -p <PID>

The above command starts a firehose of logs ( especially if the process is active ) which gives an idea the type of system calls made by the process monitored by dtruss. Unlike strace, dtrace didn't seem to slow down the process it was attached to.

This proved to be a dead end as I was not able to figure-out a pattern and decided to look for alternatives. While I was reading up on dtrace, I came across Behind the scenes of shell IO redirection by René Hansen. This post gives a fair idea of how to use the tool and it also includes suggested reading.

rbtrace

I came across this tweet from Sam Saffron on using rbtrace for debugging stuck process and decided to give rbtrace a try. Originally written by Aman Gupta, who is the author of libraries such as EventMachine, rbtrace describes itself as, like strace, but for Ruby code.

rbtrace has a very robust interface which allows for fine grained control over the desired output format. I started with the full verbose tracing.

# application.rb
require 'rbtrace'

# TERMINAL A
bundle exec rails s

# TERMINAL B
rbtrace -p 87854 --firehose

Since the micro-service had many threads and did many things in the background, rbtrace's verbosity was simply, like in the case of dtrace, quite overwhelming.

I still didn't know what I was looking for, which made the whole task akin to looking for a needle in a haystack.  To give an idea of the haystack's size, for a freshly created Rails application, visiting localhost:3000 resulted over 94,000 lines of rbtrace-logs.

I also found that rbtrace was only usable as long as the primary Ruby process was responsive. Once the main process gets stuck, rbtrace stopped sending any messages, or the client refused to 'attach' to the process. This proved not useful, mostly when I ran the script shared in the tweet above.

P.S

In hindsight, I feel I didn't spent much time with rbtrace, as much as I did with dtruss. rbtrace is an excellent tool and if I had given enough time, I could have found the root cause without using lldb.

Inspecting a process with lldb.

I needed a tool that could show me the exact state of the process and threads after it is stuck, which led me to gdb and eventually to lldb.

Apparently, MacOs dropped support for gdb, and since 2005 Mac has been steadily moving away from the GNU toolchain. I decided to give lldb a go. lldb gets installed whenever Xcode Tools or Xcode is installed.

NOTE:
All lldb stacktraces are read bottom-up, hence frame #1 is chronologically after frame #2.

Running lldb on the stuck Ruby process,

master ● sudo lldb -p 20722
(lldb) process attach --pid 20722
Process 20722 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
    frame #0: 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10
libsystem_kernel.dylib`__psynch_cvwait:
->  0x7fff7279f882 <+10>: jae    0x7fff7279f88c            ; <+20>
    0x7fff7279f884 <+12>: movq   %rax, %rdi
    0x7fff7279f887 <+15>: jmp    0x7fff7279d629            ; cerror_nocancel
    0x7fff7279f88c <+20>: retq
Target 0: (ruby) stopped.

Executable module set to "/Users/<user>/.rbenv/versions/2.5.1/bin/ruby".
Architecture set to: x86_64h-apple-macosx-.
(lldb)

Don't worry with all that stuff that is in that log/code snippet. It didn't make sense to me either.  What we are interested, are in the threads. What are the threads doing?

I could see the list of all running threads using thread list command.

(lldb) thread list
Process 20722 stopped
* thread #1: tid = 0x8f037, 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  thread #2: tid = 0x8f039, 0x00007fff727a33d6 libsystem_kernel.dylib`poll + 10, name = 'ruby-timer-thr'
  thread #3: tid = 0x8f04a, 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'ruby_thread_lo*'
  thread #4: tid = 0x8f088, 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'connection_poo*'
  thread #5: tid = 0x8f0bf, 0x00007fff727a50fe libsystem_kernel.dylib`__select + 10, name = 'thread_pool.rb*'
  thread #6: tid = 0x8f0c0, 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'thread_pool.rb*'
 
 ...

I needed a way to find out what these threads are currently doing. thread backtrace all provides backtraces of all the threads that are running.

(lldb) thread backtrace all
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff72860425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001070714b3 libruby.2.5.dylib`gvl_acquire_common + 179
    frame #3: 0x0000000107068b13 libruby.2.5.dylib`native_sleep + 435
    ...
    frame #26: 0x00007fff7265bcc9 libdyld.dylib`start + 1
    
  thread #2, name = 'ruby-timer-thr'
    frame #0: 0x00007fff727a33d6 libsystem_kernel.dylib`poll + 10
    frame #1: 0x00000001052236d1 libruby.2.5.dylib`thread_timer + 417
    frame #2: 0x00007fff72860109 libsystem_pthread.dylib`_pthread_start + 148
    frame #3: 0x00007fff7285bb8b libsystem_pthread.dylib`thread_start + 15
    
  thread #3, name = 'ruby_thread_lo*'
    frame #0: 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff72860425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x000000010521abaa libruby.2.5.dylib`native_sleep + 586
    frame #3: 0x0000000105225746 libruby.2.5.dylib`queue_sleep + 118
...

Let's look at the backtrace of one specific thread, say the first one, and see try to figureout what it is doing.

(1) command to select the first thread
(2) Shortcut bt for backtrace, shows the full backtrace of the thread.
(3) _pthread_cond_wait comes from pthread.h file of the underlying C implementation of Ruby. This function is used to conditionally wait until a mutex is released.
(4) gvl_acquire_common Thread is currently trying to acquire GVL as any Ruby thread that wishes to execute should acquire the GVL.

To summarize, this particular thread is trying to acquire GVL, but is conditionally waiting for a mutex to be released.

This is part of how threads are scheduled within the Ruby runtime, but in our case a majority of these threads were stuck with gvl_acquire_common, which was not normal.

The curious ones.

Now that these threads are stuck waiting to acquire the Global Interpreter Lock, we need to find out what is causing them to wait. The best way to figure that out is to look for threads with unusual backtraces that stand-out from the rest.

Following are the list of  the crazy ones, the misfits, the rebels, the troublemakers out of a total of 67 threads.

thread #2, name = 'ruby-timer-thr'
The timer thread is part of thread-scheduling mechanism of Ruby language. It is a native thread and can be safely ignored from our list of suspects.  

thread #2, name = 'ruby-timer-thr'
    frame #0: 0x00007fff727a33d6 libsystem_kernel.dylib`poll + 10
    frame #1: 0x0000000107071763 libruby.2.5.dylib`thread_timer + 563
    frame #2: 0x00007fff72860109 libsystem_pthread.dylib`_pthread_start + 148
    frame #3: 0x00007fff7285bb8b libsystem_pthread.dylib`thread_start + 15

thread #6, name = 'utils.rb:193'
If we read from frame #7 to #3 of the following backtrace, we can see that this thread is trying to get a lock on something called a v8::Isolate. On further reading, it looks like a v8::Isolate is an isolated instance of V8 engine, the Javascript interpreter that powers Chrome and Node.js.

thread #6, name = 'utils.rb:193'
    frame #0: 0x00007fff7279f062 libsystem_kernel.dylib`__psynch_mutexwait + 10
    frame #1: 0x00007fff7285d917 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_wait + 83
    frame #2: 0x00007fff7285b937 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_slow + 222
    frame #3: 0x0000000107c3d376 libv8.dylib`v8::Locker::Locker(v8::Isolate*) + 94
    frame #4: 0x0000000107a54976 init.bundle`rr::Locker::doLock(int, unsigned long*, unsigned long) [inlined] rr::Locker::setupLockAndCall(state=0x0000700003b9083c, code=140299575081440) at locker.cc:47:17
    frame #5: 0x0000000107a5496f init.bundle`rr::Locker::doLock(argc=<unavailable>, argv=0x00007f9a70448470, self=<unavailable>) at locker.cc:39
    frame #6: 0x00000001070b39cc libruby.2.5.dylib`vm_call_cfunc + 284
    frame #7: 0x000000010709af09 libruby.2.5.dylib`vm_exec_core + 9497
    ...

thread #8, name = 'utils.rb:193'
I also found few other threads with similar backtraces, the ones with rb_thread_io_blocking_region (in frame #1) call. Reading up the backtrace from frame #6 upto #0, it looks like this thread is doing a IO operation. We also know that a Ruby thread doesn't need GVL for performing IO and hence this thread can be safely eliminated from our list of possible suspects.

thread #8, name = 'utils.rb:193'
    frame #0: 0x00007fff7279d81e libsystem_kernel.dylib`read + 10
    frame #1: 0x000000010706a769 libruby.2.5.dylib`rb_thread_io_blocking_region + 265
    frame #2: 0x0000000106f6d12d libruby.2.5.dylib`io_fillbuf + 157
    frame #3: 0x0000000106f6daba libruby.2.5.dylib`rb_io_getline_0 + 1162
    frame #4: 0x0000000106f83ee1 libruby.2.5.dylib`rb_io_getline + 113
    frame #5: 0x0000000106f7874b libruby.2.5.dylib`rb_io_gets_m + 11
    frame #6: 0x00000001070b39cc libruby.2.5.dylib`vm_call_cfunc + 284
    ...

thread #21, name = 'base.rb:118'
The following thread, Thread 21 is an example of a thread that is waiting to be scheduled by the Ruby vm. As it is not doing anything, we can remove this one as well from our list.

thread #21, name = 'base.rb:118'
    frame #0: 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff72860425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x0000000107068baa libruby.2.5.dylib`native_sleep + 586
    frame #3: 0x0000000107073746 libruby.2.5.dylib`queue_sleep + 118
    frame #4: 0x0000000106f45d51 libruby.2.5.dylib`rb_ensure + 193
    ...
    

thread #41, name = 'utils.rb:193'
This thread is doing a lot. On frame #32, it is starting a foreign function written in C via vm_call_cfunc. Throughout the backtrace, we can see namespacing of the form rr::. This is a namespace created by therubyracer gem. ( therubyracer gem is used to evaluate Javascript strings from Ruby)

• Frames #32 through #30 locks the V8::Isolate. This section is very similar to the backtrace of thread #6.
• Frames #29 through #21 the sets-up a v8::Handle. From v8's documentation, here we are creating what is called a Transient Handle (There are two types of Handles, Transient and Permanent ), which is used by V8's GC to keep track of objects created, within current scope.
• Frames #28 through #12 registers an external exception handler with the v8::Isolate.
• Frames #11 through #10 executes the javascript string.
• Frames #9 through #0 tries to capture that result and get it back into the calling user-land Ruby thread, but as we can see, on frame #2, it gets stuck on gvl_acquire_common.

thread #41, name = 'utils.rb:193'
    frame #0: 0x00007fff7279f882 libsystem_kernel.dylib`__psynch_cvwait + 10
    frame #1: 0x00007fff72860425 libsystem_pthread.dylib`_pthread_cond_wait + 698
    frame #2: 0x00000001070714b3 libruby.2.5.dylib`gvl_acquire_common + 179
    frame #3: 0x000000010706a482 libruby.2.5.dylib`rb_thread_schedule_limits + 386
    frame #4: 0x000000010706b3a2 libruby.2.5.dylib`rb_threadptr_execute_interrupts + 1474
    frame #5: 0x000000010709c7b9 libruby.2.5.dylib`vm_exec_core + 15817
    frame #6: 0x00000001070ae0a8 libruby.2.5.dylib`vm_exec + 184
    frame #7: 0x00000001070acb56 libruby.2.5.dylib`vm_invoke_proc + 374
    frame #8: 0x00000001070bb384 libruby.2.5.dylib`vm_call0_body + 1236
    frame #9: 0x00000001070a6145 libruby.2.5.dylib`rb_funcallv + 245
    frame #10: 0x0000000107a5b562 init.bundle`rr::TryCatch::doCall(code=140299574741160) at trycatch.cc:85:12
    frame #11: 0x0000000106f45bff libruby.2.5.dylib`rb_protect + 335
    frame #12: 0x0000000107a5b4a6 init.bundle`rr::TryCatch::setupAndCall(state=0x0000700003c937dc, code=140299574741160) at trycatch.cc:79:20
    frame #13: 0x0000000107a5b394 init.bundle`rr::TryCatch::doTryCatch(argc=0, argv=0x00007f9a503604a8, self=<unavailable>) at trycatch.cc:69:20
    frame #14: 0x00000001070b39cc libruby.2.5.dylib`vm_call_cfunc + 284
    frame #15: 0x000000010709af09 libruby.2.5.dylib`vm_exec_core + 9497
    frame #16: 0x00000001070ae0a8 libruby.2.5.dylib`vm_exec + 184
    frame #17: 0x00000001070acb56 libruby.2.5.dylib`vm_invoke_proc + 374
    frame #18: 0x00000001070bb384 libruby.2.5.dylib`vm_call0_body + 1236
    frame #19: 0x00000001070a6145 libruby.2.5.dylib`rb_funcallv + 245
    frame #20: 0x0000000106f45bff libruby.2.5.dylib`rb_protect + 335
    frame #21: 0x0000000107a53c07 init.bundle`rr::Handles::HandleScope(int, unsigned long*, unsigned long) [inlined] rr::Handles::SetupAndCall(state=0x0000700003c941fc, code=140299574741440) at handles.cc:27:10
    frame #22: 0x0000000107a53bef init.bundle`rr::Handles::HandleScope(argc=<unavailable>, argv=0x00007f9a503603c0, self=<unavailable>) at handles.cc:18
    frame #23: 0x00000001070b39cc libruby.2.5.dylib`vm_call_cfunc + 284
    frame #24: 0x000000010709af09 libruby.2.5.dylib`vm_exec_core + 9497
    frame #25: 0x00000001070ae0a8 libruby.2.5.dylib`vm_exec + 184
    frame #26: 0x00000001070acb56 libruby.2.5.dylib`vm_invoke_proc + 374
    frame #27: 0x00000001070bb384 libruby.2.5.dylib`vm_call0_body + 1236
    frame #28: 0x00000001070a6145 libruby.2.5.dylib`rb_funcallv + 245
    frame #29: 0x0000000106f45bff libruby.2.5.dylib`rb_protect + 335
    frame #30: 0x0000000107a54989 init.bundle`rr::Locker::doLock(int, unsigned long*, unsigned long) [inlined] rr::Locker::setupLockAndCall(state=0x0000700003c94c0c, code=140299574741520) at locker.cc:48:13
    frame #31: 0x0000000107a5496f init.bundle`rr::Locker::doLock(argc=<unavailable>, argv=0x00007f9a50360388, self=<unavailable>) at locker.cc:39
    frame #32: 0x00000001070b39cc libruby.2.5.dylib`vm_call_cfunc + 284
    ...

thread #67, name = 'SamplerThread'
This thread is started along with the v8::Isolate. Its primary job is to periodically sample the state of the VM and optionally, (if used for profiling) the program counter and stack pointer for, the thread that created it.

thread #67, name = 'SamplerThread'
    frame #0: 0x00007fff7279ce36 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x0000000107c9f053 libv8.dylib`v8::internal::MacOSSemaphore::Wait() + 17
    frame #2: 0x0000000107be2be0 libv8.dylib`v8::internal::RuntimeProfiler::WaitForSomeIsolateToEnterJS() + 70
    frame #3: 0x0000000107c9f1c0 libv8.dylib`v8::internal::SamplerThread::Run() + 34
    frame #4: 0x0000000107c9eb1f libv8.dylib`v8::internal::ThreadEntry(void*) + 60
    ...

We have removed all threads except  thread #6 and thread #41 from our list of suspects. It is time for us to look at both of them together.

thread #6, a user-land Ruby thread is holding the GVL and is trying to lock the v8::Isolate through the ffi given by therubyracer.

thread #41, a native thread is holding the v8::Isolate lock and is trying to acquire GVL.

In short, we have a deadlock.

Conclusion

Once I identified the cause of this deadlock, which is therubyracer gem being not thread safe, it was time to look for its usage within our application. I found that we were using Handlebars.rb gem to render customizable templates, and Handlebars had therubyracer as one of it dependencies.

Solutions were either to add a global mutex which would allow only one thread to enter Handlebar's context or to move away from HandleBars to something like Liquid templating by Shopify. In the end decided to move to Liquid.

References

• V8 Docs by nodesource.com
• The Ruby Racer gem source code
• lldb tutorial and documentation by llvm.org
• Correct way to use a v8::Isolate, StackOverflow

Suggested Reading

• Nobody understands the GIL blog series by Jesse Storimer
• Debugging a stuck process by Mike Perham

As Rails developers, most of us must have come across this handy method, Hash#with_indifferent_access, another instance of "rails-magic" that lets us access values from a ruby hash using either strings or symbols.

require 'active_support/core_ext/hash'

:0> 🚘 = {
:1*  make: 'emoji',
:1*  model: 'Red-car'
:1> }.with_indifferent_access
=> {"make"=>"emoji", "model"=>"red-car"}

:0> puts 🚘[:make]
=> "emoji"
:0> puts 🚘["make"]
=> "emoji"

In this post, I will be discussing three different ways to implement this functionality and compare and contrast each of these techniques.

Patching the core Hash class / Monkey Patch

The most straightforward approach of the three is implementing this functionality by patching the core Hash class.

class Hash 
  def [](key)
    dig(key.to_s) || dig(key.to_sym)
  end

  def []=(key, value)
    dig(key.to_sym) ? store(key.to_sym, value) : store(key.to_s, value)
  end
end

In the above code snippet, we are opening and re-implementing a core class. A side effect of this approach is, from that point when this class is loaded, all instances of Hash implements this new behavior and thereby violates the Open/Closed Principle (OCP).

A technique to extend the behavior of Hash without violating OCP is by using inheritance. This is also how Rails provides indifferent access.

The Rails Way

If we open Rails console and check the class name of the object returned by calling #with_indifferent_access, we see that, it is no longer Hash, but it is ActiveSupport::HashWithIndifferentAccess.

[1] pry(main)> {}.class.name
=> "Hash"
[2] pry(main)> {}.with_indifferent_access.class.name
=> "ActiveSupport::HashWithIndifferentAccess"

If we dig up the source code we can see that, HashWithIndifferentAccess inherits from Hash.

module ActiveSupport
  class HashWithIndifferentAccess < Hash
    def initialize
      # ...
    end
    
    def [](key)
      dig(key.to_s) || dig(key.to_sym)
    end

    def []=(key, value)
      dig(key.to_sym) ? store(key.to_sym, value) : store(key.to_s, value)
    end

    # NOTE:
    # The actual HashWithIndifferentAccess implementation 
    # does a lot more than re-implement #[] and #[]=
  end
end

class Hash
  def with_indifferent_access
    HashWithIndifferentAccess.new(self)
  end
end

This technique doesn’t change the implementation of any of the interfaces of the core class, but has a major downside, which is one needs to install and use ActiveSupport gem.

While working on a gem, I thought it would be a bit too much to include ActiveSupport as a dependency just for the ability to access a hash value with either a string or a symbol and that is when I came across Ruby Refinements.

Let's Refine Hash!

Ruby Refinements, as the name suggests allow us to modify the functionality of a class with very minimal impact. In fact, refinements were introduced to minimize the impact of monkey-patching core classes.

module DifferentlyAccessibleHash
  refine Hash do
    def [](key)
      dig(key.to_s) || dig(key.to_sym)
    end

    def []=(key, value)
      dig(key.to_sym) ? store(key.to_sym, value) : store(key.to_s, value)
    end
  end
end

Take a note of the Module#refine keyword in line#2. Adapting Ruby documentation for our example above, we have the following.

• Module#refine keyword is used to refine an existing class Hash.
• Module#refine creates an anonymous module and this anonymous module can be "activated" by employing the using keyword.

This is a bit confusing, correct? Let's try to explain this with a code snippet.

# differently_accessible_hash.rb

module DifferentlyAccessibleHash
  refine Hash do
    def [](key)
      dig(key.to_s) || dig(key.to_sym)
    end

    def []=(key, value)
      dig(key.to_sym) ? store(key.to_sym, value) : store(key.to_s, value)
    end
  end
end

# car.rb

require './differently_accessible_hash'

class EmojiCar

  using DifferentlyAccessibleHash
  
  def initialize
    @specs = { 
     make: 'emoji',
     model: 'Red-car'
    }
  end
  
  def make
    @specs[:make]   # access make via symbol
  end
  
  def model
    @specs['model'] # access model via string 
  end
end

Even though Module#refine creates an anonymous module with our new functionality against Hash, this module is not activated until the usage of using keyword.

Another advantage of the using keyword is that, it is lexically scoped. From the documentation.

• You may activate refinements at top-level, and inside classes and modules.
• You may not activate refinements in method scope.
• Refinements are activated until the end of the current class or module definition, or until the end of the current file if used at the top-level.
• Refinements are only active within a scope after the call to using. Any code before the using statement will not have the refinement activated

In our example code, since we have "activated" DifferentlyAccessibleHash in the class level, any Hash objects can be accessed with either string or symbol within that class.

Additional Reading

Refine and Using Methods in Ruby by Mehdi Farsi
So what’s the deal with Ruby refinements, anyway? by Avdi Grimm

A not so gentle Introduction

Modules are some of the most exciting concepts in Ruby, but it is also a feature that is not really understood by its users. For someone who is just starting out with the language and even to seasoned programmers, Ruby Modules can be confusing, especially when used in conjunction with classes.

Before we start on this post, let me give you a 10,000ft over-view of how this post is structured. The post takes you through

• Different ways of using modules
• Anonymous Modules and a Rails use case
• In closing, a brief history of module system

How can I use modules?

Enhancing the behavior of an instance.

A good way to enhance the capabilities of an instance is to 'mix-in' a module into its class.

module Saveable
  def save
  end
end

class XMLDocument
  include Saveable
end

:0> xml_document = XMLDocument.new
:0> xml_document.respond_to? :save
=> true

Here, when Saveable module is included, the behavior of the original XMLDocument changes. It can be saved to the disk now.

Another way to look at this is, now instance-methods of XMLDocument can access #save method of Saveable module, which opens up additional possibilities like overriding the default behavior.

class XMLDocument
  include Saveable
  
  def save
    puts @data.inspect
    super
  end
end   

But why super ? To understand that, let's look at what super is.  

By definition,

super: Calls the current method in a superclass

When we included Saveable into XMLDocument, Saveable became a super from which behavior is inherited. This becomes even more evident when we inspect the ancestors of XMLDocument.

:0> XMLDocument.ancestors
=> [XMLDocument, Saveable, Object, Kernel, BasicObject]

We can see that sum-total of XMLDocument is the final inheritance or rather a mixin from itself as well as from a bunch of other classes and modules.

There are few other ways to share code between classes like Multiple Inheritance and Traits. Ruby doesn't support Multiple Inheritance.

Quoting Matz,

Single inheritance is good because the whole class inheritance structure forms a single tree with a single root, named Object, and that is very easy to understand. In languages with multiple inheritance, the classes form a network, which is harder to understand.

reference: https://web.archive.org/web/20191025214218/https://www.artima.com/intv/tuesday.html

Now that we have a clear idea of what include is, how to use it, and why is it designed that way, let's move on to the next way to use modules.

Enhancing the behavior of a Class

The way we can enhance the behavior of a Class is through the use of extend keyword.

module FileReadable
  def read(file_path)
    # reads the file at file_path
  end
end

class XMLDocument
  extend FileReadable
end

:0> xml_document = XMLDocument.read('/path/to/file.xml')

When we extended XMLDocument with FileReadable, functions on FileReadable became class methods of XMLDocument.

Even though extend lends a module's behavior to a class, ( as opposed to include which lends the behavior to an instance) the way extend works internally is very similar to include keyword.

But, let's digress to explore the subject of class or static methods in Ruby.

class XMLDocument
  def self.parse(raw_data)
  end
end

:0> XMLDocument.singleton_class.instance_methods.grep /parse/
=> [:parse]

In essence, every class method of XMLDocument is in reality, instance methods of XMLDocument's singleton or eigen or metaclass.

From Wikipedia,

A metaclass is a class whose instances are classes. Just as an ordinary class defines the behavior of certain objects, a metaclass defines the behavior of certain classes and their instances.

So far, we know the following:

• An eigen class defines the behavior of a class
• Class methods are instance methods on the eigen-class of a class
• Include keyword added instance methods by pushing Saveable module up the ancestor chain or XMLDocument

:0> XMLDocument.singleton_class.ancestors
=> [#<Class:XMLDocument>, FileReadable, #<Class:Object>, #<Class:BasicObject>, Class, Module, Object, Kernel, BasicObject]

In conclusion, extend keywork added instance methods to the metaclass of XMLDocument by pushing FileReadable module into its ancestor chain.

Decorating the existing behavior of an instance.

As its name suggests, prepend keyword prepends the behavior of a module before the instance's.

In one of our previous examples I have an XMLDocument with save capabilities, if we, for example, want to measure how many seconds it would take for save operation to complete.

module Saveable
  def save
  end
end

class XMLDocument
  include Saveable
end

module Timer
  def save
    t1 = Time.now
    super
    puts "Time taken to save: #{Time.now - t1}s"
  end
end

XMLDocument.prepend(Timer)

:0> xml_document = XMLDocument.new
:0> xml_document.save
Time taken to save: 0.084587s
=> nil

By just looking at the code, you my esteemed reader, might have guessed exactly what is going on under the hood. Let's inspect the ancestors chain again.

:0> XMLDocument.ancestors
=> [Timer, XMLDocument, Saveable, Object, Kernel, BasicObject]

Classes with just class methods

In our careers, we might have come across a fully functional class that has just class methods. A prime example is the quintessential kitchen-sink, the Util class.

class Util
  def self.do_something
  end
  
  def self.do_something_entirely_different
  end
end

This is an anti-pattern and is declining rapidly, thanks to RuboCop. This can be readily replaced by.

module Util
  module_function
  
  def do_something
  end
  
  def do_something_entirely_different
  end
end

Now that we know the many different direct use cases of modules, let us look at namespacing.

A way to logically bundle things.

Any programmer knows that "Fruits::Apple" must be something completely different from "CellPhone::Apple", we also know that "CellPhone::Apple" might be similar to "CellPhone::Nokia", hence we conclude with little-evidence that Namespacing has nothing to do with names and much more to do with similarity.

I won't be going much into namespaces and constant resolution, due to the simple fact that, the topic in itself is vast and can't beat these follwoing writeups as these posts discusses namespaces and constant resolution in great depth.

• This excellent writeup by Conrad Irvin about Constant Resolution is a must read for every Ruby practitioner
• This primer on namespaces written by Sidu Ponnappa and Jasim A Basheer for RubyMonk

As a transitive container to hold code

To understand this a bit more, let us look into the ways in which a module can be defined in Ruby code.

module Sidekiq
end

and the above form is very much equivalent to the following code.

Sidekiq = Module.new do
end

Even though these are two forms are same for all intents and purposes, there is a subtle difference. The second form, takes an anonymous module and assigns it to a constant, while in first form there is no anonymous module involved due to the implicit assignment of the module code to the constant.

An example of anonymous module in action is class_methods from ActiveSupport::Concern. I am sure you, my reader, is extremely inquisitive and would love to find out how that works.

the tl;dr version.

• The block of code passed to classmethods is assigned to an anonymous module
• This anonymous module is then used to append class methods to the including class using extend

I have an explanation of how it works in one of my previous blogs, ( and the link points to just that section ).

We have exhausted all the possible ways we can use modules in Ruby. Let us learn a bit more, and read the fantastic history of modules.

A Brief history of module system

When Matz designed Ruby, he was heavily inspired by SmallTalk which is often considered as the perfect Object Oriented language. Ruby inherited a lot of features from SmallTalk, including MetaClass ( references in above section, Enhancing the behavior of a Class), to help maintain the "everything is an object" paradigm.

Even though SmallTalk is an Object Oriented language, from the perspective of its original designers, Alan Kay, Dan Ingalls, Adele Goldberg, and others at Xerox PARC, SmallTalk was designed as a functional language based on Lisp and Simula of which Simula supported features like Objects and Classes. One can argue that, while Lisp gave functional programming capabilities to SmallTalk, Simula gave it the "object-orientedness", like Classes and Objects.

But where does the module system come from? To answer this question, we need to go further back another generation. The immediate generation of The PASCAL Family of Programming Languages.  This family contains heavyweights like Ada, Simula, Eiffel and a lesser known Modula. It is Modula that brought forth modularization, the idea that "lets one define a public interface to hide the private implementation details".

Together, let's learn how Pry debugger works, but before we dive into that, we need to do some ground work and learn what binding is.

From Ruby documentation,

Objects of class Binding encapsulate the execution context at some particular place in the code and retain this context for future use. The variables, methods, value of self , and possibly an iterator block that can be accessed in this context are all retained.

Let us use (a modified version) the sample code given in the documentation to understand this concept a bit more.

class Demo
  def initialize(message)
    @message = message
  end
  
  def get_binding
    binding
  end
end

irb:xx> demo_binding = Demo.new('fantastic').get_binding
irb:xx> puts demo_binding.eval("It has been a #{@message} demo")
It has been a fantastic demo
nil
irb:xx>

In essence, binding.eval executes any 'code-string' in the context of the object at the point at which the binding was captured.

What is binding.pry?

Pry debugger extends Ruby's Binding class to start a REPL whenever #pry is called on a binding. The REPL is started in such a way that the REPL's context is the binding itself.

Let's try to mimic this, with a barebones implementation.

class Binding
  # We are opening and patching Ruby's in-built Binding class
  # and adding a new method: #pry
  
  def pry
    # Our humble read-eval-print-loop
    loop do
      puts self.eval(gets)
    end
  end
end

class Demo
  def initialize(message)
    @message = message
  end

  def get_binding
    binding
  end
  
  def start_pry
    binding.pry
  end
end

irb:xx> demo = Demo.new("simple repl")
=> #<Demo:0x00007fa8d61677a0 @message="simple repl">

irb:xx> demo.start_pry
puts "This is a #{@message}"
This is a simple repl

At its core, Pry  is as simple as this, but in its entirety, Pry is much more. Our barebones implementation lacks a prompt and bombs when we try to evaluate multi-line code. Pry uses Ruby Readline to handle all these cases and as a cherry on top, uses coderay to highlight the code.

Read more about this at: Rails 6 adds guard against DNS Rebinding attacks

Read more about this at: Rails 6 introduces new code loader called Zeitwerk

This serializer was small enough to be written in a single class and had two or three methods which did all the heavy lifting and obviously were fat. After combing through the implementation for a while and testing it with data, I finally figured out the bug it carried and fixed it, but the fat methods were an eyesore, and like a good boy scout, I decided to refactor it.

The serializer dealt with no state at all which meant that the methods were all class methods, and splitting up class methods are always a pain.

class CustomSerializer
  def self.serialize(objects, options={})
    list = associated_records(objects, options)
    unwanted_associations = blacklisted_associations(options)
    unwanted_attributes = blacklisted_attributes(options)

    list.each do | object, associations |
      remove_blacklisted_associations(associations, unwanted_associations)
      # you get the idea
    end
  end

  def self.deserialize(json, options={})
  end

  def self.blacklisted_associations(options)
  end

  def self.blacklisted_attributes(options)
  end

  def self.associated_records(options)
  end
end

These methods, are only usable within the context of the class, and usually, we hide them using access modifiers, but how does one hide a class method?

Private Class Methods To The Rescue.

As discussed in ruby docs , private_class_methods are used to make existing class methods hidden.

class SimpleSingleton  # Not thread safe
  private_class_method :new
  def SimpleSingleton.create(*args, &block)
    @me = new(*args, &block) if ! @me
    @me
  end
end

In the above example, taken from the docs, it hides the constructor :new. But what happens when you have one too many class methods you need to hide?.

Incorporating private_class_method into our earlier class, it becomes,

class CustomSerializer
  def self.serialize(objects, options={})
    # code
  end

  def self.deserialize(json, options={})
    # code
  end

  def self.blacklisted_associations(options)
  end

  def self.blacklisted_attributes(options)
  end

  def self.associated_records(options)
  end

  private_class_method :blacklisted_associations, :blacklisted_attributes, :associated_records
end

This works!, but what if the class is very large that I need to scroll all the way down to see which ones are private class methods? If only I had something similar to class_methods from ActiveSupport::Concern

Let’s take a quick detour and see what public methods are.

Public Methods In Ruby

Let's take any public method from the above class and look at it a little deeper.

class CustomSerializer
  def self.associated_records
  end
end

# :irb > CustomSerializer.public_methods.grep /associated_records/
# => [:associated_records]

# :irb > CustomSerializer.singleton_class.instance_methods.grep /associated_records/
# => [:associated_records]

Basically, class methods are instance methods of any class’s singleton_class or eigenclass. This basically means that we can do something like:

class CustomSerializer
  class << self
    private

    def associated_records
    end
  end
end

# :irb > CustomSerializer.public_methods.grep /associated_records/
# => []

# :irb > CustomSerializer.associated_records
# NoMethodError: private method `associated_records' called for CustomSerializer:Class
#   from (irb):xx

# :irb > CustomSerializer.singleton_class.private_instance_methods.grep /associated_records/
# => [:associated_records]

We now have a way to avoid the repetition and to improve the readability of the code. Only problem is, do all of us understand what is going on here? Ruby as a language gives us immense meta-programming flexibility and I decided to take this even further.

How Far Can We Go With This?

Remember the class_methods method defined on module from ActiveSupport::Concern? Will ruby allow us to do something like that?. Lets take a look at the source code for class_methods from ActiveSupport::Concern.

# File activesupport/lib/active_support/concern.rb, line 134
def class_methods(&class_methods_module_definition)
  mod = const_defined?(:ClassMethods, false) ?
    const_get(:ClassMethods) :
    const_set(:ClassMethods, Module.new)

  mod.module_eval(&class_methods_module_definition)
end

The following is what happens when that method is executed:

• The method class_methods checks whether there is an already existing constant, :ClassMethods
• If it is not present, instantiate an anonymous module and set it to local variable mod
• Runs module_eval on mod with the given block.

Let’s decipher what ActiveSupport does here by trying this out on the console and filling the blanks whenever necessary.

module Holder
  mod = const_set :ClassMethods, Module.new
  mod.module_eval do
    def associated_records
    end
  end
end

# :irb > Holder::ClassMethods.class
# => Module

class CustomSerializer
  extend Holder::ClassMethod
end

# :irb > CustomSerializer.singleton_class.instance_methods.grep /associated_records/
# => [:associated_records]

In short, ActiveSupport::Concern uses an anonymous class as a temporary storage. But can we use this to create a helper of our own? This is what I came up with.

class Object
  def private_class_methods &block
    anonymous_module = Module.new(&block)
    anonymous_module.instance_methods.each { |method| anonymous_module.send(:private, method) }
    extend(anonymous_module)
  end
end

class CustomSerializer
  private_class_methods do
    def associated_records
    end
  end
end

# :irb > CustomSerializer.singleton_class.private_instance_methods.grep /associated_records/
# => [:associated_records]

Getting Back To Our Refactor

In the end, I went with the private_class_methods :method_A, :method_B. Why, one might ask. I went through the code base and checked for usages of private_class_method and for classes that could use this helper. I couldn't find much. I checked for the churn of CustomSerializer class. It was very low, and again, this new method isn't documented anywhere so, another developer will have to grep through the codebase to find its definition.

In the end cons associated with patching a core class outweighed the pros of having a handy helper.

Update: For encapsulating stateless code, a module with .module_functions is favored over a class with only class methods in idiomatic ruby.

Read more about this at: Setting up a high performance Geocoder.

Read more about this at: Using concurrent Ruby in a Ruby on Rails Application.

I am a big fan of code readability, but being a fan and expecting the code I write to be readable are two different things. Readable code is easier to understand and much more straightforward to grasp.

One significant difference I find while comparing readable and unreadable code, apart from the obvious, is how many different variables I have to hold in my head at a time while I try to grapple my head around it. If this task is simple, I believe that this is not because of some random act of brilliance but due to careful code construction.

CTEs helps achieve this by its ability to separate data into independent logical entities according to the context of the query.

WITH popular_posts 
     AS (SELECT id, 
                title, 
                body 
         FROM   posts 
         WHERE  posts.upvote > 5) 
SELECT * 
FROM   popular_posts; 

A random use case.  

Let's look at a random use case and check how the query performance and readability can be improved. For a particular report in our e-commerce app, we were querying for each item’s latest n review-comments, in our case, we can set n = 2.

For the first iteration, we can write a simple join and then filter that in our application language (Ruby, Go, PHP etc.)

SELECT items.id             AS item_id, 
       review_comments.id   AS comment_id, 
       review_comments.body AS comment_body
FROM   items 
       LEFT OUTER JOIN review_comments 
                    ON items.id = review_comments.item_id; 

For an e-commerce system like Amazon, this is not going to scale since the sheer number of items and the associated review comments are guaranteed to bog down the dbms.

Lets introduce a Window Function

In general, a Window Function, is a mathematical function that is zero valued outside of some interval. In case of SQL engines, they operate on rows that are related to the current row, in our case, this can be the item_id. All rows of the join that has a common item_id acts as a partition over which the window function acts.

We rewrite our query to do the following:

• Window function should operate on a partition of same item_ids
• Each of these partitions should be ordered by created time stamp of review_comment.
• Select only the top two from each partition

SELECT 
  item_id, 
  comment_id, 
  comment_body 
FROM 
  (
    SELECT 
      items.id AS item_id, 
      review_comments.id AS comment_id, 
      review_comments.body AS comment_body, 
      Row_number() OVER(
        partition BY item_id 
        ORDER BY 
          review_comments.created_at DESC
      ) AS comment_row_number, 
    FROM 
      items 
      LEFT OUTER JOIN review_comments ON items.id = review_comments.item_id
  ) AS items_ranked_by_comments 
WHERE 
  comment_row_number < 3;

/* Result:
+----------+------------+--------------------+
|  item_id | comment_id |    comment_body    |
+----------+------------+--------------------+
|      900 |       8789 | This product is..  |
|      900 |      12301 | Fantastic produ..  |
|     1200 |      13466 | Great to see cu..  |
|     1200 |      19023 |                    | 
|       .. |         .. |                ..  |
+----------+------------+--------------------+
*/

The sub-query is resulting in a full join table, but now we have comment_row_number field to let us know that the newest review_comment has a value of 1. All we need to do now is to filter using that column.

We have used row_number() function from PostgreSQL as the window function here. According to the docs, any built-in or user-defined aggregate function can be used as a window function.

Putting It All Together

Even though we have our answer, our query has become pretty hard to read. We can get better readability by introducing a Common Table Expression.

WITH items_ranked_by_comments AS (
  SELECT 
    items.id AS item_id, 
    review_comments.id AS comment_id, 
    review_comments.body AS comment_body, 
    Row_number() OVER(
      partition BY item_id 
      ORDER BY 
        review_comments.created_at DESC
    ) AS comment_row_number, 
  FROM 
    items 
    LEFT OUTER JOIN review_comments ON items.id = review_comments.item_id
) 
SELECT 
  item_id, 
  comment_id, 
  comment_body 
FROM 
  items_ranked_by_comments 
WHERE 
  comment_row_number < 3;

Well, that is it folks. We have put together two concepts, readability and performance to create something which is the best of both worlds.

Read more about this at: Rails 5 silences assets logs in dev mode by default

We could implement the filter as shown here.

Patient.where("lower(first_name) = ?", first_name.downcase)

Read more about this at: Rails 5 Expression Indexes & Operator Classes support

Read more about this at: Attach arbitrary metadata to an Active Job in Rails 5