src/or/command.c

   1 /* Copyright 2001 Matej Pfajfar.
   2  * Copyright 2001-2004 Roger Dingledine.
   3  * Copyright 2004-2005 Roger Dingledine, Nick Mathewson. */
   4 /* See LICENSE for licensing information */
   5 /* $Id$ */
   6 const char command_c_id[] = "$Id$";
   7
   8 /**
   9  * \file command.c
  10  * \brief Functions for processing incoming cells.
  11  **/
  12
  13 /* In-points to command.c:
  14  *
  15  * - command_process_cell(), called from
  16  *   connection_or_process_cells_from_inbuf() in connection_or.c
  17  */
  18
  19 #define NEW_LOG_INTERFACE
  20 #include "or.h"
  21
  22 /** Keep statistics about how many of each type of cell we've received. */
  23 unsigned long stats_n_padding_cells_processed = 0;
  24 unsigned long stats_n_create_cells_processed = 0;
  25 unsigned long stats_n_created_cells_processed = 0;
  26 unsigned long stats_n_relay_cells_processed = 0;
  27 unsigned long stats_n_destroy_cells_processed = 0;
  28
  29 /* These are the main four functions for processing cells */
  30 static void command_process_create_cell(cell_t *cell, connection_t *conn);
  31 static void command_process_created_cell(cell_t *cell, connection_t *conn);
  32 static void command_process_relay_cell(cell_t *cell, connection_t *conn);
  33 static void command_process_destroy_cell(cell_t *cell, connection_t *conn);
  34
  35 #ifdef KEEP_TIMING_STATS
  36 /** This is a wrapper function around the actual function that processes the
  37  * <b>cell</b> that just arrived on <b>conn</b>. Increment <b>*time</b>
  38  * by the number of microseconds used by the call to <b>*func(cell, conn)</b>.
  39  */
  40 static void
  41 command_time_process_cell(cell_t *cell, connection_t *conn, int *time,
  42                                void (*func)(cell_t *, connection_t *))
  43 {
  44   struct timeval start, end;
  45   long time_passed;
  46
  47   tor_gettimeofday(&start);
  48
  49   (*func)(cell, conn);
  50
  51   tor_gettimeofday(&end);
  52   time_passed = tv_udiff(&start, &end) ;
  53
  54   if (time_passed > 10000) { /* more than 10ms */
  55     debug(LD_OR,"That call just took %ld ms.",time_passed/1000);
  56   }
  57   if (time_passed < 0) {
  58     info(LD_GENERAL,"That call took us back in time!");
  59     time_passed = 0;
  60   }
  61   *time += time_passed;
  62 }
  63 #endif
  64
  65 /** Process a <b>cell</b> that was just received on <b>conn</b>. Keep internal
  66  * statistics about how many of each cell we've processed so far
  67  * this second, and the total number of microseconds it took to
  68  * process each type of cell.
  69  */
  70 void
  71 command_process_cell(cell_t *cell, connection_t *conn)
  72 {
  73 #ifdef KEEP_TIMING_STATS
  74   /* how many of each cell have we seen so far this second? needs better
  75    * name. */
  76   static int num_create=0, num_created=0, num_relay=0, num_destroy=0;
  77   /* how long has it taken to process each type of cell? */
  78   static int create_time=0, created_time=0, relay_time=0, destroy_time=0;
  79   static time_t current_second = 0; /* from previous calls to time */
  80
  81   time_t now = time(NULL);
  82
  83   if (now > current_second) { /* the second has rolled over */
  84     /* print stats */
  85     info(LD_OR,"At end of second: %d creates (%d ms), %d createds (%d ms), %d relays (%d ms), %d destroys (%d ms)",
  86       num_create, create_time/1000,
  87       num_created, created_time/1000,
  88       num_relay, relay_time/1000,
  89       num_destroy, destroy_time/1000);
  90
  91     /* zero out stats */
  92     num_create = num_created = num_relay = num_destroy = 0;
  93     create_time = created_time = relay_time = destroy_time = 0;
  94
  95     /* remember which second it is, for next time */
  96     current_second = now;
  97   }
  98 #endif
  99
 100   switch (cell->command) {
 101     case CELL_PADDING:
 102       ++stats_n_padding_cells_processed;
 103       /* do nothing */
 104       break;
 105     case CELL_CREATE:
 106     case CELL_CREATE_FAST:
 107       ++stats_n_create_cells_processed;
 108 #ifdef KEEP_TIMING_STATS
 109       ++num_create;
 110       command_time_process_cell(cell, conn, &create_time,
 111                                 command_process_create_cell);
 112 #else
 113       command_process_create_cell(cell, conn);
 114 #endif
 115       break;
 116     case CELL_CREATED:
 117     case CELL_CREATED_FAST:
 118       ++stats_n_created_cells_processed;
 119 #ifdef KEEP_TIMING_STATS
 120       ++num_created;
 121       command_time_process_cell(cell, conn, &created_time,
 122                                 command_process_created_cell);
 123 #else
 124       command_process_created_cell(cell, conn);
 125 #endif
 126       break;
 127     case CELL_RELAY:
 128       ++stats_n_relay_cells_processed;
 129 #ifdef KEEP_TIMING_STATS
 130       ++num_relay;
 131       command_time_process_cell(cell, conn, &relay_time,
 132                                 command_process_relay_cell);
 133 #else
 134       command_process_relay_cell(cell, conn);
 135 #endif
 136       break;
 137     case CELL_DESTROY:
 138       ++stats_n_destroy_cells_processed;
 139 #ifdef KEEP_TIMING_STATS
 140       ++num_destroy;
 141       command_time_process_cell(cell, conn, &destroy_time,
 142                                 command_process_destroy_cell);
 143 #else
 144       command_process_destroy_cell(cell, conn);
 145 #endif
 146       break;
 147     default:
 148       log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 149              "Cell of unknown type (%d) received. Dropping.", cell->command);
 150       break;
 151   }
 152 }
 153
 154 /** Process a 'create' <b>cell</b> that just arrived from <b>conn</b>. Make a new circuit
 155  * with the p_circ_id specified in cell. Put the circuit in state
 156  * onionskin_pending, and pass the onionskin to the cpuworker. Circ will
 157  * get picked up again when the cpuworker finishes decrypting it.
 158  */
 159 static void
 160 command_process_create_cell(cell_t *cell, connection_t *conn)
 161 {
 162   circuit_t *circ;
 163
 164   if (we_are_hibernating()) {
 165     info(LD_OR,"Received create cell but we're shutting down. Sending back destroy.");
 166     connection_send_destroy(cell->circ_id, conn);
 167     return;
 168   }
 169
 170   /* If the high bit of the circuit ID is not as expected, then switch
 171    * which half of the space we'll use for our own CREATE cells.
 172    *
 173    * This can happen because Tor 0.0.9pre5 and earlier decide which
 174    * half to use based on nickname, and we now use identity keys.
 175    */
 176   if ((cell->circ_id & (1<<15)) && conn->circ_id_type == CIRC_ID_TYPE_HIGHER) {
 177     info(LD_OR, "Got a high circuit ID from %s (%d); switching to low circuit IDs.",
 178            conn->nickname ? conn->nickname : "client", conn->s);
 179     conn->circ_id_type = CIRC_ID_TYPE_LOWER;
 180   } else if (!(cell->circ_id & (1<<15)) && conn->circ_id_type == CIRC_ID_TYPE_LOWER) {
 181     info(LD_OR, "Got a low circuit ID from %s (%d); switching to high circuit IDs.",
 182            conn->nickname ? conn->nickname : "client", conn->s);
 183     conn->circ_id_type = CIRC_ID_TYPE_HIGHER;
 184   }
 185
 186   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 187
 188   if (circ) {
 189     routerinfo_t *router = router_get_by_digest(conn->identity_digest);
 190     log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 191            "received CREATE cell (circID %d) for known circ. Dropping (age %d).",
 192            cell->circ_id, (int)(time(NULL) - conn->timestamp_created));
 193     if (router)
 194       log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 195              "Details: nickname '%s', platform '%s'.",
 196              router->nickname, router->platform);
 197     return;
 198   }
 199
 200   circ = circuit_new(cell->circ_id, conn);
 201   circ->purpose = CIRCUIT_PURPOSE_OR;
 202   circ->state = CIRCUIT_STATE_ONIONSKIN_PENDING;
 203   if (cell->command == CELL_CREATE) {
 204     memcpy(circ->onionskin, cell->payload, ONIONSKIN_CHALLENGE_LEN);
 205
 206     /* hand it off to the cpuworkers, and then return */
 207     if (assign_to_cpuworker(NULL, CPUWORKER_TASK_ONION, circ) < 0) {
 208       warn(LD_GENERAL,"Failed to hand off onionskin. Closing.");
 209       circuit_mark_for_close(circ);
 210       return;
 211     }
 212     debug(LD_OR,"success: handed off onionskin.");
 213   } else {
 214     char keys[CPATH_KEY_MATERIAL_LEN];
 215     char reply[DIGEST_LEN*2];
 216     tor_assert(cell->command == CELL_CREATE_FAST);
 217     if (fast_server_handshake(cell->payload, reply, keys, sizeof(keys))<0) {
 218       warn(LD_OR,"Failed to generate key material. Closing.");
 219       circuit_mark_for_close(circ);
 220       return;
 221     }
 222     if (onionskin_answer(circ, CELL_CREATED_FAST, reply, keys)<0) {
 223       warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing.");
 224       circuit_mark_for_close(circ);
 225       return;
 226     }
 227   }
 228 }
 229
 230 /** Process a 'created' <b>cell</b> that just arrived from <b>conn</b>. Find the circuit
 231  * that it's intended for. If we're not the origin of the circuit, package
 232  * the 'created' cell in an 'extended' relay cell and pass it back. If we
 233  * are the origin of the circuit, send it to circuit_finish_handshake() to
 234  * finish processing keys, and then call circuit_send_next_onion_skin() to
 235  * extend to the next hop in the circuit if necessary.
 236  */
 237 static void
 238 command_process_created_cell(cell_t *cell, connection_t *conn)
 239 {
 240   circuit_t *circ;
 241
 242   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 243
 244   if (!circ) {
 245     info(LD_OR,"(circID %d) unknown circ (probably got a destroy earlier). Dropping.", cell->circ_id);
 246     return;
 247   }
 248
 249   if (circ->n_circ_id != cell->circ_id) {
 250     log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,
 251            "got created cell from OPward? Closing.");
 252     circuit_mark_for_close(circ);
 253     return;
 254   }
 255
 256   if (CIRCUIT_IS_ORIGIN(circ)) { /* we're the OP. Handshake this. */
 257     debug(LD_OR,"at OP. Finishing handshake.");
 258     if (circuit_finish_handshake(circ, cell->command, cell->payload) < 0) {
 259       warn(LD_OR,"circuit_finish_handshake failed.");
 260       circuit_mark_for_close(circ);
 261       return;
 262     }
 263     debug(LD_OR,"Moving to next skin.");
 264     if (circuit_send_next_onion_skin(circ) < 0) {
 265       info(LD_OR,"circuit_send_next_onion_skin failed.");
 266       circuit_mark_for_close(circ); /* XXX push this circuit_close lower */
 267       return;
 268     }
 269   } else { /* pack it into an extended relay cell, and send it. */
 270     debug(LD_OR,"Converting created cell to extended relay cell, sending.");
 271     connection_edge_send_command(NULL, circ, RELAY_COMMAND_EXTENDED,
 272                                  cell->payload, ONIONSKIN_REPLY_LEN, NULL);
 273   }
 274 }
 275
 276 /** Process a 'relay' <b>cell</b> that just arrived from <b>conn</b>. Make sure
 277  * it came in with a recognized circ_id. Pass it on to
 278  * circuit_receive_relay_cell() for actual processing.
 279  */
 280 static void
 281 command_process_relay_cell(cell_t *cell, connection_t *conn)
 282 {
 283   circuit_t *circ;
 284
 285   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 286
 287   if (!circ) {
 288     debug(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.",
 289           cell->circ_id, conn->address, conn->port);
 290     return;
 291   }
 292
 293   if (circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) {
 294     log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,"circuit in create_wait. Closing.");
 295     circuit_mark_for_close(circ);
 296     return;
 297   }
 298
 299   if (cell->circ_id == circ->p_circ_id) { /* it's an outgoing cell */
 300     if (circuit_receive_relay_cell(cell, circ, CELL_DIRECTION_OUT) < 0) {
 301       log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,"circuit_receive_relay_cell (forward) failed. Closing.");
 302       circuit_mark_for_close(circ);
 303       return;
 304     }
 305   } else { /* it's an ingoing cell */
 306     if (circuit_receive_relay_cell(cell, circ, CELL_DIRECTION_IN) < 0) {
 307       log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,"circuit_receive_relay_cell (backward) failed. Closing.");
 308       circuit_mark_for_close(circ);
 309       return;
 310     }
 311   }
 312 }
 313
 314 /** Process a 'destroy' <b>cell</b> that just arrived from
 315  * <b>conn</b>. Find the circ that it refers to (if any).
 316  *
 317  * If the circ is in state
 318  * onionskin_pending, then call onion_pending_remove() to remove it
 319  * from the pending onion list (note that if it's already being
 320  * processed by the cpuworker, it won't be in the list anymore; but
 321  * when the cpuworker returns it, the circuit will be gone, and the
 322  * cpuworker response will be dropped).
 323  *
 324  * Then mark the circuit for close (which marks all edges for close,
 325  * and passes the destroy cell onward if necessary).
 326  */
 327 static void
 328 command_process_destroy_cell(cell_t *cell, connection_t *conn)
 329 {
 330   circuit_t *circ;
 331
 332   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 333
 334   if (!circ) {
 335     info(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.",
 336            cell->circ_id, conn->address, conn->port);
 337     return;
 338   }
 339
 340   debug(LD_OR,"Received for circID %d.",cell->circ_id);
 341   if (circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) {
 342     onion_pending_remove(circ);
 343   }
 344
 345   if (cell->circ_id == circ->p_circ_id) {
 346     /* the destroy came from behind */
 347     circuit_set_circid_orconn(circ, 0, NULL, P_CONN_CHANGED);
 348     circuit_mark_for_close(circ);
 349   } else { /* the destroy came from ahead */
 350     circuit_set_circid_orconn(circ, 0, NULL, N_CONN_CHANGED);
 351     if (CIRCUIT_IS_ORIGIN(circ)) {
 352       circuit_mark_for_close(circ);
 353     } else {
 354       debug(LD_OR, "Delivering 'truncated' back.");
 355       connection_edge_send_command(NULL, circ, RELAY_COMMAND_TRUNCATED,
 356                                    NULL, 0, NULL);
 357     }
 358   }
 359 }
 360