I did some more test with other scenarios: I did a case with simulates voicemail behavior. test procedure was the following (*when calling directly to the destination which played the role of voice mail there was no problem with the session establishment)
first go through ser for first invite dump_attrs() lookup_user("$t.did","@ruri") dump_attrs() load_attrs("$tu","@ruri") load_attrs("$tr","@ruri") dump_attrs() lookup_contacts("location")
before lookup_contacts dump_attrs() gives: Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:540: class=GLOBAL Feb 13 16:08:50 rd ser[10548]: AVP["lang"]="en" Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 16:08:50 rd ser[10548]: AVP["did"]="voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: AVP["digest_realm"]="voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:560: track=TO class=DOMAIN Feb 13 16:08:50 rd ser[10548]: AVP["did"]="voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: AVP["digest_realm"]="voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:570: track=FROM class=USER Feb 13 16:08:50 rd ser[10548]: AVP["uid"]="hellboy@voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: AVP["tyk"]="tyk" Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:580: track=TO class=USER Feb 13 16:08:50 rd ser[10548]: INFO: No AVP present Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:590: track=FROM class=URI Feb 13 16:08:50 rd ser[10548]: AVP["authuid"]="hellboy@voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: AVP["uid"]="hellboy@voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: INFO: avp.c:600: track=TO class=URI Feb 13 16:08:50 rd ser[10548]: AVP["uid"]="mm@voip.touk.pl" Feb 13 16:08:50 rd ser[10548]: AVP["forward_voicemail"]="sip:evn@voip.touk.pl"
then because the user wasn't found in the database I replace the Request uri by forward_voicemail avp and do t_relay().
After this the modified invite is sent to ser again and there is a second go (with completely the same procedure logic) before lookup_contacts("location") dump_attrs() gave: Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:540: class=GLOBAL Feb 13 16:30:31 rd ser[10550]: AVP["lang"]="en" Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 16:30:31 rd ser[10550]: AVP["did"]="voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: AVP["digest_realm"]="voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:560: track=TO class=DOMAIN Feb 13 16:30:31 rd ser[10550]: AVP["did"]="voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: AVP["digest_realm"]="voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:570: track=FROM class=USER Feb 13 16:30:31 rd ser[10550]: AVP["uid"]="hellboy@voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: AVP["tyk"]="tyk" Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:580: track=TO class=USER Feb 13 16:30:31 rd ser[10550]: INFO: No AVP present Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:590: track=FROM class=URI Feb 13 16:30:31 rd ser[10550]: AVP["authuid"]="hellboy@voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: AVP["uid"]="hellboy@voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: INFO: avp.c:600: track=TO class=URI Feb 13 16:30:31 rd ser[10550]: AVP["uid"]="evn@voip.touk.pl" Feb 13 16:30:31 rd ser[10550]: AVP["uri_avp_test"]="uri_avp_test"
and here was an error because in this case lookup_contacts("location") returned negative response although the user pointed by $tr.uid avp was in the database! In the case of direct call to evn@voip.touk.pl there is no error and the dump_attrs() returns the same result before the lookup_contacts() was invoked there was only track to set in the uri class!
I hope this can figure out what is going on.
Bests -tomasz
I did some tests. I sent them on the list because I wat not sure how to interpret their correctness beefore putting them on the tracker I did the following general procedure:
dump_attrs() lookup_user(..) dump_attrs() load_attrs(..) dump_attrs() lookup_contacts(..)
Case one:
dump_attrs() lookup_user("$t.uid","@ruri") dump_attrs() load_attrs("$tu","$t.uid") dump_attrs() lookup_contacts("location")
my observations: after lookup_user("$t.uid","@ruri") uid avp appered in the uri class and to track, lookup_contacts("location") found the user
debug log: Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:540: class=GLOBAL Feb 13 13:48:25 rd ser[9875]: AVP["lang"]="en" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:560: track=TO class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:570: track=FROM class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:580: track=TO class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:590: track=FROM class=URI Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:600: track=TO class=URI Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: route[INBOUND]: (lookup_user($t.uid, @ruri)) Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:540: class=GLOBAL Feb 13 13:48:25 rd ser[9875]: AVP["lang"]="en" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:560: track=TO class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:570: track=FROM class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:580: track=TO class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:590: track=FROM class=URI Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:600: track=TO class=URI Feb 13 13:48:25 rd ser[9875]: AVP["uid"]="hellboy@voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: route[INBOUND]: load_attrs($tu,$t.uid) Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:540: class=GLOBAL Feb 13 13:48:25 rd ser[9875]: AVP["lang"]="en" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:560: track=TO class=DOMAIN Feb 13 13:48:25 rd ser[9875]: AVP["did"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: AVP["digest_realm"]="voip.touk.pl" Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:570: track=FROM class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:25 rd ser[9875]: INFO: avp.c:580: track=TO class=USER Feb 13 13:48:25 rd ser[9875]: INFO: No AVP present Feb 13 13:48:26 rd ser[9875]: INFO: avp.c:590: track=FROM class=URI Feb 13 13:48:26 rd ser[9875]: INFO: No AVP present Feb 13 13:48:26 rd ser[9875]: INFO: avp.c:600: track=TO class=URI Feb 13 13:48:26 rd ser[9875]: AVP["uid"]="hellboy@voip.touk.pl"
Case two:
dump_attrs() lookup_user("Request-uri") dump_attrs() load_attrs("$tu","$tu.uid") dump_attrs() lookup_contacts("location")
my observations: after lookup_user("Request-uri") uid avp appered in the user class and to track, lookup_contacts("location") didn't find the user
Feb 13 14:22:57 rd ser[10047]: INFO: avp.c:540: class=GLOBAL Feb 13 14:22:57 rd ser[10047]: AVP["lang"]="en" Feb 13 14:22:57 rd ser[10047]: INFO: avp.c:550: track=FROM class=DOMAIN Feb 13 14:22: