photo

I am currently laid up from a recent hand injury, involving a bottle of wine and and a bad idea. Ironically, despite only having 1.2 hands to use for typing (pinky on right hand), being stuck at home has actually made it easier to get through some of my hacking todo list. The first item on that list is to release a little utility I have been using lately: stacklog.

What does it do?

Stacklog simply wraps another logging module (I like Winston) so that you can push logging prefixes onto a stack and they will be automatically prepended to the logger’s output. Something I used to do manually like this (real example from a recent project):

var log = require('./log')
...
function getVideosInReadyState(next) {
  log.debug('[videos][getVideosInReadyState]');

  VideoStore.loadQueue('readyQueue', function (err, videoDocList) {
    log.debug('[videos][getVideosInReadyState][x]');
    if (err) { return next(err); }
    if (!videoDocList) { 
      log.error('[videos][getVideosInReadyState][onloadQueue] no videos returned');
      return next(new Error('No videos returned'));
    }

    log.debug('[videos][getVideosInReadyState][onloadQueue] ' + videoDocList.length + ' videos found in ready state');

    return next(null, videoDocList);
  });
}

Now becomes this:

var log = require('./log')('videos');
...
function getVideosInReadyState(next) {
  var l = log.debug('getVideosInReadyState');

  VideoStore.loadQueue('readyQueue', function (err, videoDocList) {
    var l2 = l.debug('onLoadQueue');
    if (err) { return next(err); }
    if (!videoDocList) { 
      l2.error('no videos returned');
      return next(new Error('No videos returned'));
    }

    l2.debug(videoDocList.length + ' videos found in ready state');

    return next(null, videoDocList);
  });
}

In both cases, the output produced during a call with debug logging enabled would look like:

debug: [videos][getVideosInReadyState]
debug: [videos][getVideosInReadyState][onLoadQueue]
debug: [videos][getVideosInReadyState][onLoadQueue] 8 videos found in ready state

The advantage of the second case is simple. If I rename the module or function, I don’t have to go change every debug log statement. It also is also harder to forget to add the prefix in the call and leads to greater consistency in the various log statements sprinkled around the app.

But so much logging! and other whining

Yes, this approach still requires lots of manual log statements and somewhat unsightly variables named l and l2 floating around. I explored a few other options to get automatic tracing in Node, but there really isn’t a great solution to this problem. Error objects do get stack traces, but they are too expensive to create for non-error related debugging. This is JavaScript folks, and it is the world we have chosen to live in. It is a miracle that we can even take console.log for granted now (server side at least)!

My philosophical approach to logging is that it is worth the effort up front, rather than dropping debug statements in “when needed.” Some of our developers prefer to leave the code debug statement free on the basis that it is cleaner/prettier. I’m always greatly annoyed when I have to debug their apps in production.

Performance implications?

Yes. Not logging at all performs much better (as expected). Short of using dTrace, this is an unavoidable penalty that any logging solution will have to incur. The upside is that running stacklog at less verbose log levels (as you would in normal production operation) performs better than leaving console.log() statements in.

Tests were run on core i7 2012 Macbook Air w/ 8GB ram. Average over 100 runs of 1000 iterations. There was zero sciences involved in this experiment.

Test - average (microseconds)

  • nolog.js - 1.8
  • console.js - 22041.17
  • winston.js - 45438.45
  • stacklogon.js - 77842.35
  • stacklogoff.js - 14706.28

Where to get it

Stacklog is released under the MIT license and is available on npm and github. As always,

Feedback

If you find stacklog useful, or you have a better way of accomplishing the same task, or you are interested in joining the MLS Dev team, we would love to hear from you!

@jdslatts on twitter or Justin.Slattery@mlssoccer.com

 photo

Introduction

The MLS Digital dev team is in Portland this week to attend DrupalCon 2013. We are very excited to be involved with the Drupal community and plan on helping to tackle issues during the code sprints on Friday.

We have made it a priority to start contributing more back to the open source community. Specifically, we want to release some of the custom modules that we use to build our MLS platform. Today, we are announcing the release of our first three releases on Drupal.org.

Custom Meta

Custom Meta module on Drupal.org

While Nodewords (D6) and Metatags (D7) work well for adding things like Abstract, Description, Keywords, Robots, Copyright and even OpenGraph meta tags to your content, we continually found ourselves backed into a situation where we would have to release a tpl.php update or write a custom module to inject meta tag elements onto our platform.

