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@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@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@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@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@cryy.com"},"source":{"address":"34.94.123.121"}},"signature":"P52y8GIkL2FEeT51WbYicjIdjdWp-1FXpIRPLHFmlw4"}}}
type: str
}
}
}
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@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.dumproot@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@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 => tokenExec 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:serverThe 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.