--- gvpe/src/connection.C 2008/08/10 01:34:36 1.73 +++ gvpe/src/connection.C 2008/08/15 17:45:12 1.79 @@ -674,7 +674,7 @@ void connection::connection_established () { - slog (L_TRACE, _("%s: possible connection establish (ictx %d, octx %d)"), conf->nodename, !!ictx, !!octx); + slog (L_NOISE, _("%s: possible connection establish (ictx %d, octx %d)"), conf->nodename, !!ictx, !!octx); if (ictx && octx) { @@ -762,7 +762,7 @@ pkt->setup (conf->id, pong ? ping_packet::PT_PONG : ping_packet::PT_PING); - slog (L_TRACE, ">>%d %s [%s]", conf->id, pong ? "PT_PONG" : "PT_PING", (const char *)si); + slog (L_TRACE, "%s << %s [%s]", conf->nodename, pong ? "PT_PONG" : "PT_PING", (const char *)si); send_vpn_packet (pkt, si, IPTOS_LOWDELAY); @@ -792,7 +792,7 @@ rsa_cache.gen (pkt->id, chg); rsa_encrypt (conf->rsa_key, chg, pkt->encr); - slog (L_TRACE, ">>%d PT_AUTH_REQ [%s]", conf->id, (const char *)si); + slog (L_TRACE, "%s >> PT_AUTH_REQ [%s]", conf->nodename, (const char *)si); send_vpn_packet (pkt, si, IPTOS_RELIABILITY | IPTOS_LOWDELAY); // rsa is very very costly @@ -810,7 +810,7 @@ pkt->hmac_set (octx); - slog (L_TRACE, ">>%d PT_AUTH_RES [%s]", conf->id, (const char *)si); + slog (L_TRACE, "%s >> PT_AUTH_RES [%s]", conf->nodename, (const char *)si); send_vpn_packet (pkt, si, IPTOS_RELIABILITY); // rsa is very very costly @@ -820,8 +820,8 @@ void connection::send_connect_info (int rid, const sockinfo &rsi, u8 rprotocols) { - slog (L_TRACE, ">>%d PT_CONNECT_INFO(%d,%s)", - conf->id, rid, (const char *)rsi); + slog (L_TRACE, "%s >> PT_CONNECT_INFO(%s,%s)", conf->nodename, + vpn->conns[rid - 1]->conf->nodename, (const char *)rsi); connect_info_packet *r = new connect_info_packet (conf->id, rid, rsi, rprotocols); @@ -862,7 +862,7 @@ { /*TODO*/ /* start the timer so we don't recurse endlessly */ w.start (1); - vpn->send_connect_request (conf->id); + vpn->send_connect_request (this); } else { @@ -1001,8 +1001,8 @@ { last_activity = ev_now (); - slog (L_NOISE, "<<%d received packet type %d from %d to %d.", - conf->id, pkt->typ (), pkt->src (), pkt->dst ()); + slog (L_NOISE, "%s >> received packet type %d from %d to %d.", + conf->nodename, pkt->typ (), pkt->src (), pkt->dst ()); if (connectmode == conf_node::C_DISABLED) return; @@ -1010,6 +1010,8 @@ switch (pkt->typ ()) { case vpn_packet::PT_PING: + slog (L_TRACE, "%s >> PT_PING", conf->nodename); + // we send pings instead of auth packets after some retries, // so reset the retry counter and establish a connection // when we receive a ping. @@ -1026,6 +1028,7 @@ break; case vpn_packet::PT_PONG: + slog (L_TRACE, "%s >> PT_PONG", conf->nodename); break; case vpn_packet::PT_RESET: @@ -1050,7 +1053,7 @@ { auth_req_packet *p = (auth_req_packet *) pkt; - slog (L_TRACE, "<<%d PT_AUTH_REQ(%d)", conf->id, p->initiate); + slog (L_TRACE, "%s << PT_AUTH_REQ(%s)", conf->nodename, p->initiate ? "initiate" : "reply"); if (p->chk_config () && !strncmp (p->magic, MAGIC, 8)) { @@ -1098,9 +1101,9 @@ case vpn_packet::PT_AUTH_RES: { - auth_res_packet *p = (auth_res_packet *) pkt; + auth_res_packet *p = (auth_res_packet *)pkt; - slog (L_TRACE, "<<%d PT_AUTH_RES", conf->id); + slog (L_TRACE, "%s << PT_AUTH_RES", conf->nodename); if (p->chk_config ()) { @@ -1145,8 +1148,9 @@ si = rsi; protocol = rsi.prot; - slog (L_INFO, _("%s(%s): connection established, protocol version %d.%d."), + slog (L_INFO, _("%s(%s): connection established (%s), protocol version %d.%d."), conf->nodename, (const char *)rsi, + is_direct ? "direct" : "routed", p->prot_major, p->prot_minor); connection_established (); @@ -1204,23 +1208,26 @@ // fast re-sync on source address changes, useful especially for tcp/ip //if (last_si_change < ev_now () + 5.) // { - si = rsi; - - slog (L_INFO, _("%s(%s): socket address changed to %s."), + slog (L_INFO, _("%s(%s): changing socket address to %s."), conf->nodename, (const char *)si, (const char *)rsi); + + si = rsi; // } //else // slog (L_INFO, _("%s(%s): accepted packet from %s, not (yet) redirecting traffic."), // conf->nodename, (const char *)si, (const char *)rsi); } } - else if (seqclass == 1) // silently ignore - slog (L_ERR, _("received duplicate packet (received %08lx, expected %08lx)\n" - "possible replay attack, or just packet duplication, ignoring."), seqno, iseqno.seq + 1); - else if (seqclass == 2) // reset + else if (seqclass == 1) // far history + slog (L_ERR, _("received very old packet (received %08lx, expected %08lx). " + "possible replay attack, or just packet duplication/delay, ignoring."), seqno, iseqno.seq + 1); + else if (seqclass == 2) // in-window duplicate, happens often on wireless + slog (L_DEBUG, _("received recent duplicated packet (received %08lx, expected %08lx). " + "possible replay attack, or just packet duplication, ignoring."), seqno, iseqno.seq + 1); + else if (seqclass == 3) // reset { - slog (L_ERR, _("received duplicate or out-of-sync packet (received %08lx, expected %08lx)\n" - "possible replay attack, or just massive packet loss, resetting connection."), seqno, iseqno.seq + 1); + slog (L_ERR, _("received out-of-sync (far future) packet (received %08lx, expected %08lx). " + "probably just massive packet loss, sending reset."), seqno, iseqno.seq + 1); send_reset (rsi); } @@ -1242,8 +1249,8 @@ connection *c = vpn->conns[p->id - 1]; conf->protocols = p->protocols; - slog (L_TRACE, "<<%d PT_CONNECT_REQ(%d) [%d]", - conf->id, p->id, c->ictx && c->octx); + slog (L_TRACE, "%s << PT_CONNECT_REQ(%s) [%d]", + conf->nodename, vpn->conns[p->id - 1]->conf->nodename, c->ictx && c->octx); if (c->ictx && c->octx) { @@ -1276,8 +1283,9 @@ protocol = best_protocol (c->conf->protocols & THISNODE->protocols & p->si.supported_protocols (c->conf)); p->si.upgrade_protocol (protocol, c->conf); - slog (L_TRACE, "<<%d PT_CONNECT_INFO(%d,%s) (%d)", - conf->id, p->id, (const char *)p->si, !c->ictx && !c->octx); + slog (L_TRACE, "%s << PT_CONNECT_INFO(%s,%s) [%d]", + conf->nodename, vpn->conns[p->id - 1]->conf->nodename, + (const char *)p->si, !c->ictx && !c->octx); const sockinfo &dsi = forward_si (p->si); @@ -1326,7 +1334,8 @@ { connect_req_packet *p = new connect_req_packet (conf->id, id, conf->protocols); - slog (L_TRACE, ">>%d PT_CONNECT_REQ(%d)", conf->id, id); + slog (L_TRACE, "%s >> PT_CONNECT_REQ(%s)", + conf->nodename, vpn->conns[id - 1]->conf->nodename); p->hmac_set (octx); send_vpn_packet (p, si);