Index: channels/chan_sip.c
===================================================================
RCS file: /usr/cvsroot/asterisk/channels/chan_sip.c,v
retrieving revision 1.688
diff -u -r1.688 chan_sip.c
--- channels/chan_sip.c	22 Mar 2005 19:09:47 -0000	1.688
+++ channels/chan_sip.c	23 Mar 2005 19:57:34 -0000
@@ -114,28 +114,29 @@
 static const char config[] = "sip.conf";
 static const char notify_config[] = "sip_notify.conf";
 
-#define SIP_REGISTER	1
-#define SIP_OPTIONS	2
-#define SIP_NOTIFY	3
-#define SIP_INVITE	4
-#define SIP_ACK		5
-#define SIP_PRACK	6
-#define SIP_BYE		7
-#define SIP_REFER	8
-#define SIP_SUBSCRIBE	9
-#define SIP_MESSAGE	10
-#define SIP_UPDATE	11
-#define SIP_INFO	12
-#define SIP_CANCEL	13
-#define SIP_PUBLISH	14
-#define SIP_MAX_METHODS	14
-#define SIP_RESPONSE	100
+#define SIP_RESPONSE	1
+#define SIP_REGISTER	2
+#define SIP_OPTIONS	3
+#define SIP_NOTIFY	4
+#define SIP_INVITE	5
+#define SIP_ACK		6
+#define SIP_PRACK	7
+#define SIP_BYE		8
+#define SIP_REFER	9
+#define SIP_SUBSCRIBE	10
+#define SIP_MESSAGE	11
+#define SIP_UPDATE	12
+#define SIP_INFO	13
+#define SIP_CANCEL	14
+#define SIP_PUBLISH	15
+#define SIP_MAX_METHODS	15
 
 const struct  cfsip_methods { 
 	int id;
 	char *text;
 } sip_methods[] = {
 	{ 0,		"-UNKNOWN-" },
+	{ SIP_RESPONSE,	"SIP/2.0" },
 	{ SIP_REGISTER,	"REGISTER" },
  	{ SIP_OPTIONS,	"OPTIONS" },
 	{ SIP_NOTIFY,	"NOTIFY" },
@@ -282,6 +283,7 @@
 	int lines;						/* SDP Content */
 	char *line[SIP_MAX_LINES];
 	char data[SIP_MAX_PACKET];
+	int debug;		/* Debug flag for this packet */
 };
 
 struct sip_pkt;
@@ -694,6 +696,10 @@
 int find_sip_method(char *msg)
 {
 	int i, res = 0;
+	
+	if (!msg || ast_strlen_zero(msg))
+		return 0;
+
 	/* Strictly speaking, SIP methods are case SENSITIVE, but we don't check */
 	for (i=1; i< SIP_MAX_METHODS && !res; i++) {
 		if (!strcasecmp(sip_methods[i].text, msg)) 
@@ -730,9 +736,9 @@
 	int res;
 	char iabuf[INET_ADDRSTRLEN];
 	if (ast_test_flag(p, SIP_NAT) & SIP_NAT_ROUTE)
-	    res=sendto(sipsock, data, len, 0, (struct sockaddr *)&p->recv, sizeof(struct sockaddr_in));
+		res=sendto(sipsock, data, len, 0, (struct sockaddr *)&p->recv, sizeof(struct sockaddr_in));
 	else
-	    res=sendto(sipsock, data, len, 0, (struct sockaddr *)&p->sa, sizeof(struct sockaddr_in));
+		res=sendto(sipsock, data, len, 0, (struct sockaddr *)&p->sa, sizeof(struct sockaddr_in));
 	if (res != len) {
 		ast_log(LOG_WARNING, "sip_xmit of %p (len %d) to %s returned %d: %s\n", data, len, ast_inet_ntoa(iabuf, sizeof(iabuf), p->sa.sin_addr), res, strerror(errno));
 	}
@@ -1030,7 +1036,7 @@
 	return res;
 }
 
-static void parse(struct sip_request *req);
+static void parse_request(struct sip_request *req);
 static char *get_header(struct sip_request *req, char *name);
 static void copy_request(struct sip_request *dst,struct sip_request *src);
 
@@ -1039,7 +1045,7 @@
 	memset(dst, 0, sizeof(*dst));
 	memcpy(dst->data, src->data, sizeof(dst->data));
 	dst->len = src->len;
-	parse(dst);
+	parse_request(dst);
 }
 /*--- send_response: Transmit response on SIP request---*/
 static int send_response(struct sip_pvt *p, struct sip_request *req, int reliable, int seqno)
