Cheltenham Web Design and Drupal Development | Tigerfish Interactive

We had a recurring problem recently on one of our Drupal 6 e-commerce developments where Ubercart 2 content types were disappearing. We would create an Ubercart product class, which would in turn create a Drupal content type, assign a few CCK fields to it, and set it up how we wanted to. Alas, each time we cleared the cache, it was gone!

It turns out that the cause was a rogue statement in a contrib module causing node_get_types() to be called before Drupal was fully bootstrapped and therefore some modules, at that time, were not included yet. The solution was simply to implement hook_init() and put the stray code in there.

Debugging this problem was particularly difficult because there was simply no indication of what was to blame. We started by looking at the mechanism responsible for determining the node types, which is an internal function in the node module called _node_types_build(). We knew the problem was stemming from clearing the cache, so we looked more closely at Drupal 6's cache clearing mechanism. Sure enough, on clearing the cache, this _node_types_build() is called.

What ought to happen here is that two types of node get returned. The first type is the Drupal internal content type: that is, nodes that are created by Drupal's 'add content type' facility. The second type are content types provided by modules. For example, an event module might define an event content type, or a recipe module might provide a recipe content type. Ubercart allows for the creation of product classes, which are content types. Where Ubercart differs slightly is that it allows product classes to override node types. This means that if you have a node type called foo, and you add an Ubercart product class called foo, it will transform the node into a product.

In our case, it was all Ubercart product classes that were disappearing, whether we had created them outright or 'overtaken' an existing node type. We found that _node_types_build() was calling module_invoke_all() and invoking hook_node_info. This hook is what allows modules to provide information about the content types they define. In Ubercart's case, it is supposed to return all its product classes when this hook is invoked. To our confusion, we found that when invoking the hook manually, it did indeed return product classes correctly, but when calling _node_types_build(), those very product classes were missing!

This suggested to us that the hook was not being invoked. Digging in a little further, we discovered that module_invoke_all() calls module_implements(), which goes off and gets a list of the modules that implement a particular hook. At this point we discovered that module_implements() reported that Ubercart was not in the list of modules that implemented hook_node_info. This shouldn't be the case, because we could see quite plainly in the code that the hook is implemented and it is named correctly. Then we began to theorise: what if the hook isn't implemented because the Ubercart modules were not included?

We knew that Ubercart was being included at some point because the module did work properly and the checkout was functioning and all the other bits were working, but Drupal 'bootstraps' (loads everything) in a particular order, so what if _node_types_build() was being called before the bootstrapping process responsible for including the Ubercart modules?

We thought we'd check this by deliberately inserting a module_load_include() at the beginning of the core module_invoke_all() function, thereby forcing Drupal to include the Ubercart modules. Sure enough, the content types stopped disappearing when we forced the module to be included, so we had established that _node_types_build() was being called before the Ubercart modules had a chance to be included.

Another key cause of this problem was the static caching mechanism in the core module_implements() function. It meant that no matter how many times _node_types_build() was called, the same list of modules was returned when asking Drupal what implements hook_node_info. Since _node_types_build() gets called on a number of occasions during a cache clear, all we really knew is that the first call was made before the Ubercart modules were included. Any subsequent calls would used cached data to prevent excessive database queries, so their results could not be trusted.

We implemented a debug_backtrace() inside the module_implements() function in order to track the order of functions being called. Note that because debug_backtrace() output can be huge, it was important to make sure it only got called the first time module_implements('node_info') was called, and not every time, so we set up a temporary static variable the first time, and did not bother with the backtrace if the variable was already set. Here is our output, pumped through dpm():

The important thing to notice here is that key 3 refers to node_get_types() being called within the config_perms module. This is the first time it is called. Remember that node_get_types() is responsible for calling _node_types_build() and that's where our problem was occurring.

We then checked our modified version of the config_perms module and noticed something strange. There were some statements in the module file that were not inside any functions! One of these statements was calling node_get_types()! The problem was now becoming clear. The Drupal bootstrapping process includes each module file one by one, in alphabetical order (unless module weight is set). When config_perms gets included, the code that exists outside any functions gets executed immediately, not waiting for the rest of the modules to be included.

Therefore, when node_get_types() was being called for the first time, Drupal didn't know about the Ubercart module (or any other module whose name began with a letter after C in the alphabet), so it wasn't given the chance to call its implementation of hook_node_info. Because of the static caching mechanism responsible for storing the list of modules that implement hook_node_info, the list was never refreshed, and Ubercart's modules never appeared in it.

The solution was simple: hook_init would save us. It allows modules to invoke code on each page request, early enough that it would achieve what we wanted it to do, but not so early as to miss modules. Once we moved our code inside an implementation of hook_init, everything worked perfectly! Here's how it was achieved:

Let's be very clear here that there is no issue with config_perms itself. We modified it, and by doing so, we took on the responsibility of making sure our modifications didn't break anything. On this occasion, they did. The lesson is not to put code inside a module file but outside of any functions. It is appropriate to define static values here, but not to execute code logic or anything like what we were trying to achieve.

Also it's worth pointing out that this complicated debugging process cost us dearly in terms of time. With hindsight it's easy to see and fix the problem, and the trouble we had debugging it is not well conveyed here. Because we were using a modified version of config_perms, even if we'd established that the module was somehow to blame, nothing would have showed up in the module's issue queue on drupal.org.