src/or/command.c

   1 /* Copyright (c) 2001 Matej Pfajfar.
   2  * Copyright (c) 2001-2004, Roger Dingledine.
   3  * Copyright (c) 2004-2007, Roger Dingledine, Nick Mathewson. */
   4 /* See LICENSE for licensing information */
   5 /* $Id$ */
   6 const char command_c_id[] =
   7   "$Id$";
   8
   9 /**
  10  * \file command.c
  11  * \brief Functions for processing incoming cells.
  12  **/
  13
  14 /* In-points to command.c:
  15  *
  16  * - command_process_cell(), called from
  17  *   connection_or_process_cells_from_inbuf() in connection_or.c
  18  */
  19
  20 #include "or.h"
  21
  22 /** Keep statistics about how many of each type of cell we've received. */
  23 uint64_t stats_n_padding_cells_processed = 0;
  24 uint64_t stats_n_create_cells_processed = 0;
  25 uint64_t stats_n_created_cells_processed = 0;
  26 uint64_t stats_n_relay_cells_processed = 0;
  27 uint64_t 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, or_connection_t *conn);
  31 static void command_process_created_cell(cell_t *cell, or_connection_t *conn);
  32 static void command_process_relay_cell(cell_t *cell, or_connection_t *conn);
  33 static void command_process_destroy_cell(cell_t *cell, or_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, or_connection_t *conn, int *time,
  42                                void (*func)(cell_t *, or_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     log_debug(LD_OR,"That call just took %ld ms.",time_passed/1000);
  56   }
  57   if (time_passed < 0) {
  58     log_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, or_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     log_info(LD_OR,
  86          "At end of second: %d creates (%d ms), %d createds (%d ms), "
  87          "%d relays (%d ms), %d destroys (%d ms)",
  88          num_create, create_time/1000,
  89          num_created, created_time/1000,
  90          num_relay, relay_time/1000,
  91          num_destroy, destroy_time/1000);
  92
  93     /* zero out stats */
  94     num_create = num_created = num_relay = num_destroy = 0;
  95     create_time = created_time = relay_time = destroy_time = 0;
  96
  97     /* remember which second it is, for next time */
  98     current_second = now;
  99   }
 100 #endif
 101
 102   switch (cell->command) {
 103     case CELL_PADDING:
 104       ++stats_n_padding_cells_processed;
 105       /* do nothing */
 106       break;
 107     case CELL_CREATE:
 108     case CELL_CREATE_FAST:
 109       ++stats_n_create_cells_processed;
 110 #ifdef KEEP_TIMING_STATS
 111       ++num_create;
 112       command_time_process_cell(cell, conn, &create_time,
 113                                 command_process_create_cell);
 114 #else
 115       command_process_create_cell(cell, conn);
 116 #endif
 117       break;
 118     case CELL_CREATED:
 119     case CELL_CREATED_FAST:
 120       ++stats_n_created_cells_processed;
 121 #ifdef KEEP_TIMING_STATS
 122       ++num_created;
 123       command_time_process_cell(cell, conn, &created_time,
 124                                 command_process_created_cell);
 125 #else
 126       command_process_created_cell(cell, conn);
 127 #endif
 128       break;
 129     case CELL_RELAY:
 130       ++stats_n_relay_cells_processed;
 131 #ifdef KEEP_TIMING_STATS
 132       ++num_relay;
 133       command_time_process_cell(cell, conn, &relay_time,
 134                                 command_process_relay_cell);
 135 #else
 136       command_process_relay_cell(cell, conn);
 137 #endif
 138       break;
 139     case CELL_DESTROY:
 140       ++stats_n_destroy_cells_processed;
 141 #ifdef KEEP_TIMING_STATS
 142       ++num_destroy;
 143       command_time_process_cell(cell, conn, &destroy_time,
 144                                 command_process_destroy_cell);
 145 #else
 146       command_process_destroy_cell(cell, conn);
 147 #endif
 148       break;
 149     default:
 150       log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 151              "Cell of unknown type (%d) received. Dropping.", cell->command);
 152       break;
 153   }
 154 }
 155
 156 /** Process a 'create' <b>cell</b> that just arrived from <b>conn</b>. Make a
 157  * new circuit with the p_circ_id specified in cell. Put the circuit in state
 158  * onionskin_pending, and pass the onionskin to the cpuworker. Circ will get
 159  * picked up again when the cpuworker finishes decrypting it.
 160  */
 161 static void
 162 command_process_create_cell(cell_t *cell, or_connection_t *conn)
 163 {
 164   or_circuit_t *circ;
 165   int id_is_high;
 166
 167   if (we_are_hibernating()) {
 168     log_info(LD_OR,
 169              "Received create cell but we're shutting down. Sending back "
 170              "destroy.");
 171     connection_or_send_destroy(cell->circ_id, conn,
 172                                END_CIRC_REASON_HIBERNATING);
 173     return;
 174   }
 175
 176   if (!server_mode(get_options())) {
 177     log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 178            "Received create cell (type %d) from %s:%d, but we're a client. "
 179            "Sending back a destroy.",
 180            (int)cell->command, conn->_base.address, conn->_base.port);
 181     connection_or_send_destroy(cell->circ_id, conn,
 182                                END_CIRC_REASON_TORPROTOCOL);
 183     return;
 184   }
 185
 186   /* If the high bit of the circuit ID is not as expected, close the
 187    * circ. */
 188   id_is_high = cell->circ_id & (1<<15);
 189   if ((id_is_high && conn->circ_id_type == CIRC_ID_TYPE_HIGHER) ||
 190       (!id_is_high && conn->circ_id_type == CIRC_ID_TYPE_LOWER)) {
 191     log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 192            "Received create cell with unexpected circ_id %d. Closing.",
 193            cell->circ_id);
 194     connection_or_send_destroy(cell->circ_id, conn,
 195                                END_CIRC_REASON_TORPROTOCOL);
 196     return;
 197   }
 198
 199   if (circuit_get_by_circid_orconn(cell->circ_id, conn)) {
 200     routerinfo_t *router = router_get_by_digest(conn->identity_digest);
 201     log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 202            "Received CREATE cell (circID %d) for known circ. "
 203            "Dropping (age %d).",
 204            cell->circ_id, (int)(time(NULL) - conn->_base.timestamp_created));
 205     if (router)
 206       log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,
 207              "Details: nickname \"%s\", platform %s.",
 208              router->nickname, escaped(router->platform));
 209     return;
 210   }
 211
 212   circ = or_circuit_new(cell->circ_id, conn);
 213   circ->_base.purpose = CIRCUIT_PURPOSE_OR;
 214   circuit_set_state(TO_CIRCUIT(circ), CIRCUIT_STATE_ONIONSKIN_PENDING);
 215   if (cell->command == CELL_CREATE) {
 216     circ->_base.onionskin = tor_malloc(ONIONSKIN_CHALLENGE_LEN);
 217     memcpy(circ->_base.onionskin, cell->payload, ONIONSKIN_CHALLENGE_LEN);
 218
 219     /* hand it off to the cpuworkers, and then return. */
 220     if (assign_to_cpuworker(NULL, CPUWORKER_TASK_ONION, circ) < 0) {
 221       log_warn(LD_GENERAL,"Failed to hand off onionskin. Closing.");
 222       circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL);
 223       return;
 224     }
 225     log_debug(LD_OR,"success: handed off onionskin.");
 226   } else {
 227     /* This is a CREATE_FAST cell; we can handle it immediately without using
 228      * a CPU worker. */
 229     char keys[CPATH_KEY_MATERIAL_LEN];
 230     char reply[DIGEST_LEN*2];
 231     tor_assert(cell->command == CELL_CREATE_FAST);
 232     if (fast_server_handshake(cell->payload, reply, keys, sizeof(keys))<0) {
 233       log_warn(LD_OR,"Failed to generate key material. Closing.");
 234       circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL);
 235       return;
 236     }
 237     if (onionskin_answer(circ, CELL_CREATED_FAST, reply, keys)<0) {
 238       log_warn(LD_OR,"Failed to reply to CREATE_FAST cell. Closing.");
 239       circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL);
 240       return;
 241     }
 242   }
 243 }
 244
 245 /** Process a 'created' <b>cell</b> that just arrived from <b>conn</b>.
 246  * Find the circuit
 247  * that it's intended for. If we're not the origin of the circuit, package
 248  * the 'created' cell in an 'extended' relay cell and pass it back. If we
 249  * are the origin of the circuit, send it to circuit_finish_handshake() to
 250  * finish processing keys, and then call circuit_send_next_onion_skin() to
 251  * extend to the next hop in the circuit if necessary.
 252  */
 253 static void
 254 command_process_created_cell(cell_t *cell, or_connection_t *conn)
 255 {
 256   circuit_t *circ;
 257
 258   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 259
 260   if (!circ) {
 261     log_info(LD_OR,
 262              "(circID %d) unknown circ (probably got a destroy earlier). "
 263              "Dropping.", cell->circ_id);
 264     return;
 265   }
 266
 267   if (circ->n_circ_id != cell->circ_id) {
 268     log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,
 269            "got created cell from Tor client? Closing.");
 270     circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL);
 271     return;
 272   }
 273
 274   if (CIRCUIT_IS_ORIGIN(circ)) { /* we're the OP. Handshake this. */
 275     origin_circuit_t *origin_circ = TO_ORIGIN_CIRCUIT(circ);
 276     int err_reason = 0;
 277     log_debug(LD_OR,"at OP. Finishing handshake.");
 278     if ((err_reason = circuit_finish_handshake(origin_circ, cell->command,
 279                                  cell->payload)) < 0) {
 280       log_warn(LD_OR,"circuit_finish_handshake failed.");
 281       circuit_mark_for_close(circ, -err_reason);
 282       return;
 283     }
 284     log_debug(LD_OR,"Moving to next skin.");
 285     if ((err_reason = circuit_send_next_onion_skin(origin_circ)) < 0) {
 286       log_info(LD_OR,"circuit_send_next_onion_skin failed.");
 287       /* XXX push this circuit_close lower */
 288       circuit_mark_for_close(circ, -err_reason);
 289       return;
 290     }
 291   } else { /* pack it into an extended relay cell, and send it. */
 292     log_debug(LD_OR,
 293               "Converting created cell to extended relay cell, sending.");
 294     relay_send_command_from_edge(0, circ, RELAY_COMMAND_EXTENDED,
 295                                  cell->payload, ONIONSKIN_REPLY_LEN,
 296                                  NULL);
 297   }
 298 }
 299
 300 /** Process a 'relay' <b>cell</b> that just arrived from <b>conn</b>. Make sure
 301  * it came in with a recognized circ_id. Pass it on to
 302  * circuit_receive_relay_cell() for actual processing.
 303  */
 304 static void
 305 command_process_relay_cell(cell_t *cell, or_connection_t *conn)
 306 {
 307   circuit_t *circ;
 308   int reason, direction;
 309
 310   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 311
 312   if (!circ) {
 313     log_debug(LD_OR,
 314               "unknown circuit %d on connection from %s:%d. Dropping.",
 315               cell->circ_id, conn->_base.address, conn->_base.port);
 316     return;
 317   }
 318
 319   if (circ->state == CIRCUIT_STATE_ONIONSKIN_PENDING) {
 320     log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,"circuit in create_wait. Closing.");
 321     circuit_mark_for_close(circ, END_CIRC_REASON_TORPROTOCOL);
 322     return;
 323   }
 324
 325   if (!CIRCUIT_IS_ORIGIN(circ) &&
 326       cell->circ_id == TO_OR_CIRCUIT(circ)->p_circ_id)
 327     direction = CELL_DIRECTION_OUT;
 328   else
 329     direction = CELL_DIRECTION_IN;
 330
 331   if ((reason = circuit_receive_relay_cell(cell, circ, direction)) < 0) {
 332     log_fn(LOG_PROTOCOL_WARN,LD_PROTOCOL,"circuit_receive_relay_cell "
 333            "(%s) failed. Closing.",
 334            direction==CELL_DIRECTION_OUT?"forward":"backward");
 335     circuit_mark_for_close(circ, -reason);
 336   }
 337 }
 338
 339 /** Process a 'destroy' <b>cell</b> that just arrived from
 340  * <b>conn</b>. Find the circ that it refers to (if any).
 341  *
 342  * If the circ is in state
 343  * onionskin_pending, then call onion_pending_remove() to remove it
 344  * from the pending onion list (note that if it's already being
 345  * processed by the cpuworker, it won't be in the list anymore; but
 346  * when the cpuworker returns it, the circuit will be gone, and the
 347  * cpuworker response will be dropped).
 348  *
 349  * Then mark the circuit for close (which marks all edges for close,
 350  * and passes the destroy cell onward if necessary).
 351  */
 352 static void
 353 command_process_destroy_cell(cell_t *cell, or_connection_t *conn)
 354 {
 355   circuit_t *circ;
 356   int reason;
 357
 358   circ = circuit_get_by_circid_orconn(cell->circ_id, conn);
 359   reason = (uint8_t)cell->payload[0];
 360   if (!circ) {
 361     log_info(LD_OR,"unknown circuit %d on connection from %s:%d. Dropping.",
 362              cell->circ_id, conn->_base.address, conn->_base.port);
 363     return;
 364   }
 365   log_debug(LD_OR,"Received for circID %d.",cell->circ_id);
 366
 367   if (!CIRCUIT_IS_ORIGIN(circ) &&
 368       cell->circ_id == TO_OR_CIRCUIT(circ)->p_circ_id) {
 369     /* the destroy came from behind */
 370     circuit_set_p_circid_orconn(TO_OR_CIRCUIT(circ), 0, NULL);
 371     circuit_mark_for_close(circ, reason|END_CIRC_REASON_FLAG_REMOTE);
 372   } else { /* the destroy came from ahead */
 373     circuit_set_n_circid_orconn(circ, 0, NULL);
 374     if (CIRCUIT_IS_ORIGIN(circ)) {
 375       circuit_mark_for_close(circ, reason|END_CIRC_REASON_FLAG_REMOTE);
 376     } else {
 377       char payload[1];
 378       log_debug(LD_OR, "Delivering 'truncated' back.");
 379       payload[0] = (char)reason;
 380       relay_send_command_from_edge(0, circ, RELAY_COMMAND_TRUNCATED,
 381                                    payload, sizeof(payload), NULL);
 382     }
 383   }
 384 }
 385