@@ -1897,9 +1903,9 @@
 		needcancel = 1;
 	/* Disconnect */
 	p = ast->tech_pvt;
-        if (p->vad) {
-            ast_dsp_free(p->vad);
-        }
+	if (p->vad) {
+		ast_dsp_free(p->vad);
+	}
 	p->owner = NULL;
 	ast->tech_pvt = NULL;
 
@@ -2550,26 +2556,22 @@
 	char *callid;
 	char tmp[256] = "";
 	char iabuf[INET_ADDRSTRLEN];
-	char *cmd;
 	char *tag = "", *c;
 
 	callid = get_header(req, "Call-ID");
+	if (ast_strlen_zero(callid)) {
+		ast_log(LOG_WARNING, "Call missing call ID from '%s' - Totally ignoring this packet.\n", ast_inet_ntoa(iabuf, sizeof(iabuf), sin->sin_addr));
+		return NULL;
+	}
 
 	if (pedanticsipchecking) {
-		/* In principle Call-ID's uniquely identify a call, however some vendors
-		   (i.e. Pingtel) send multiple calls with the same Call-ID and different
-		   tags in order to simplify billing.  The RFC does state that we have to
-		   compare tags in addition to the call-id, but this generate substantially
-		   more overhead which is totally unnecessary for the vast majority of sane
-		   SIP implementations, and thus Asterisk does not enable this behavior
-		   by default. Short version: You'll need this option to support conferencing
-		   on the pingtel */
-		strncpy(tmp, req->header[0], sizeof(tmp) - 1);
-		cmd = tmp;
-		c = strchr(tmp, ' ');
-		if (c)
-			*c = '\0';
-		if (!strcasecmp(cmd, "SIP/2.0"))
+		/* In principle Call-ID's uniquely identify a call,  but with
+		   a forking proxy, each fork has a unique identify consisting
+		   of call-ID and From and To tags. Turn on pedanticsipchecking
+		   to support using a forking proxy with Asterisk.
+		*/
+		
+		if (req->method == SIP_RESPONSE)
 			strncpy(tmp, get_header(req, "To"), sizeof(tmp) - 1);
 		else
 			strncpy(tmp, get_header(req, "From"), sizeof(tmp) - 1);
@@ -2583,23 +2585,29 @@
 			
 	}
 		
-	if (ast_strlen_zero(callid)) {
-		ast_log(LOG_WARNING, "Call missing call ID from '%s'\n", ast_inet_ntoa(iabuf, sizeof(iabuf), sin->sin_addr));
-		return NULL;
-	}
 	ast_mutex_lock(&iflock);
 	p = iflist;
+	/* The matching here depends on the method, really. */
 	while(p) {
-		if (!strcmp(p->callid, callid) && 
-			(!pedanticsipchecking || !tag || ast_strlen_zero(p->theirtag) || !strcmp(p->theirtag, tag))) {
+		int found = 0;
+		/* For register, callid is enough to match on */
+		if (req->method  == SIP_REGISTER)	/* Incoming REGISTER */
+			found = (!strcmp(p->callid, callid));
+		else
+			found =  (!strcmp(p->callid, callid) && (!pedanticsipchecking || !tag || ast_strlen_zero(p->theirtag) || !strcmp(p->theirtag, tag)  ) );
+		if (found) {
 			/* Found the call */
 			ast_mutex_lock(&p->lock);
 			ast_mutex_unlock(&iflock);
+			if (option_debug > 2)
+				ast_log(LOG_DEBUG, "Found matching transaction for incoming packet: %s\n", p->callid);
 			return p;
 		}
 		p = p->next;
 	}
 	ast_mutex_unlock(&iflock);
+	if (option_debug > 2)
+		ast_log(LOG_DEBUG, "Did not find matching transaction, allocating new transaction: %s\n", callid);
 	p = sip_alloc(callid, sin, 1);
 	if (p)
 		ast_mutex_lock(&p->lock);
@@ -2726,12 +2734,15 @@
 	return t; 
 }
 
