[SR-Users] Using lock() correctly

[Sebastian Damm]

Okay, this is the order from my first mail:

(1) Jun 28 13:27:04 busch /usr/sbin/kamailio[18836]: INFO: <script>: Got
new packet INVITE: 172.20.21.247 => 172.20.21.4
(2) Jun 28 13:27:04 busch /usr/sbin/kamailio[18836]: INFO: <script>:
Obtained lock, calling lua...
(3) Jun 28 13:27:04 busch /usr/sbin/kamailio[18836]: INFO: app_lua
[app_lua_sr.c:98]: lua_sr_log(): some logging
(4) Jun 28 13:27:04 busch /usr/sbin/kamailio[18837]: INFO: <script>: Got
new packet INVITE: 172.20.21.4 => 172.20.21.247 - Reply Code 407
(5) Jun 28 13:27:04 busch /usr/sbin/kamailio[18837]: INFO: <script>:
Obtained lock, calling lua...
(6) Jun 28 13:27:04 busch /usr/sbin/kamailio[18837]: INFO: <script>: Lua
finished, released lock...
(7) Jun 28 13:27:04 busch /usr/sbin/kamailio[18836]: INFO: app_lua
[app_lua_sr.c:98]: lua_sr_log(): some more logging


You see, there are 2 PIDs involved, 18836 and 18837. PID 18836 gets
the initial INVITE ands starts working. Gets the lock (2). In line
(3), app_lua logs stuff. Now in line (4) the 407 comes in. PID 18837
starts working on it. Now it trys to lock the Call-ID, and apparently
it can get it. But why? You can see in line (7), that PID 18836 is
still in the lua code, so within the locked part of the config. I
think, the correct order would be (1) - (2) - (3) - (4) - (7) - (8) -
(5) - (6), with (8) being the "released lock" message from PID 18836.
The lines 5 and 6 should'nt be printed before the lock is returned.

I have simplified my code for easier understanding. Threw out lua and
all stuff, just used sleep from the cfgutils package.

This is what the code looks like:

request_route {
        xlog("L_INFO", "Got new request ($ci) $rm: $si => $Ri\n");
        route(magic);
}

onreply_route {
        xlog("L_INFO", "Got new reply ($ci) $rm: $si => $Ri - Reply
Code $rs\n");
        route(magic);
}

route[magic] {
        lock("$ci");
        xlog("L_INFO", "Obtained lock, sleeping for a second...\n");
        sleep("1");

        xlog("L_INFO", "Done sleeping, releasing lock...\n");
        unlock("$ci");
        xlog("L_INFO", "Released lock...\n");

        drop;
        exit;
}


And this is what the logs say:
Jul  3 14:36:06 busch /usr/sbin/kamailio[12273]: INFO: <script>: Got
new request (313439393038353336363236313137-2m3hb9h5v6o9) INVITE:
172.20.21.200 => 172.20.21.4
Jul  3 14:36:06 busch /usr/sbin/kamailio[12273]: INFO: <script>:
Obtained lock, sleeping for a second...
Jul  3 14:36:06 busch /usr/sbin/kamailio[12276]: INFO: <script>: Got
new reply (313439393038353336363236313137-2m3hb9h5v6o9) INVITE:
172.20.21.4 => 172.20.21.200 - Reply Code 407
Jul  3 14:36:06 busch /usr/sbin/kamailio[12276]: INFO: <script>:
Obtained lock, sleeping for a second...
Jul  3 14:36:07 busch /usr/sbin/kamailio[12273]: INFO: <script>: Done
sleeping, releasing lock...
Jul  3 14:36:07 busch /usr/sbin/kamailio[12273]: INFO: <script>:
Released lock...
Jul  3 14:36:07 busch /usr/sbin/kamailio[12276]: INFO: <script>: Done
sleeping, releasing lock...
Jul  3 14:36:07 busch /usr/sbin/kamailio[12276]: INFO: <script>:
Released lock...

As you can see, both PIDs get the lock on the Call-ID simultaneously.
>From what I think the lock() function should do, the second PID should
wait for the first one to release the lock.

Best Regards,
Sebastian