A good example is the Smart App Banner from Apple. We received the info to add the tag to our site for early adoption of the feature but had to deploy code to implement. After adding one too many contrib modules or writing yet another custom module to add small or bulk custom meta tags to our system, we came up with the idea for Custom Meta.

The module allows you to define and manage custom meta tags.

  • Select the “Meta Attribute” (Property, Name, or http-equiv)
  • Set the “Attribute value”
  • Set the “Content Value”
  • Module will add meta tags to all Non-Admin content for your site.
<meta [Meta Attribute]="[Attribute Value]" content="[Content value]">

Custom Meta

Gigya Top Comments

Gigya Top Comments module on Drupal.org

We utilize Gigya for our user management, comments, and social infrastructure.

To determine “popular” content, Gigya provides metadata about content via their REST API. We implemented the getTopStreams method to acquire a list of popular content based on comment counts. Unfortunately, the getTopStreams algorithm did not really factor “velocity” into its ranking. This created a fan experience that was a bit jarring, as almost all of our front page content, each with hundreds of comments, could be dropped off the popular list suddenly when they hit the maximum age of three days, even though their were active discussions.

To make the aging of popular content a bit more natural, we decided to implement our own ranking algorithm. We reviewed a few different publicly available aglorithms and ultimately decided to implement the algorithm that powers Hacker News as described in this blog post http://amix.dk/blog/post/19574.

Our implementation of the algorithm weighs the comment count against the age of the first comment on a piece of content. We aim to keep fresh content in the Top Discussions block by rewarding content that generates a high volume of comments over a shorter period of time, but slowly making time a heavier penalty. For an item to stay on the front page, it has to continously generate more traffic than the fresher content. By default the getTopStreams call to Gigya’s API returns 100 streams that we then rank using the algorithm. We have found that our default parameters for comments (1) and time (1.5), have done a good job displaying engaging content on MLSsoccer.com, but the parameters can be tweaked for particular implementations through the module’s admin UI.

The code below demonstrates how the parameters alter the behavior of the alogrithm:

1 function mls_gigya_top_content_rank($item, $age) {
2   $time_modifier = variable_get('mls_gigya_top_content_time_modifier', '');
3   $comment_modifier = variable_get('mls_gigya_top_content_comment_modifier', '');
4   $item_rank = pow($item->commentCount-1, $comment_modifier)/pow($age+2,$time_modifier);
5   return intval($item_rank*1000);
6 }

Tweet Block

Tweet Block module on Drupal.org

We were very excited when Twitter introduced Embedded Timelines and Embeddable Tweets. It gave our editors a new way to integrate tweets about our league and create editorial around them. Our editors wanted the ability to generate blocks that showed a specified tweet via a Tweet ID in a few different layouts. This would allow us to feature tweet blocks in our site layout via Context.

Here are the layouts we chose (of course all of these are customizable via theme overrides of the tpl.php files found in the theme directory of the module).

Tweet Block

The module uses the oEmbed endpoint call to generate static pre-formatted blocks to your site to be used via blocks where ever you like. It allows for an unlimited amount of embedded timelines to be created. There is a limit to the number of API requests you can do per hour (currently 150), so this module stashes the response in the database and only makes requests when you save the settings form. Content is not written into the block unless an tweet ID is specified and the Twitter response is valid.

This module generates the following blocks.

  • Block 1 - The proper response from the Twitter API formatted by Twitter. The twitter JavaScript embed is required and is an option in the admin UI for this block.
  • Block 2 - A custom single line representation of the Tweet. You can override the styles and theme yourself.
  • Block 3 - A stylized version of the tweet that you can skin yourself.
  • Block 4[n] - Unlimited amount of embedded timelines.

This module is definitely customized to our use case, but we feel that it can be refined for more widespread adoption. We would love to hear what you think and what you would want in a future version. Tweet BEAN blocks for Drupal 7, indefinite custom block definitions, etc.. Please let us know in the Issue Queue what you would like to see.


Our team is committed to ensuring that these modules are activley maintained. Please feel free to open issues on the project pages for any enhancements and bugs you might have.

Thanks!

Hans Gutknecht - @HansyG , Louis Jimenez - @LouisAJimenez


Past Contributions

 photo

Introduction

The developers here have been working hard behind the scenes, and in the midst of that, we’ve abstracted out a project we think you may find usefull. Today we introduce, diff.js! This project was created from the need to find the difference between objects, for us, so we can control the data we send around applications at a detailed level.

Use Case