-/*--- parse: Parse a SIP message ----*/
-static void parse(struct sip_request *req)
+static int determine_firstline_parts( struct sip_request *req );
+
+/*--- parse_request: Parse a SIP message ----*/
+static void parse_request(struct sip_request *req)
 {
 	/* Divide fields by NULL's */
 	char *c;
 	int f = 0;
+
 	c = req->data;
 
 	/* First header starts immediately */
@@ -2741,16 +2752,15 @@
 			/* We've got a new header */
 			*c = 0;
 
-#if 0
-			printf("Header: %s (%d)\n", req->header[f], strlen(req->header[f]));
-#endif			
+			if(option_debug > 4)
+				ast_log(LOG_DEBUG, "Header: %s (%d)\n", req->header[f], strlen(req->header[f]));
 			if (ast_strlen_zero(req->header[f])) {
 				/* Line by itself means we're now in content */
 				c++;
 				break;
 			}
 			if (f >= SIP_MAX_HEADERS - 1) {
-				ast_log(LOG_WARNING, "Too many SIP headers...\n");
+				ast_log(LOG_WARNING, "Too many SIP headers. Ignoring\n" );
 			} else
 				f++;
 			req->header[f] = c + 1;
@@ -2771,9 +2781,8 @@
 		if (*c == '\n') {
 			/* We've got a new line */
 			*c = 0;
-#if 0
-			printf("Line: %s (%d)\n", req->line[f], strlen(req->line[f]));
-#endif			
+			if(option_debug > 4)
+				ast_log(LOG_DEBUG, "Line: %s (%d)\n", req->line[f], strlen(req->line[f]));
 			if (f >= SIP_MAX_LINES - 1) {
 				ast_log(LOG_WARNING, "Too many SDP lines...\n");
 			} else
@@ -2791,6 +2800,8 @@
 	req->lines = f;
 	if (*c) 
 		ast_log(LOG_WARNING, "Odd content, extra stuff left over ('%s')\n", c);
+	/* Split up the first line parts */
+	determine_firstline_parts(req);
 }
 
 /*--- process_sdp: Process SIP SDP ---*/
@@ -3492,13 +3503,13 @@
 	return __transmit_response(p, msg, req, 0);
 }
 
-/*--- transmit_response: Transmit response, Make sure you get a reply */
+/*--- transmit_response_reliable: Transmit response, Make sure you get a reply */
 static int transmit_response_reliable(struct sip_pvt *p, char *msg, struct sip_request *req, int fatal)
 {
 	return __transmit_response(p, msg, req, fatal ? 2 : 1);
 }
 
-/*--- append_date: Append date to SIP message ---*/
+/*--- append_date: Append date header to SIP message ---*/
 static void append_date(struct sip_request *req)
 {
 	char tmpdat[256];
@@ -3802,20 +3813,23 @@
 }
 
 /*--- determine_firstline_parts: parse first line of incoming SIP request */
