Mongrel2 Profiler Filter: Take 2

I wrote about creating the profiler filter for Mongrel2 web/application server before. The filter was dead simple and measured the time it took to serve a simple request. This profiler did not include the per-connection request profiling since it saved the data into global ProfilerSession struct which recorded times of receiving the request and sending the response. Since this was just a proof-of-concept thing to get to know how one can write a filter for Mongrel2 - it didn’t have a good architecture to begin with.

Wanting to improve it I wrote to Mongrel2 librelist seeking advice. I’m not a good C programmer, so Tordek helped me a lot by virtually rewriting the whole filter to handle per-connection profiling of different requests as well cleaning up the code and making it shorter.

Here’s the code in whole 76 lines of its glory:

Profiler filter with per-connection profiling
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76

#include <filter.h>
#include <dbg.h>
#include <adt/hash.h>

#include <sys/time.h>

hash_t* sessions_hash = NULL;

int profsess_cmp(const void *ps0, const void *ps1);
hash_val_t profsess_hash(const void *conn);

StateEvent filter_transition(StateEvent state, Connection *conn, tns_value_t *config)
{
  struct timeval *currentTime = malloc(sizeof(struct timeval));
  check_mem(currentTime);

  int rc = gettimeofday(currentTime, NULL);
  check(rc == 0, "Failed to get time of day");
  
  switch(state) {
      case REQ_RECV: {
          int rc = hash_alloc_insert(sessions_hash, conn, currentTime);
          check(rc == 1, "Failed to insert timestamp into hash.");
          break;
      }
      case RESP_SENT: {
          hnode_t *startTimeNode = hash_lookup(sessions_hash, conn);
          struct timeval *startTime = startTimeNode->hash_data;
          
          long int startTimeInt = startTime->tv_sec * 1000 + startTime->tv_usec / 1000;
          long int endTimeInt = (currentTime->tv_sec * 1000 + currentTime->tv_usec / 1000);
          long int diffInt = endTimeInt - startTimeInt;
          debug("Request took %ldms", diffInt);

          free(startTime);
          hash_delete_free(sessions_hash, startTimeNode);
          break;
      }
      default :
          sentinel("Unknown state received by filter.");
          break;
  }
  return state;
  
error:
  return CLOSE;
}


StateEvent *filter_init(Server *srv, bstring load_path, int *out_nstates)
{
  StateEvent states[] = {REQ_RECV, RESP_SENT};
  *out_nstates = Filter_states_length(states);
  check(*out_nstates == 2, "Wrong states array length.");
  debug("[Profiler:filter_init] initted filter with needed states:");

  sessions_hash = hash_create(MAX_HASH_COUNT, profsess_cmp, profsess_hash);
  check_mem(sessions_hash);
  debug("[Profiler:filter_init] initted sessions hash");

  return Filter_state_list(states, *out_nstates);

error:
  return NULL;
}

hash_val_t profsess_hash(const void *data)
{
  return (hash_val_t)data;
}


int profsess_cmp(const void *ps0, const void *ps1)
{
  return memcmp(ps0, ps1, sizeof(Connection *));
}

Same setup instructions apply. You can find them in previous post.

programming

Comments