3 Nov
2020
3 Nov
'20
12:15 a.m.
Nov 2 21:13:28 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_EXPIRED,
lets retrieve a new one
Nov 2 21:13:28 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_RECEIVED,
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzUxNjA4LCJleHAiOjE2MDQzNTUyMDgsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.sUQImDqDfE-xdA1SQ-7I5TnFMZaPh8WB2c-S-ut1hog","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604351608,"exp":1604355208,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"sUQImDqDfE-xdA1SQ-7I5TnFMZaPh8WB2c-S-ut1hog"}}}
Nov 2 21:13:28 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_TIME,
1604351608
root@main:/etc/kamailio# kamcmd htable.dump server
{
entry: 11
size: 1
slot: {
{
name: auth::token
value:
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzUxNjA4LCJleHAiOjE2MDQzNTUyMDgsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.sUQImDqDfE-xdA1SQ-7I5TnFMZaPh8WB2c-S-ut1hog","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604351608,"exp":1604355208,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"sUQImDqDfE-xdA1SQ-7I5TnFMZaPh8WB2c-S-ut1hog"}}}
type: str
}
}
}
Nov 2 21:13:48 main kamailio[1334]: INFO: <script>: AUTH_TOKEN_EXPIRED,
lets retrieve a new one
Nov 2 21:13:48 main kamailio[1334]: INFO: <script>: AUTH_TOKEN_RECEIVED,
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzUxNjI4LCJleHAiOjE2MDQzNTUyMjgsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.stW5JzPR-Gz3oVvQEb1wxF7I0GcZ1KjkkQhinHGEivQ","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604351628,"exp":1604355228,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"stW5JzPR-Gz3oVvQEb1wxF7I0GcZ1KjkkQhinHGEivQ"}}}
Nov 2 21:13:48 main kamailio[1334]: INFO: <script>: AUTH_TOKEN_TIME,
1604351628
root@main:/etc/kamailio# kamcmd htable.dump server
{
entry: 0
size: 1
slot: {
{
name: auth::time
value: 1604351628
type: int
}
}
}
Nov 2 21:14:08 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_EXPIRED,
lets retrieve a new one
Nov 2 21:14:08 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_RECEIVED,
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzUxNjQ4LCJleHAiOjE2MDQzNTUyNDgsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.P52y8GIkL2FEeT51WbYicjIdjdWp-1FXpIRPLHFmlw4","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604351648,"exp":1604355248,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"P52y8GIkL2FEeT51WbYicjIdjdWp-1FXpIRPLHFmlw4"}}}
Nov 2 21:14:08 main kamailio[1331]: INFO: <script>: AUTH_TOKEN_TIME,
1604351648
root@main:/etc/kamailio# kamcmd htable.dump server
{
entry: 11
size: 1
slot: {
{
name: auth::token
value:
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzUxNjQ4LCJleHAiOjE2MDQzNTUyNDgsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.P52y8GIkL2FEeT51WbYicjIdjdWp-1FXpIRPLHFmlw4","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604351648,"exp":1604355248,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"P52y8GIkL2FEeT51WbYicjIdjdWp-1FXpIRPLHFmlw4"}}}
type: str
}
}
}
On Mon, Nov 2, 2020 at 12:44 PM Brandon Armstead <brandon(a)cryy.com> wrote:
Also to add one more thing, I added a third static
variable into the mix
to test when using the "bad config" just setting server=>auth::name to
"brandon" and introducing the 3rd variable seems to just make kamailio hang
when doing kamcmd htable.dump server <---- (no results returned).
On Mon, Nov 2, 2020 at 12:41 PM Brandon Armstead <brandon(a)cryy.com> wrote:
Daniel,
In short kamcmd does not reflect the value set in $sht(server=>auth
::token)
It alternates between being set and not being set (reflecting in kamcmd
htable.dump
root@main:/etc/kamailio# kamcmd htable.dump server
{
entry: 11
size: 1
slot: {
{
name: auth::token
value:
{"data":{"token":{"token":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJDUllZIiwiaWF0IjoxNjA0MzQ2NzgzLCJleHAiOjE2MDQzNTAzODMsIm1ldGhvZCI6InBvc3Q6YXV0aDp0b2tlbiIsImFjY291bnQiOnsiaWQiOiIxIiwiZmlyc3RuYW1lIjoiVGVzdCIsImxhc3RuYW1lIjoiQXJtc3RlYWQiLCJlbWFpbCI6ImJyYW5kb25AY3J5eS5jb20ifSwic291cmNlIjp7ImFkZHJlc3MiOiIzNC45NC4xMjMuMTIxIn19.aFGWqQg31oNnw10XfZ61Xm5Jncvt7RoNri2ZuDJ6yLQ","header":{"alg":"HS256","typ":"JWT"},"payload":{"iss":"CRYY","iat":1604346783,"exp":1604350383,"method":"post:auth:token","account":{"id":"1","firstname":"Test","lastname":"Armstead","email":"
brandon(a)cryy.com
"},"source":{"address":"34.94.123.121"}},"signature":"aFGWqQg31oNnw10XfZ61Xm5Jncvt7RoNri2ZuDJ6yLQ"}}}
type: str
}
}
}
In the kamailio logs it always shows AUTH_TOKEN_RECEIVED (correctly, with
the correct auth token), kamcmd dump of htable alternates between execution
of this route: htable:expired:server
Exec 1:
auth::time => [timestamp]
Exec 2:
auth::token => token
Exec 3:
auth::time => [timestamp]
So on and so forth, [ kamcmd htable.dump server ] it does not correctly
hold both $sht(server=>auth::time) and $sht(server=>auth::token) like it
should, despite kamailio logs showing the HTTP_AUTH_TOKEN received message
with the correct auth token (100% of the time).
It's almost like there is a race condition when using the modules
http_client_query in both init and expired event route.
When I changed it to the resolved code block above separating the calls
and introducing http_async_client inside htable:expired:server
The result is 100% of the time auth token exists correctly, just like the
logs 100% of the time show the auth token received regardless of
event_route implementation.
So somewhere somehow the problematic config causes the hash table to not
store HTTP_AUTH_TOKEN it receives and logs.