+/* For a response, rlPart1 is SIP/2.0, rlPart2 is response code
+   for a request, rlPart1 is method, rlPart2 is URI. 
+ */
 static int determine_firstline_parts( struct sip_request *req ) 
 {
 	char *e, *cmd;
 	int len;
   
-	cmd = req->header[0];
-	while(*cmd && (*cmd < 33)) {
+	cmd = req->header[0];	/* First header line */
+	while(*cmd && (*cmd < 33)) {	/* Skip spaces */
 		cmd++;
 	}
 	if (!*cmd) {
-		return -1;
+		return -1;	/* Nothing? return error */
 	}
 	e = cmd;
-	while(*e && (*e > 32)) {
+	while(*e && (*e > 32)) {	/* Find next part */
 		e++;
 	}
 	/* Get the command */
@@ -3823,26 +3837,25 @@
 		*e = '\0';
 		e++;
 	}
-	req->rlPart1 = cmd;
+	req->rlPart1 = cmd;	/* We have the first part, either SIP/2.0 or a method */
 	while( *e && ( *e < 33 ) ) {
 		e++; 
 	}
 	if( !*e ) {
-		return -1;
+		return -1;	/* No second part? return error */
 	}
     
-	if ( !strcasecmp(cmd, "SIP/2.0") ) {
-		/* We have a response */
-		req->rlPart2 = e;
+	if ( !strcasecmp(cmd, "SIP/2.0") ) { /* We have a response */
+		req->rlPart2 = e;		/* Response code and text */
 		len = strlen( req->rlPart2 );
-		if( len < 2 ) { 
+		if( len < 2 ) { 	/* Too short, error */
 			return -1;
 		}
 		e+= len - 1;
 		while( *e && *e < 33 ) {
 			e--; 
 		}
-		*(++e)= '\0';
+		*(++e)= '\0';		/* Remove the text from the response code */
 	} else {
 		/* We have a request */
 		if( *e == '<' ) { 
@@ -3852,6 +3865,7 @@
 			}  
 		}
 		req->rlPart2 = e;	/* URI */
+		/* The request is always followd by SIP/2.0 - remove that part */
 		if( ( e= strrchr( req->rlPart2, 'S' ) ) == NULL ) {
 			return -1;
 		}
@@ -3884,10 +3898,9 @@
 	add_sdp(&req, p);
 	/* Use this as the basis */
 	copy_request(&p->initreq, &req);
-	parse(&p->initreq);
+	parse_request(&p->initreq);
 	if (sip_debug_test_pvt(p))
 		ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-	determine_firstline_parts(&p->initreq);
 	p->lastinvite = p->ocseq;
 	ast_set_flag(p, SIP_OUTGOING);
 	return send_request(p, &req, 1, p->ocseq);
@@ -3898,6 +3911,7 @@
 {
 	char stripped[256]="";
 	char *c, *n;
+
 	strncpy(stripped, get_header(req, "Contact"), sizeof(stripped) - 1);
 	c = strchr(stripped, '<');
 	if (c) 
@@ -4127,10 +4141,9 @@
 	if (!p->initreq.headers) {
 		/* Use this as the basis */
 		copy_request(&p->initreq, &req);
-		parse(&p->initreq);
+		parse_request(&p->initreq);
 		if (sip_debug_test_pvt(p))
 			ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-		determine_firstline_parts(&p->initreq);
 	}
 	p->lastinvite = p->ocseq;
 	return send_request(p, &req, init ? 2 : 1, p->ocseq);
@@ -4271,24 +4284,22 @@
 	if (!p->initreq.headers) {
 		/* Use this as the basis */
 		copy_request(&p->initreq, &req);
-		parse(&p->initreq);
+		parse_request(&p->initreq);
 		if (sip_debug_test_pvt(p))
 			ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-		determine_firstline_parts(&p->initreq);
 	}
-
 	return send_request(p, &req, 1, p->ocseq);
 }
 
+/*--- transmit_sip_request: Yes, transmit SIP request :-) */
 static int transmit_sip_request(struct sip_pvt *p,struct sip_request *req)
 {
 	if (!p->initreq.headers) {
 		/* Use this as the basis */
 		copy_request(&p->initreq, req);
-		parse(&p->initreq);
+		parse_request(&p->initreq);
 		if (sip_debug_test_pvt(p))
 			ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-		determine_firstline_parts(&p->initreq);
 	}
 
 	return send_request(p, req, 0, p->ocseq);
@@ -4318,15 +4329,15 @@
 	if (!p->initreq.headers) {
 		/* Use this as the basis */
 		copy_request(&p->initreq, &req);
-		parse(&p->initreq);
+		parse_request(&p->initreq);
 		if (sip_debug_test_pvt(p))
 			ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-		determine_firstline_parts(&p->initreq);
 	}
 
 	return send_request(p, &req, 1, p->ocseq);
 }
 
+/*--- regstate2str: Convert registration state to string for sip show registry */
 static char *regstate2str(int regstate)
 {
 	switch(regstate) {
@@ -4574,10 +4585,9 @@
 	add_header(&req, "Content-Length", "0");
 	add_blank_header(&req);
 	copy_request(&p->initreq, &req);
-	parse(&p->initreq);
+	parse_request(&p->initreq);
 	if (sip_debug_test_pvt(p))
 		ast_verbose("%d headers, %d lines\n", p->initreq.headers, p->initreq.lines);
-	determine_firstline_parts(&p->initreq);
 	r->regstate=auth?REG_STATE_AUTHSENT:REG_STATE_REGSENT;
 	return send_request(p, &req, 2, p->ocseq);
 }
@@ -5177,6 +5187,7 @@
 		char *response ="";
 		char *resp_uri ="";
 
+
 		/* Find their response among the mess that we'r sent for comparison */
 		strncpy(tmp, authtoken, sizeof(tmp) - 1);
 		c = tmp;
@@ -5296,24 +5307,24 @@
 			ASTOBJ_UNREF(peer,sip_destroy_peer);
 	}
 	if (peer) {
-			if (!ast_test_flag(peer, SIP_DYNAMIC)) {
-				ast_log(LOG_NOTICE, "Peer '%s' is trying to register, but not configured as host=dynamic\n", peer->name);
-			} else {
-				ast_copy_flags(p, peer, SIP_NAT);
-				transmit_response(p, "100 Trying", req);
-				if (!(res = check_auth(p, req, p->randdata, sizeof(p->randdata), peer->name, peer->secret, peer->md5secret, SIP_REGISTER, uri, 0, ignore))) {
-					sip_cancel_destroy(p);
-					if (parse_contact(p, peer, req)) {
-						ast_log(LOG_WARNING, "Failed to parse contact info\n");
-					} else {
-						update_peer(peer, p->expiry);
-						/* Say OK and ask subsystem to retransmit msg counter */
-						transmit_response_with_date(p, "200 OK", req);
-						peer->lastmsgssent = -1;
-						res = 0;
-					}
-				} 
-			}
+		if (!ast_test_flag(peer, SIP_DYNAMIC)) {
+			ast_log(LOG_NOTICE, "Peer '%s' is trying to register, but not configured as host=dynamic\n", peer->name);
+		} else {
+			ast_copy_flags(p, peer, SIP_NAT);
+			transmit_response(p, "100 Trying", req);
+			if (!(res = check_auth(p, req, p->randdata, sizeof(p->randdata), peer->name, peer->secret, peer->md5secret, SIP_REGISTER, uri, 0, ignore))) {
+				sip_cancel_destroy(p);
+				if (parse_contact(p, peer, req)) {
+					ast_log(LOG_WARNING, "Failed to parse contact info\n");
+				} else {
+					update_peer(peer, p->expiry);
+					/* Say OK and ask subsystem to retransmit msg counter */
+					transmit_response_with_date(p, "200 OK", req);
+					peer->lastmsgssent = -1;
+					res = 0;
+				}
+			} 
+		}
 	}
 	if (!peer && autocreatepeer) {
 		/* Create peer if we have autocreate mode enabled */
@@ -8267,6 +8278,7 @@
 	int gotdest;
 	struct ast_frame af = { AST_FRAME_NULL, };
 
+	/* Are we getting an invite from ourselves? */
 	if (ast_test_flag(p, SIP_OUTGOING) && p->owner && (p->owner->_state != AST_STATE_UP)) {
 		/* This is a call to ourself.  Send ourselves an error code and stop
 		   processing immediately, as SIP really has no good mechanism for
@@ -8275,6 +8287,7 @@
 		/* We do NOT destroy p here, so that our response will be accepted */
 		return 0;
 	}
+
 	if (!ignore) {
 		/* Use this as the basis */
 		if (debug)
@@ -8300,7 +8313,7 @@
 			}
 		}
 	} else if (debug)
-		ast_verbose("Ignoring this request\n");
+		ast_verbose("Ignoring this INVITE request\n");
 	if (!p->lastinvite && !ignore && !p->owner) {
 		/* Handle authentication if this is our first invite */
 		res = check_user(p, req, SIP_INVITE, e, 1, sin, ignore);
@@ -8743,23 +8756,25 @@
 	int res = 0;
 	char iabuf[INET_ADDRSTRLEN];
 
+	/* Go ahead and free RTP port */
+	if (p->rtp) {
+		ast_rtp_destroy(p->rtp);
+		p->rtp = NULL;
+	}
+	if (p->vrtp) {
+		ast_rtp_destroy(p->vrtp);
+		p->vrtp = NULL;
+	}
+
 	/* Use this as the basis */
 	if (debug)
 		ast_verbose("Using latest request as basis request\n");
+
 	copy_request(&p->initreq, req);
 	check_via(p, req);
 	if ((res = register_verify(p, sin, req, e, ignore)) < 0) 
 		ast_log(LOG_NOTICE, "Registration from '%s' failed for '%s'\n", get_header(req, "To"), ast_inet_ntoa(iabuf, sizeof(iabuf), sin->sin_addr));
 	if (res < 1) {
-		/* Go ahead and free RTP port */
-		if (p->rtp) {
-			ast_rtp_destroy(p->rtp);
-			p->rtp = NULL;
-		}
-		if (p->vrtp) {
-			ast_rtp_destroy(p->vrtp);
-			p->vrtp = NULL;
-		}
 		/* Destroy the session, but keep us around for just a bit in case they don't
 		   get our 200 OK */
 		sip_scheddestroy(p, 15*1000);
@@ -8768,6 +8783,7 @@
 }
 /*--- handle_request: Handle SIP requests (methods) ---*/
 /*      this is where all incoming requests go first   */
+/*	Returns -1 on error */
 static int handle_request(struct sip_pvt *p, struct sip_request *req, struct sockaddr_in *sin, int *recount, int *nounlock)
 {
 	/* Called with p->lock held, as well as p->owner->lock if appropriate, keeping things
@@ -8794,33 +8810,32 @@
 	cmd = req->header[0];
 
 	/* Must have Cseq */
-	if (ast_strlen_zero(cmd) || ast_strlen_zero(cseq))
+	if (ast_strlen_zero(cseq))
 		return -1;
 	if (sscanf(cseq, "%i%n", &seqno, &len) != 1) {
-		ast_log(LOG_DEBUG, "No seqno in '%s'\n", cmd);
+		ast_log(LOG_DEBUG, "SIP protocol error: No seqno in '%s'\n", cmd);
 		return -1;
 	}
 	/* Get the command */
 	cseq += len;
 
-	/* Determine the request URI for sip, sips or tel URIs */
-	if( determine_firstline_parts( req ) < 0 ) {
-		return -1; 
-	}
-	cmd = req->rlPart1;
-	e = req->rlPart2;
+	cmd = req->rlPart1;	/* Method for SIP requests, SIP/2.0 for responses */
+	e = req->rlPart2;	/* URI for requests, response code for responses */
+	if (ast_strlen_zero(cmd))	/* Must have a CMD */
+		return -1;
 
 	/* Save useragent of the client */
 	useragent = get_header(req, "User-Agent");
-	strncpy(p->useragent, useragent, sizeof(p->useragent)-1);
+	if (!ast_strlen_zero(useragent))
+		strncpy(p->useragent, useragent, sizeof(p->useragent)-1);
+
 
 	
 	/* Find out SIP method for incoming request */
-	if (!strcasecmp(cmd, "SIP/2.0")) {	/* Response to our request */
-		p->method = SIP_RESPONSE;
+	if (req->method == SIP_RESPONSE) {	/* Response to our request */
 		/* Response to our request -- Do some sanity checks */	
 		if (!p->initreq.headers) {
-			ast_log(LOG_DEBUG, "That's odd...  Got a response on a call we dont know about.\n");
+			ast_log(LOG_DEBUG, "That's odd...  Got a response on a call we dont know about. (%s)\n", e);
 			ast_set_flag(p, SIP_NEEDDESTROY);	
 			return 0;
 		} else if (p->ocseq && (p->ocseq < seqno)) {
@@ -8846,25 +8861,28 @@
 	/* New SIP request coming in 
 	   (could be new request in existing SIP dialog as well...) 
 	 */			
-	p->method = find_sip_method(cmd);	/* Find out which SIP method they are using */
+	p->method = req->method;	/* Find out which SIP method they are using */
+
 	if (option_debug > 2)
 		ast_log(LOG_DEBUG, "**** Received %s (%d) - Command in SIP %s\n", sip_methods[p->method].text, sip_methods[p->method].id, cmd); 
 
 	if (p->icseq && (p->icseq > seqno)) {
-		ast_log(LOG_DEBUG, "Ignoring too old SIP packet packet %d (expecting >= %d)\n", seqno, p->icseq);
+		ast_log(LOG_DEBUG, "Ignoring too old SIP %s packet packet with seqno %d (expecting >= %d)\n", cmd, seqno, p->icseq);
 		return -1;
-	} else if (p->icseq && (p->icseq == seqno) && (strcasecmp(cmd, "CANCEL") || ast_test_flag(p, SIP_ALREADYGONE))) {
+	} else if (p->icseq && (p->icseq == seqno) && (p->method != SIP_CANCEL || ast_test_flag(p, SIP_ALREADYGONE))) {
 		/* ignore means "don't do anything with it" but still have to 
 		   respond appropriately.  We do this if we receive a repeat of
 		   the last sequence number  */
-		ignore=1;
+		ast_log(LOG_DEBUG, "Ignoring SIP message because of retransmit (%s Seqno %d, ours %d)\n", sip_methods[p->method].text, p->icseq, seqno);
+		ignore=2;
 	}
-		
+
 	if (seqno >= p->icseq)
 		/* Next should follow monotonically (but not necessarily 
 		   incrementally -- thanks again to the genius authors of SIP --
 		   increasing */
 		p->icseq = seqno;
+		
 
 	/* Find their tag if we haven't got it */
 	if (ast_strlen_zero(p->theirtag)) {
@@ -8959,7 +8977,6 @@
 	int len;
 	int nounlock;
 	int recount = 0;
-	int debug;
 	char iabuf[INET_ADDRSTRLEN];
 
 	len = sizeof(sin);
@@ -8977,13 +8994,14 @@
 	}
 	req.data[res] = '\0';
 	req.len = res;
-	debug = sip_debug_test_addr(&sin);
+	req.debug = sip_debug_test_addr(&sin);
 	if (pedanticsipchecking)
-		req.len = lws2sws(req.data, req.len);
-	if (debug)
+		req.len = lws2sws(req.data, req.len);	/* Fix multiline headers */
+	if (req.debug)
 		ast_verbose("\n<-- SIP read from %s:%d: \n%s\n", ast_inet_ntoa(iabuf, sizeof(iabuf), sin.sin_addr), ntohs(sin.sin_port), req.data);
-	parse(&req);
-	if (debug) {
+	parse_request(&req);
+	req.method = find_sip_method(req.rlPart1);
+	if (req.debug) {
 		ast_verbose("--- (%d headers %d lines)", req.headers, req.lines);
 		if (req.headers + req.lines == 0) 
 			ast_verbose(" Nat keepalive ");