[OpenSIPS-Users] Trouble getting mediaproxy to work (dialog module)

[Dan Pascu]

On Saturday 21 March 2009, slophoo wrote:
> I should say first that I am rather new to this, and am positive the
> mistake is mine, just don't know what it is.  The dialog module does
> load ok in startup, i guess i will post my startup debug here to show
> that.

Your problem seems pretty clear. While the dialog module loads, the 
application doesn't actually start because an old instance it already 
running, so you still get the old instance of it (using the old 
unmodified configuration) processing your messages.

> I've looked at the documentation for engage_media_proxy (saying 
> "This needs to be called only once for the first INVITE in a dialog.")
> and despite reading the documentation for dialog module, I still am
> missing something.

The doc and the example show you that you have to call this for an INVITE 
when there is no to_tag, but in your script you call it only when you 
have a to_tag.

> Is a dialog something i am supposed to create/setup 
> before I can use mediaproxy --  Or is it something i am automatically
> in when making a call?

You don't need to create/setup any dialog. It's done automatically by 
mediaproxy.

> Mar 20 15:00:39 [4198] ERROR:mediaproxy:EngageMediaProxy:
> engage_media_proxy requires the dialog module to be loaded and
> configured

Notice that pid 4198 gave the error.

> Mar 20 14:56:22 [4816] DBG:core:yyparse: loading module
> /usr/local/lib/opensips/modules/dialog.so
> [...]
> Mar 20 14:56:22 [4818] DBG:core:init_mod: initializing module
> mediaproxy
> [...]
> Mar 20 14:56:22 [4818] ERROR:core:tcp_init: bind(6, 0x8190ddc, 16) on
> 127.0.0.1:5060 : Address already in use
> Mar 20 14:56:22 [4818] DBG:xlog:destroy: destroy module...
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: tm_shutdown : start
> Mar 20 14:56:22 [4818] DBG:tm:unlink_timer_lists: emptying DELETE list
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: emptying hash table
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: releasing timers
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: removing semaphores
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: destroying callback lists
> Mar 20 14:56:22 [4818] DBG:tm:tm_shutdown: tm_shutdown : done
> Mar 20 14:56:22 [4818] DBG:core:shm_mem_destroy:
> Mar 20 14:56:22 [4818] DBG:core:shm_mem_destroy: destroying the shared
> memory lock

The new process tries to start. Notice pids 4816 and 4818. It loads the 
dialog module and doesn't give any error for mediaproxy, but in the end 
it said that it could not bind to 127.0.0.1:5060 because the address is 
already in use and exited. Now if a worker of this process would have 
reported the error, it should have a pid higher than 4818, but you get 
the error from 4198 (the old process).

Do these:

stop opensips
ps ax | grep opensips
# if still there kill it:
killall -9 opensips
# check again and wait for it until it exits
ps ax | grep opensips

change your debug level to 3 (dbg messages are not useful in this case and 
make reading the logs more difficult than needed)

start opensips

report back if you still see the problem with the syslog entries.

-- 
Dan