The primary reason for building this lib was to reduce the payload we were sending around the app, especially the data we were broadcasting to clients over socket.io. Some of our datasets can get fairly large and complex, lets say, for example, one dataset was 5kb, and we have 1 connected client, not that big of a deal. What if we have 5000 clients? Sending that much data can add up fast.

So, instead of sending the entire dataset, we dif it! It turns out that in most cases only a few keys or properties had changed, so we pay the cost up front and find out exactly what has changed from the old version to the new, reducing the payload to 100 bytes. Using this method around our application we reduced the data size being sent to the client by over 70%. In some cases there was no difference between versions of the data, and we don’t send updates at all.

Heres an example of what we’re doing, for brevity, lets imagine there are 99 players in the following objects:

var previous = {
  1: {
    name: 'John'
  , number: '23'
  , stats: {
      shots: 1
    , passes: 13
    }
  }
, 99: {
    name: 'Peter'
  , number: '05'
  , stats: {
      shots: 0
    , passes: 7
    }
  }
};

var updated = {
  1: {
    name: 'John'
  , number: '23'
  , stats: {
      shots: 4
    , passes: 15
    }
  }
, 99: {
    name: 'Peter'
  , number: '05'
  , stats: {
      shots: 0
    , passes: 7
    }
  }
};

You can see that only John’s stats have changed, we would previously send the entire updated object, but really, we only need to tell the clients that John has changed.

var difference = dif(previous, updated);
{
  1: {
    name: 'John'
  , number: '23'
  , stats: {
      shots: 4
    , passes: 15
    }
  }
}

Isn’t that better? Now we only have to deal with a much smaller subset of data. We hope this library can be of use to the community, so, enjoy! Feel free to open issues you find with the project on github.

Beau Sorensen - @beausorensen

 photo

Introduction

For those of us who come from traditional sysops backgrounds, learning Salt means un-learning many of our shell scripting habits. Instead of linearly specifying the operations you need a server to perform like this (contrived example, the salt-minion package would ask to install python):

#!/bin/bash
  apt-get update
  apt-get install python 
  apt-get install salt-minion
  cp ~/temp/salt-minion-config /etc/salt/minion
  chown root.root /etc/salt/minion
  chmod 600 /etc/salt/minion
  /etc/init.d/salt-minion restart

You instead specify a series of states that will be applied the server. States are evaluated independently from each other and may live in separate files. Each specifies its own dependencies and SaltStack will make sure they get applied in the correct order. The example above translates to something like:

 1 python:
 2     pkg:
 3       - installed
 4 
 5   salt-minion:
 6     pkg:
 7       - installed
 8       - require:
 9         - pkg: python
10 
11   /etc/salt/minion:
12     file:
13       - managed
14       - source: salt://salt/salt-minion-config
15       - mode: 600
16       - user: root
17       - group: root
18       - require:
19         - pkg: salt-minion
20 
21   salt-minion:
22     service:
23       - running
24       - watch:
25         - file: /etc/salt/minion
26       - require:
27         - pkg: salt-minion

Ok, so the Salt version is a tad longer. But even for this not-so-realistic example, there are several benefits:

  • In the shell script version, the minion will be restarted every time. In the Salt version, the minion is only restarted when the config file is changed.
  • It would require a lot more tricky shell script coding if we decided to split the installation of python into a separate file.
  • Where does the salt-minion-config file even come from? The shell script version will need it delivered to ~/temp somehow. Salt handles this for us.

Real Power

The real power of Salt starts to become apparent when you realize you can start adding flow control logic to your jinja states. Example to add users to a server:

{% for usr in 'Tom','Dick','Harry' %}
{{ usr }}:
  user:
    - present
    - fullname: {{ usr }}
    - home: True
    - shell: /bin/bash
    # group names for sudo very by platform
    - optional_groups:
      - admin
      - ubuntu
      - wheel
  ssh_auth:
    - present
    - user: {{ usr }} 
    - source: salt://users/keys/{{ usr }}_id_rsa.pub
    - require:
      - user: {{ usr }}
{% endfor %} 

Slick huh? We have a list of usernames and we auto-generate the rest of the jinja file to create each user’s corresponding state. We even use a simple naming convention to get their SSH keys out there!

This is a real example that we used here at MLS Digital to add users to all of our servers. It worked great, but as the team grew, the need to constantly be editing the user list became tedious. Furthermore, we started to find that we didn’t want every developer to have full access to every server.

The next level

We had just recently started using Salt Pillars to achieve better separation between data and code and we thought this would be a great application for pillars. Our first attempt resulted in this:

 1 _pillar/top.sls:_
 2 
 3     'prod_servers*':
 4       - produsers
 5     'dev_servers*':
 6       - devusers
 7 
 8 _salt/top.sls:_
 9 
10     '*_servers*':
11       - sudoers
12 
13 _pillar/users/produsers.sls:_
14     
15     sudoers_users: ['Tom','Jane','Harry','Sue','Mike','Janet']
16 
17 _pillar/users/devusers.sls:_
18     
19     sudoers_users: ['Dick', 'Tom','Jane','Harry','Sue','Mike','Janet']
20 
21 _salt/users/sudoers.sls:_
{% for usr in pillar['sudoers_users'] %}
{{ usr }}:
  user:
    - present
    - fullname: {{ usr }}
    - home: True
    - shell: /bin/bash
    # group names for sudo very by platform
    - optional_groups:
      - admin
      - ubuntu
      - wheel
  ssh_auth:
    - present
    - user: {{ usr }} 
    - source: salt://users/keys/{{ usr }}_id_rsa.pub
    - require:
      - user: {{ usr }}
{% endfor %} 

Jinja templates allow basic flow control structures, such as loops, conditionals, and macros. Pillars allow you to assign chunks of data (think strings and lists) scoped in the same way you scope the states themselves. Pulling the data out of the states allows you to create more dynamic states and achieve better re-usability across your code base. In this example, we are using the same basic sudoers state, but getting different behavior depending on the target server. In case you were wondering, Dick crashed production with some untested code and is on temporary production probation :)

Trouble in paradise

That’s pretty nice! But us OCD programmer types like to keep it DRY and seeing the produsers’ names listed twice makes us start twitching… uncontrollably.

The first thought was to try and aggregate the separate user lists in the pillars themselves. It looked something like:

pillar/users/produsers.sls:

sudoers_users: ['Tom','Jane','Harry','Sue','Mike','Janet']

pillar/users/devusers.sls:

{% if 'sudoers_users' in pillar %}
sudoers_users: pillar['sudoers_users'].extend(['Dick'])
{% else %}
sudoers_users: ['Dick']
{% endif %}

Unfortunately, that doesn’t work and several similar variations failed as well. The pillar constructs are simply not available to be used by the pillars themselves.

The even next-er level

After some research and some experimenting, we realized that between the limitations in the Pillar system and the minimal tools available in Jinja, that we would have to write our Python state. Oh, did I mention you can do that? Yes! All you have to do is prefix the sls file with #!py and Salt will execute everything inside the run() function. The only requirement is that you return a valid Salt high state data structure.

pillar/users/mls.sls:

users_add_mls: ['Tom','Jane','Harry','Sue','Mike','Janet']

pillar/users/probation.sls:

users_add_probation: ['Dick']

salt/users/sudoers.sls:

#!py

def run():
    '''
    Manage sudo enabled user adds/removes
    '''

    users_root = []
    [users_root.extend(value) for key,value in pillar.iteritems() if key.startswith('users_add')]

    generated_user_hsd = {}

    for user in users_root:
        generated_user_hsd[user] = {}

        generated_user_hsd[user]['user'] = [
            'present',
            {'fullname' : user},
            {'home' : True},
            {'shell' : '/bin/bash'},
            {'optional_groups' : ['admin','ubuntu','wheel']}
        ]
        generated_user_hsd[user]['ssh_auth'] = [
            'present',
            {'user' : user},
            {'source' : 'salt://users/keys/' + user + '_id_rsa.pub'},
            {'require' : [{'user': user}]}
        ]

    return generated_user_hsd

It certainly is refreshing to have the full power of Python available! Our new state is now smart enough to search for available pillars with users_add as part of their name, aggregate the results, and generate the correct high state data structure for Salt to process. This version above is very similar to what we currently run in production and it works quite well.

Wrapping it up

We started with shell scripting, progressed to generated jinja states, and ended up with custom python states. What fun! A small warning though. Writing a custom python state should be your last resort. There is a major tradeoff between readbility and keeping things DRY. We try to stick to jinja states unless the benefits of the custom code are significant. As you become more familar with Salt, you will start to get a feel for what level of complexity is required for various tasks.

Remember, you’re DevOps now, not some unix cowboy. This is code. You’re a programmer and all the best practice coding rules apply.

Justin Slattery - @jdslatts