Browse code

Merge 8c9cac93bf5c60d922f5bbe530b72251176e7631 into 298aeb7f93bfa75ec78bc941f2c76167525b2e61

Julien Chavanton authored on 24/09/2020 20:29:29 • GitHub committed on 24/09/2020 20:29:29
Showing 2 changed files
... ...
@@ -1267,6 +1267,19 @@ dlg_cell_t *dlg_get_msg_dialog(sip_msg_t *msg)
1267 1267
 	return dlg_lookup_msg_dialog(msg, NULL);
1268 1268
 }
1269 1269
 
1270
+
1271
+void extra_ack_debug_info(const char *s, struct sip_msg* req, int dir) {
1272
+	if (!req || req->first_line.u.request.method_value != METHOD_ACK)
1273
+		return;
1274
+	if (parse_headers(req,HDR_CALLID_F,0)<0 || !req->callid) {
1275
+		LM_ERR("[ACK][%d] %s >>> can not parse call-id !\n", dir, s);
1276
+	}
1277
+	if (parse_headers(req,HDR_TO_F,0)<0 || !req->to) {
1278
+		LM_ERR("[ACK][%d] %s >>> can not parse to-tag call-id[%.*s]\n", dir, s, req->callid->body.len, req->callid->body.s);
1279
+	}
1280
+	LM_INFO("[ACK][%d] %s >>> call-id[%.*s] to-tag[%.*s]\n", dir, s, req->callid->body.len, req->callid->body.s, req->to->body.len, req->to->body.s);
1281
+}
1282
+
1270 1283
 /*!
1271 1284
  * \brief Function that is registered as RR callback for dialog tracking
1272 1285
  *
... ...
@@ -1291,6 +1304,8 @@ void dlg_onroute(struct sip_msg* req, str *route_params, void *param)
1291 1304
 	dlg = dlg_get_ctx_dialog();
1292 1305
 	if (dlg!=NULL) {
1293 1306
 		dlg_release(dlg);
1307
+		if (req->first_line.u.request.method_value == METHOD_ACK)
1308
+			LM_NOTICE(" DIALOG skipping dlg!=null call-id[%.*s]\n", dlg->callid.len, dlg->callid.s);
1294 1309
 		return;
1295 1310
 	}
1296 1311
 
... ...
@@ -1309,13 +1324,17 @@ void dlg_onroute(struct sip_msg* req, str *route_params, void *param)
1309 1324
 	if ( seq_match_mode!=SEQ_MATCH_NO_ID ) {
1310 1325
 		if( d_rrb.get_route_param( req, &rr_param, &val)!=0) {
1311 1326
 			LM_DBG("Route param '%.*s' not found\n", rr_param.len,rr_param.s);
1312
-			if (seq_match_mode==SEQ_MATCH_STRICT_ID )
1327
+			if (seq_match_mode==SEQ_MATCH_STRICT_ID ) {
1328
+				extra_ack_debug_info("seq_match_mode STRICT_ID (#1)", req, dir);
1313 1329
 				return;
1330
+			}
1314 1331
 		} else {
1315 1332
 			LM_DBG("route param is '%.*s' (len=%d)\n",val.len,val.s,val.len);
1316 1333
 
1317
-			if ( parse_dlg_rr_param( val.s, val.s+val.len, &h_entry, &h_id)<0 )
1334
+			if ( parse_dlg_rr_param( val.s, val.s+val.len, &h_entry, &h_id)<0 ) {
1335
+				extra_ack_debug_info("parse_dlg_rr_param failed", req, dir);
1318 1336
 				return;
1337
+			}
1319 1338
 
1320 1339
 			dlg = dlg_lookup(h_entry, h_id);
1321 1340
 			if (dlg==0) {
... ...
@@ -1326,12 +1345,15 @@ void dlg_onroute(struct sip_msg* req, str *route_params, void *param)
1326 1345
 					req->first_line.u.request.method.s,
1327 1346
 					val.len,val.s, h_entry, h_id,
1328 1347
 					req->callid->body.len, req->callid->body.s);
1329
-				if (seq_match_mode==SEQ_MATCH_STRICT_ID )
1348
+				if (seq_match_mode==SEQ_MATCH_STRICT_ID ) {
1349
+					extra_ack_debug_info("seq_match_mode STRICT_ID (#2)", req, dir);
1330 1350
 					return;
1351
+				}
1331 1352
 			} else {
1332 1353
 				if (pre_match_parse( req, &callid, &ftag, &ttag, 1)<0) {
1333 1354
 					// lookup_dlg has incremented the ref count by 1
1334 1355
 					dlg_release(dlg);
1356
+					extra_ack_debug_info("pre_match_parse failed (#1)", req, dir);
1335 1357
 					return;
1336 1358
 				}
1337 1359
 				if (match_dialog( dlg, &callid, &ftag, &ttag, &dir )==0) {
... ...
@@ -1356,22 +1378,27 @@ void dlg_onroute(struct sip_msg* req, str *route_params, void *param)
1356 1378
 					dlg = 0;
1357 1379
 					dir = DLG_DIR_NONE;
1358 1380
 
1359
-					if (seq_match_mode==SEQ_MATCH_STRICT_ID )
1381
+					if (seq_match_mode==SEQ_MATCH_STRICT_ID ) {
1382
+						extra_ack_debug_info("seq_match_mode MATCH_STRICT_ID (#3)", req, dir);
1360 1383
 						return;
1384
+					}
1361 1385
 				}
1362 1386
 			}
1363 1387
 		}
1364 1388
 	}
1365 1389
 
1366 1390
 	if (dlg==0) {
1367
-		if (pre_match_parse(req, &callid, &ftag, &ttag, 1)<0)
1391
+		if (pre_match_parse(req, &callid, &ftag, &ttag, 1)<0) {
1392
+			extra_ack_debug_info("pre_match_parse failed (#2)", req, dir);
1368 1393
 			return;
1394
+		}
1369 1395
 		/* TODO - try to use the RR dir detection to speed up here the
1370 1396
 		 * search -bogdan */
1371 1397
 		dlg = get_dlg(&callid, &ftag, &ttag, &dir);
1372 1398
 		if (dlg==0){
1373 1399
 			LM_DBG("Callid '%.*s' not found\n",
1374 1400
 				req->callid->body.len, req->callid->body.s);
1401
+			extra_ack_debug_info("get_dlg not found", req, dir);
1375 1402
 			return;
1376 1403
 		}
1377 1404
 	}
... ...
@@ -1416,6 +1443,10 @@ void dlg_onroute(struct sip_msg* req, str *route_params, void *param)
1416 1443
 	}
1417 1444
 
1418 1445
 	next_state_dlg( dlg, event, &old_state, &new_state, &unref);
1446
+	if (new_state != DLG_STATE_CONFIRMED) {
1447
+		extra_ack_debug_info("state not changed", req, dir);
1448
+		LM_INFO("state not changed old[%d]new[%d]\n", old_state, new_state);
1449
+	}
1419 1450
 
1420 1451
 	CURR_DLG_ID = req->id;
1421 1452
 	CURR_DLG_LIFETIME = (unsigned int)(time(0))-dlg->start_ts;
... ...
@@ -243,6 +243,10 @@ int dlg_clean_run(ticks_t ti)
243 243
 				unlink_unsafe_dlg(&d_table->entries[i], tdlg);
244 244
 				destroy_dlg(tdlg);
245 245
 			}
246
+			if(tdlg->state==DLG_STATE_CONFIRMED_NA && tdlg->start_ts>0 && tdlg->start_ts<tm-60) {
247
+				LM_NOTICE("dialog disconnection no-ACK call-id[%.*s][%u]<[%u - 60]\n",
248
+						tdlg->callid.len, tdlg->callid.s, tdlg->start_ts, tm);
249
+			}
246 250
 			if(tdlg->state==DLG_STATE_CONFIRMED_NA && tdlg->start_ts>0
247 251
 					&& tdlg->start_ts<tm-dlg_noack_timeout) {
248 252
 				if(update_dlg_timer(&tdlg->tl, 10)<0) {