[sr-dev] Timer warning whenever PUA sends a request

[Juha Heinanen]

Andrei Pelinescu-Onciul writes:

> You get this warning only when trying to send a new request from the pua
> module? Do you try to send it using t_request or t_request_within?
> Did you notice anything else, like immediate retransmissions?

andrei,

here is an example on how i get the warnings.  i start two sip UAs at
the same time and they send during same second a bunch of subscribe and
publishes via sip proxy sr to presence server sr.  there is no pua
involved.

-- juha

Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9820]: INFO: SUBSCRIBE <sip:test at vm.test.fi> by <sip:test at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9821]: INFO: SUBSCRIBE <sip:jh at test.fi> by <sip:test at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9819]: INFO: PUBLISH <sip:test at test.fi> by <sip:test at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: SUBSCRIBE <sip:jh at vm.test.fi> by <sip:jh at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: PUBLISH <sip:jh at test.fi> by <sip:jh at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9820]: INFO: SUBSCRIBE <sip:test at vm.test.fi> by <test at test.fi> as <sip:test at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: SUBSCRIBE <sip:test at test.fi> by <sip:jh at test.fi> has no Proxy-Authorization header
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9822]: INFO: SUBSCRIBE <sip:jh at test.fi> by <test at test.fi> as <sip:test at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9821]: INFO: PUBLISH <sip:test at test.fi> by <test at test.fi> as <sip:test at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: SUBSCRIBE <sip:jh at vm.test.fi> by <jh at test.fi> as <sip:jh at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9820]: INFO: Routing SUBSCRIBE <sip:test at vm.test.fi> to <sip:127.0.0.1:5082;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: Routing SUBSCRIBE <sip:jh at vm.test.fi> to <sip:127.0.0.1:5082;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: <core> [tcp_main.c:2755]: quick connect for 0xb4a530e8
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: PUBLISH <sip:jh at test.fi> by <jh at test.fi> as <sip:jh at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9691]: INFO: INFO: Handling SUBSCRIBE <sip:test at vm.test.fi>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: INFO: Handling SUBSCRIBE <sip:jh at vm.test.fi>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9691]: INFO: Routing locally generated NOTIFY to <sip:test at 192.98.102.10:5074;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9691]: INFO: presence [notify.c:1593]: NOTIFY sip:test at test.fi via sip:192.98.102.10;lr;ftag=gabqc on behalf of sip:test at test.fi for event message-summary
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9819]: INFO: Routing in-dialog NOTIFY <sip:test at 192.98.102.10:5074;transport=udp> from <sip:test at test.fi>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: Routing locally generated NOTIFY to <sip:jh_test_fi at 192.98.102.10:5074;alias=192.98.102.10~58663~2;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: <core> [tcp_main.c:2755]: quick connect for 0xb4f667b0
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: presence [notify.c:1593]: NOTIFY sip:jh at test.fi via sip:192.98.102.10;transport=tcp;lr;ftag=sspcj on behalf of sip:jh at test.fi for event message-summary
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9822]: INFO: Routing SUBSCRIBE <sip:jh at test.fi> to <sip:127.0.0.1:5082;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9821]: INFO: Routing PUBLISH <sip:test at test.fi> to <sip:127.0.0.1:5082;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9692]: INFO: INFO: Handling SUBSCRIBE <sip:jh at test.fi>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9857]: INFO: Routing in-dialog NOTIFY <sip:jh_test_fi at 192.98.102.10:5074;transport=tcp> from <sip:jh at test.fi> to <sip:192.98.102.10:58663;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9694]: INFO: INFO: Handling PUBLISH <sip:test at test.fi>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: Routing PUBLISH <sip:jh at test.fi> to <sip:127.0.0.1:5082;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: INFO: Handling PUBLISH <sip:jh at test.fi>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9857]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: SUBSCRIBE <sip:test at test.fi> by <jh at test.fi> as <sip:jh at test.fi> from <192.98.102.10> is authorized
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9692]: INFO: Routing locally generated NOTIFY to <sip:test at 192.98.102.10:5074;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9692]: INFO: presence [notify.c:1593]: NOTIFY sip:test at test.fi via sip:192.98.102.10;lr;ftag=jysro on behalf of sip:jh at test.fi for event presence
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9819]: INFO: Routing in-dialog NOTIFY <sip:test at 192.98.102.10:5074;transport=udp> from <sip:jh at test.fi>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: INFO: Routing SUBSCRIBE <sip:test at test.fi> to <sip:127.0.0.1:5082;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9855]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: Routing locally generated NOTIFY to <sip:test at 192.98.102.10:5074;transport=udp>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: presence [notify.c:1593]: NOTIFY sip:test at test.fi via sip:192.98.102.10;lr;ftag=jysro on behalf of sip:jh at test.fi for event presence
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: INFO: Handling SUBSCRIBE <sip:test at test.fi>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9820]: INFO: Routing in-dialog NOTIFY <sip:test at 192.98.102.10:5074;transport=udp> from <sip:jh at test.fi>
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: Routing locally generated NOTIFY to <sip:jh_test_fi at 192.98.102.10:5074;alias=192.98.102.10~58663~2;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9857]: INFO: Routing in-dialog NOTIFY <sip:jh_test_fi at 192.98.102.10:5074;transport=tcp> from <sip:test at test.fi> to <sip:192.98.102.10:58663;transport=tcp>
Aug 22 20:00:25 sip /usr/sbin/sip-proxy[9857]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:00:25 sip /usr/sbin/pres-serv[9699]: INFO: presence [notify.c:1593]: NOTIFY sip:jh at test.fi via sip:192.98.102.10;transport=tcp;lr;ftag=qkzdu on behalf of sip:test at test.fi for event presence
Aug 22 20:02:25 sip /usr/sbin/sip-proxy[9857]: INFO: Routing in-dialog SUBSCRIBE <sip:127.0.0.1:5082;transport=tcp> from <sip:jh at test.fi>
Aug 22 20:02:25 sip /usr/sbin/sip-proxy[9857]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:02:25 sip /usr/sbin/pres-serv[9701]: INFO: INFO: Handling in-dialog SUBSCRIBE to <sip:test at test.fi> from <sip:jh at test.fi>
Aug 22 20:02:25 sip /usr/sbin/pres-serv[9701]: INFO: Routing locally generated NOTIFY to <sip:jh_test_fi at 192.98.102.10:5074;alias=192.98.102.10~58663~2;transport=tcp>
Aug 22 20:02:25 sip /usr/sbin/pres-serv[9701]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added
Aug 22 20:02:25 sip /usr/sbin/pres-serv[9701]: INFO: presence [notify.c:1593]: NOTIFY sip:jh at test.fi via sip:192.98.102.10;transport=tcp;lr;ftag=qkzdu on behalf of sip:test at test.fi for event presence
Aug 22 20:02:25 sip /usr/sbin/sip-proxy[9855]: INFO: Routing in-dialog NOTIFY <sip:jh_test_fi at 192.98.102.10:5074;transport=tcp> from <sip:test at test.fi> to <sip:192.98.102.10:58663;transport=tcp>
Aug 22 20:02:25 sip /usr/sbin/sip-proxy[9855]: WARNING: <core> [timer_funcs.h:119]: WARNING: timer: add_timeout: 0 expire timer added