From notifications@github.com Fri Apr 30 19:48:48 2021
From: Giacomo Vacca <notifications@github.com>
To: sr-dev@lists.kamailio.org
Subject: Re: [sr-dev] [kamailio/kamailio] tm: t_suspend.c -
 t_continue_helper() - do not continue processing a reply if it's suspended
 again (#2721)
Date: Fri, 30 Apr 2021 10:48:45 -0700
Message-ID: <kamailio/kamailio/pull/2721/c830258187@github.com>
In-Reply-To: <kamailio/kamailio/pull/2721@github.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="===============1168288488=="

--===============1168288488==
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: quoted-printable

In order to explain why this is needed, I've prepared a new test scenario: ht=
tps://github.com/kamailio/kamailio-tests/pull/19

This sees an HTTP request being performed in a reply route, using `http_async=
_client` and with suspension of the transaction.
Upon landing into the HTTP reply route, the transaction is suspended for a se=
cond time while a new `http_async_query()` is performed.

Without the change in this PR, the suspension during the second query, even t=
hough it's logged as happened, doesn't have effect on `t_continue_helper()` w=
hich continues processing the reply. The reply is so sent out and when the HT=
TP reply route is reached afterwards the transaction exists but it's already =
in terminated state.

An example of .cfg (as used in the example test scenario):

```
request_route {
	if (is_request()) {
		if (is_method("INVITE")) {
			t_newtran();
			t_on_reply("INVITE_REPLY");
			t_relay("127.0.0.1", "5080");
			exit;
		}
		else if (is_method("ACK")) {
			t_relay("127.0.0.1", "5080");
			exit;
		}
	}
	drop;
}

onreply_route[INVITE_REPLY] {
	xlog("L_INFO", "=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D INVITE_REPL=
Y =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D\n");
	if (status=3D~"200") {
		http_async_query("http://127.0.0.1:8080/", "HTTP_REPLY1");
	}
}

route[HTTP_REPLY1] {
	xlog("L_INFO", "=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D HTTP_REPLY1=
 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D\n");
	if ($http_ok) {
		xlog("L_INFO", "HTTP GET REPLY1: $http_rs - Response: $http_rb\n");
		http_async_query("http://127.0.0.1:8080/", "HTTP_REPLY2");
		sl_send_reply("200", "OK");
		exit;
	}
	else {
		xlog("L_ERR", "HTTP error: $http_err\n");
	}
}

route[HTTP_REPLY2] {
	xlog("L_INFO", "=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D HTTP_REPLY2=
 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D DONE\n");
}
```

The debug log before the change:

```
 6(32) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found
 6(32) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming=
 transaction (44930:409999179)
 6(32) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found
 6(32) DEBUG: tm [t_suspend.c:364]: t_continue_helper(): continuing from a su=
spended reply - resetting the suspend branch flag

 6(32) INFO: <script>: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D HTTP_=
REPLY1 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
 6(32) INFO: <script>: HTTP GET REPLY1: 200 - Response:

Now it calls async_send_query():

 6(32) DEBUG: tm [t_suspend.c:113]: t_suspend(): this is a suspend on reply -=
 setting msg flag to SUSPEND
 6(32) DEBUG: tm [t_lookup.c:1034]: t_check_msg(): msg (0x7f48b3cd6b60) id=3D=
2/27 global id=3D2/27 T start=3D0x7f48b3cd34d8
 6(32) DEBUG: tm [t_lookup.c:1109]: t_check_msg(): T (0x7f48b3cd34d8) already=
 found for msg (0x7f48b3cd6b60)!
 6(32) DEBUG: tm [t_suspend.c:121]: t_suspend(): found a a match with branch =
id [0] - cloning reply message to t->uac[branch].reply
 6(32) DEBUG: tm [t_suspend.c:133]: t_suspend(): saving transaction data

 6(32) DEBUG: http_async_client [async_http.c:469]: async_send_query(): trans=
action suspended [44930:409999179]

(index and label are as expected)

 6(32) DEBUG: http_async_client [async_http.c:625]: async_push_query(): query=
 sent [http://127.0.0.1:8080/] (0x7f48b3cdfa08) to worker 1

Here it should have suspended, but it's actually continuing in the reply rout=
e:

 6(32) DEBUG: tm [t_suspend.c:408]: t_continue_helper(): restoring previous e=
nvironment
 6(32) DEBUG: tm [t_suspend.c:435]: t_continue_helper(): t is not local - rel=
aying reply with status code: [200]
```





--=20
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/pull/2721#issuecomment-830258187



--===============1168288488==
Content-Type: text/html
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="attachment.html"
MIME-Version: 1.0

PHA+PC9wPgo8cD5JbiBvcmRlciB0byBleHBsYWluIHdoeSB0aGlzIGlzIG5lZWRlZCwgSSd2ZSBw
cmVwYXJlZCBhIG5ldyB0ZXN0IHNjZW5hcmlvOiA8YSBjbGFzcz0iaXNzdWUtbGluayBqcy1pc3N1
ZS1saW5rIiBkYXRhLWVycm9yLXRleHQ9IkZhaWxlZCB0byBsb2FkIHRpdGxlIiBkYXRhLWlkPSI4
NzI4ODgxOTYiIGRhdGEtcGVybWlzc2lvbi10ZXh0PSJUaXRsZSBpcyBwcml2YXRlIiBkYXRhLXVy
bD0iaHR0cHM6Ly9naXRodWIuY29tL2thbWFpbGlvL2thbWFpbGlvLXRlc3RzL2lzc3Vlcy8xOSIg
ZGF0YS1ob3ZlcmNhcmQtdHlwZT0icHVsbF9yZXF1ZXN0IiBkYXRhLWhvdmVyY2FyZC11cmw9Ii9r
YW1haWxpby9rYW1haWxpby10ZXN0cy9wdWxsLzE5L2hvdmVyY2FyZCIgaHJlZj0iaHR0cHM6Ly9n
aXRodWIuY29tL2thbWFpbGlvL2thbWFpbGlvLXRlc3RzL3B1bGwvMTkiPmthbWFpbGlvL2thbWFp
bGlvLXRlc3RzIzE5PC9hPjwvcD4KPHA+VGhpcyBzZWVzIGFuIEhUVFAgcmVxdWVzdCBiZWluZyBw
ZXJmb3JtZWQgaW4gYSByZXBseSByb3V0ZSwgdXNpbmcgPGNvZGU+aHR0cF9hc3luY19jbGllbnQ8
L2NvZGU+IGFuZCB3aXRoIHN1c3BlbnNpb24gb2YgdGhlIHRyYW5zYWN0aW9uLjxicj4KVXBvbiBs
YW5kaW5nIGludG8gdGhlIEhUVFAgcmVwbHkgcm91dGUsIHRoZSB0cmFuc2FjdGlvbiBpcyBzdXNw
ZW5kZWQgZm9yIGEgc2Vjb25kIHRpbWUgd2hpbGUgYSBuZXcgPGNvZGU+aHR0cF9hc3luY19xdWVy
eSgpPC9jb2RlPiBpcyBwZXJmb3JtZWQuPC9wPgo8cD5XaXRob3V0IHRoZSBjaGFuZ2UgaW4gdGhp
cyBQUiwgdGhlIHN1c3BlbnNpb24gZHVyaW5nIHRoZSBzZWNvbmQgcXVlcnksIGV2ZW4gdGhvdWdo
IGl0J3MgbG9nZ2VkIGFzIGhhcHBlbmVkLCBkb2Vzbid0IGhhdmUgZWZmZWN0IG9uIDxjb2RlPnRf
Y29udGludWVfaGVscGVyKCk8L2NvZGU+IHdoaWNoIGNvbnRpbnVlcyBwcm9jZXNzaW5nIHRoZSBy
ZXBseS4gVGhlIHJlcGx5IGlzIHNvIHNlbnQgb3V0IGFuZCB3aGVuIHRoZSBIVFRQIHJlcGx5IHJv
dXRlIGlzIHJlYWNoZWQgYWZ0ZXJ3YXJkcyB0aGUgdHJhbnNhY3Rpb24gZXhpc3RzIGJ1dCBpdCdz
IGFscmVhZHkgaW4gdGVybWluYXRlZCBzdGF0ZS48L3A+CjxwPkFuIGV4YW1wbGUgb2YgLmNmZyAo
YXMgdXNlZCBpbiB0aGUgZXhhbXBsZSB0ZXN0IHNjZW5hcmlvKTo8L3A+CjxwcmU+PGNvZGU+cmVx
dWVzdF9yb3V0ZSB7CglpZiAoaXNfcmVxdWVzdCgpKSB7CgkJaWYgKGlzX21ldGhvZCgiSU5WSVRF
IikpIHsKCQkJdF9uZXd0cmFuKCk7CgkJCXRfb25fcmVwbHkoIklOVklURV9SRVBMWSIpOwoJCQl0
X3JlbGF5KCIxMjcuMC4wLjEiLCAiNTA4MCIpOwoJCQlleGl0OwoJCX0KCQllbHNlIGlmIChpc19t
ZXRob2QoIkFDSyIpKSB7CgkJCXRfcmVsYXkoIjEyNy4wLjAuMSIsICI1MDgwIik7CgkJCWV4aXQ7
CgkJfQoJfQoJZHJvcDsKfQoKb25yZXBseV9yb3V0ZVtJTlZJVEVfUkVQTFldIHsKCXhsb2coIkxf
SU5GTyIsICI9PT09PT09PT09PT09PT09IElOVklURV9SRVBMWSA9PT09PT09PT09PT09PT09PT1c
biIpOwoJaWYgKHN0YXR1cz1+IjIwMCIpIHsKCQlodHRwX2FzeW5jX3F1ZXJ5KCJodHRwOi8vMTI3
LjAuMC4xOjgwODAvIiwgIkhUVFBfUkVQTFkxIik7Cgl9Cn0KCnJvdXRlW0hUVFBfUkVQTFkxXSB7
Cgl4bG9nKCJMX0lORk8iLCAiPT09PT09PT09PT09PT09PSBIVFRQX1JFUExZMSA9PT09PT09PT09
PT09PT09PT1cbiIpOwoJaWYgKCRodHRwX29rKSB7CgkJeGxvZygiTF9JTkZPIiwgIkhUVFAgR0VU
IFJFUExZMTogJGh0dHBfcnMgLSBSZXNwb25zZTogJGh0dHBfcmJcbiIpOwoJCWh0dHBfYXN5bmNf
cXVlcnkoImh0dHA6Ly8xMjcuMC4wLjE6ODA4MC8iLCAiSFRUUF9SRVBMWTIiKTsKCQlzbF9zZW5k
X3JlcGx5KCIyMDAiLCAiT0siKTsKCQlleGl0OwoJfQoJZWxzZSB7CgkJeGxvZygiTF9FUlIiLCAi
SFRUUCBlcnJvcjogJGh0dHBfZXJyXG4iKTsKCX0KfQoKcm91dGVbSFRUUF9SRVBMWTJdIHsKCXhs
b2coIkxfSU5GTyIsICI9PT09PT09PT09PT09PT09IEhUVFBfUkVQTFkyID09PT09PT09PT09PT09
PT09PSBET05FXG4iKTsKfQo8L2NvZGU+PC9wcmU+CjxwPlRoZSBkZWJ1ZyBsb2cgYmVmb3JlIHRo
ZSBjaGFuZ2U6PC9wPgo8cHJlPjxjb2RlPiA2KDMyKSBERUJVRzogdG0gW3RfbG9va3VwLmM6MTYx
Ml06IHRfbG9va3VwX2lkZW50X2ZpbHRlcigpOiB0cmFuc2FjdGlvbiBmb3VuZAogNigzMikgREVC
VUc6IGh0dHBfYXN5bmNfY2xpZW50IFthc3luY19odHRwLmM6MjM1XTogYXN5bmNfaHR0cF9jYigp
OiByZXN1bWluZyB0cmFuc2FjdGlvbiAoNDQ5MzA6NDA5OTk5MTc5KQogNigzMikgREVCVUc6IHRt
IFt0X2xvb2t1cC5jOjE2MTJdOiB0X2xvb2t1cF9pZGVudF9maWx0ZXIoKTogdHJhbnNhY3Rpb24g
Zm91bmQKIDYoMzIpIERFQlVHOiB0bSBbdF9zdXNwZW5kLmM6MzY0XTogdF9jb250aW51ZV9oZWxw
ZXIoKTogY29udGludWluZyBmcm9tIGEgc3VzcGVuZGVkIHJlcGx5IC0gcmVzZXR0aW5nIHRoZSBz
dXNwZW5kIGJyYW5jaCBmbGFnCgogNigzMikgSU5GTzogJmx0O3NjcmlwdCZndDs6ID09PT09PT09
PT09PT09PT0gSFRUUF9SRVBMWTEgPT09PT09PT09PT09PT09PT09CiA2KDMyKSBJTkZPOiAmbHQ7
c2NyaXB0Jmd0OzogSFRUUCBHRVQgUkVQTFkxOiAyMDAgLSBSZXNwb25zZToKCk5vdyBpdCBjYWxs
cyBhc3luY19zZW5kX3F1ZXJ5KCk6CgogNigzMikgREVCVUc6IHRtIFt0X3N1c3BlbmQuYzoxMTNd
OiB0X3N1c3BlbmQoKTogdGhpcyBpcyBhIHN1c3BlbmQgb24gcmVwbHkgLSBzZXR0aW5nIG1zZyBm
bGFnIHRvIFNVU1BFTkQKIDYoMzIpIERFQlVHOiB0bSBbdF9sb29rdXAuYzoxMDM0XTogdF9jaGVj
a19tc2coKTogbXNnICgweDdmNDhiM2NkNmI2MCkgaWQ9Mi8yNyBnbG9iYWwgaWQ9Mi8yNyBUIHN0
YXJ0PTB4N2Y0OGIzY2QzNGQ4CiA2KDMyKSBERUJVRzogdG0gW3RfbG9va3VwLmM6MTEwOV06IHRf
Y2hlY2tfbXNnKCk6IFQgKDB4N2Y0OGIzY2QzNGQ4KSBhbHJlYWR5IGZvdW5kIGZvciBtc2cgKDB4
N2Y0OGIzY2Q2YjYwKSEKIDYoMzIpIERFQlVHOiB0bSBbdF9zdXNwZW5kLmM6MTIxXTogdF9zdXNw
ZW5kKCk6IGZvdW5kIGEgYSBtYXRjaCB3aXRoIGJyYW5jaCBpZCBbMF0gLSBjbG9uaW5nIHJlcGx5
IG1lc3NhZ2UgdG8gdC0mZ3Q7dWFjW2JyYW5jaF0ucmVwbHkKIDYoMzIpIERFQlVHOiB0bSBbdF9z
dXNwZW5kLmM6MTMzXTogdF9zdXNwZW5kKCk6IHNhdmluZyB0cmFuc2FjdGlvbiBkYXRhCgogNigz
MikgREVCVUc6IGh0dHBfYXN5bmNfY2xpZW50IFthc3luY19odHRwLmM6NDY5XTogYXN5bmNfc2Vu
ZF9xdWVyeSgpOiB0cmFuc2FjdGlvbiBzdXNwZW5kZWQgWzQ0OTMwOjQwOTk5OTE3OV0KCihpbmRl
eCBhbmQgbGFiZWwgYXJlIGFzIGV4cGVjdGVkKQoKIDYoMzIpIERFQlVHOiBodHRwX2FzeW5jX2Ns
aWVudCBbYXN5bmNfaHR0cC5jOjYyNV06IGFzeW5jX3B1c2hfcXVlcnkoKTogcXVlcnkgc2VudCBb
aHR0cDovLzEyNy4wLjAuMTo4MDgwL10gKDB4N2Y0OGIzY2RmYTA4KSB0byB3b3JrZXIgMQoKSGVy
ZSBpdCBzaG91bGQgaGF2ZSBzdXNwZW5kZWQsIGJ1dCBpdCdzIGFjdHVhbGx5IGNvbnRpbnVpbmcg
aW4gdGhlIHJlcGx5IHJvdXRlOgoKIDYoMzIpIERFQlVHOiB0bSBbdF9zdXNwZW5kLmM6NDA4XTog
dF9jb250aW51ZV9oZWxwZXIoKTogcmVzdG9yaW5nIHByZXZpb3VzIGVudmlyb25tZW50CiA2KDMy
KSBERUJVRzogdG0gW3Rfc3VzcGVuZC5jOjQzNV06IHRfY29udGludWVfaGVscGVyKCk6IHQgaXMg
bm90IGxvY2FsIC0gcmVsYXlpbmcgcmVwbHkgd2l0aCBzdGF0dXMgY29kZTogWzIwMF0KPC9jb2Rl
PjwvcHJlPgoKPHAgc3R5bGU9ImZvbnQtc2l6ZTpzbWFsbDstd2Via2l0LXRleHQtc2l6ZS1hZGp1
c3Q6bm9uZTtjb2xvcjojNjY2OyI+Jm1kYXNoOzxiciAvPllvdSBhcmUgcmVjZWl2aW5nIHRoaXMg
YmVjYXVzZSB5b3UgYXJlIHN1YnNjcmliZWQgdG8gdGhpcyB0aHJlYWQuPGJyIC8+UmVwbHkgdG8g
dGhpcyBlbWFpbCBkaXJlY3RseSwgPGEgaHJlZj0iaHR0cHM6Ly9naXRodWIuY29tL2thbWFpbGlv
L2thbWFpbGlvL3B1bGwvMjcyMSNpc3N1ZWNvbW1lbnQtODMwMjU4MTg3Ij52aWV3IGl0IG9uIEdp
dEh1YjwvYT4sIG9yIDxhIGhyZWY9Imh0dHBzOi8vZ2l0aHViLmNvbS9ub3RpZmljYXRpb25zL3Vu
c3Vic2NyaWJlLWF1dGgvQUJPN1VaTU9VUUZOS0g1MlgyNTZDNTNUTExVUDNBTkNORlNNNDM0NUJE
UEEiPnVuc3Vic2NyaWJlPC9hPi48aW1nIHNyYz0iaHR0cHM6Ly9naXRodWIuY29tL25vdGlmaWNh
dGlvbnMvYmVhY29uL0FCTzdVWklEV1dLVDJKNVpVSkNHRzdUVExMVVAzQTVDTkZTTTQzNDVCRFBL
WVkzUE5WV1dLM1RVTDUySFM0REZWUkVYRzQzVk1WQlc2M0xOTVZYSEpLVERONVdXMlpMT09SUFdT
WkdPR0Y2TFlDWS5naWYiIGhlaWdodD0iMSIgd2lkdGg9IjEiIGFsdD0iIiAvPjwvcD4KPHNjcmlw
dCB0eXBlPSJhcHBsaWNhdGlvbi9sZCtqc29uIj5bCnsKIkBjb250ZXh0IjogImh0dHA6Ly9zY2hl
bWEub3JnIiwKIkB0eXBlIjogIkVtYWlsTWVzc2FnZSIsCiJwb3RlbnRpYWxBY3Rpb24iOiB7CiJA
dHlwZSI6ICJWaWV3QWN0aW9uIiwKInRhcmdldCI6ICJodHRwczovL2dpdGh1Yi5jb20va2FtYWls
aW8va2FtYWlsaW8vcHVsbC8yNzIxI2lzc3VlY29tbWVudC04MzAyNTgxODciLAoidXJsIjogImh0
dHBzOi8vZ2l0aHViLmNvbS9rYW1haWxpby9rYW1haWxpby9wdWxsLzI3MjEjaXNzdWVjb21tZW50
LTgzMDI1ODE4NyIsCiJuYW1lIjogIlZpZXcgUHVsbCBSZXF1ZXN0Igp9LAoiZGVzY3JpcHRpb24i
OiAiVmlldyB0aGlzIFB1bGwgUmVxdWVzdCBvbiBHaXRIdWIiLAoicHVibGlzaGVyIjogewoiQHR5
cGUiOiAiT3JnYW5pemF0aW9uIiwKIm5hbWUiOiAiR2l0SHViIiwKInVybCI6ICJodHRwczovL2dp
dGh1Yi5jb20iCn0KfQpdPC9zY3JpcHQ+

--===============1168288488==--