Redundancy problem with sip

assachs · September 26, 2009, 7:37pm

Hello,
i have a strang problem with the following setup.

I have a sip-account from sipgate.de.

Asterisk is connected to this account as client. If somebody calls the telefone number the calls are routed to the asterisk-server and the calls are answered by a agi-script (the callers are asked someting and can enter the answer in there telephone (dtfm))

This setup works fine.

FOr redundancy issues two asterisk servers are connected to the sip-account. My wish is, that the first server who response get the call.
This works until today 18:30. After that point something happened, but i do not know what.

If a user calls the number the first asterisk server get the call. The caller can hear the output of the agi-script but the answers are not transmitted back to the script.

If i stop the second server everyting works fine again. Restarting of both servers does not solve the problem.

Server 1: Asterisk 1.4.21 (debian 5.0.3)
Server 2: Asterisk 1.2.13 (debian 4.0)

Has anybody an idea what could be wrong with my setup?

Thanks
Andi

ianplain · September 26, 2009, 9:44pm

hi we would need to see some traces , as without seeing what’s going on it makes little sense

Ian

assachs · September 26, 2009, 11:08pm

hello,
we only use the servers on weekends (it’s for sport result). so i cannot do any tests at the moment. (i shut down the second server, so everything is working at the moment).

During the week i can generate the traces. Can you give me some informatiion on debuglevel or something else you need?

Thanks
Andi

assachs · September 27, 2009, 5:35pm

Hello,
today i could reproduce the problem. The problem did not start immediately after the second server is startet.

I also discovered that not only the answers(dtfm) of the callers are missing, also the hangup is missing.

First call (only one server):

[code]tc1:~# asterisk -r -c -vvvvvvv
Asterisk 1.4.21.2~dfsg-3, Copyright © 1999 - 2008 Digium, Inc. and others.
Created by Mark Spencer markster@digium.com
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for detail s.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘core show license’ for details.

This package has been modified for the Debian GNU/Linux distribution
Please report all bugs to bugs.debian.org/asterisk

== Parsing ‘/etc/asterisk/asterisk.conf’: Found
== Parsing ‘/etc/asterisk/extconfig.conf’: Found
Connected to Asterisk 1.4.21.2~dfsg-3 currently running on tc1 (pid = 25790)
Verbosity was 4 and is now 7
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– ast_get_srv: SRV lookup for ‘_sip._udp.sipgate.de’ mapped to host sipgate.de, port 5060
– Executing [2351681@default:1] AGI(“SIP/sipgate.de-0a1ac990”, “start.php|7|tc1”) in new stack
– Launched AGI Script /usr/share/asterisk/agi-bin/start.php
start.php|7|tc1: Array
start.php|7|tc1: (
start.php|7|tc1: => 200 start.php|7|tc1: [result] => 1 start.php|7|tc1: [data] => 091284441 <091284441> start.php|7|tc1: ) start.php|7|tc1: start.php|7|tc1: Channel 7 start.php|7|tc1: session 2217 -- Playing '/var/spool/asterisk//tmp//swift_101c1cf757b40874effcafbec68fbe07' (escape_digits=) (sample_offset 0) -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0) -- <SIP/sipgate.de-0a1ac990> Playing 'beep' (language 'en') -- Playing '/var/spool/asterisk//tmp//swift_dd145af798ee59b676ee407f06d5589d' (escape_digits=) (sample_offset 0) start.php|7|tc1: spiel ermitteln 1 start.php|7|tc1: spiel ermitteln 3 start.php|7|tc1: spiel ermitteln 6 start.php|7|tc1: spielarray ermitteln 1 start.php|7|tc1: select distinct a.* from vesa_spiele s, telefoncomputer c , vesa_teams a where s.orga=1 and s.liga=4 and s.orga=a.orga and s.liga=a.liga and s.heim=a.mid and c.orga=s.orga and c.liga=s.liga and spieltag<=now() and to_days(spieltag)>= to_days(now())-c.meldetage order by a.bez -- Playing '/var/spool/asterisk//tmp//swift_baaa1503964c6cccbfdcd010a693c88e' (escape_digits=) (sample_offset 0) -- AGI Script start.php completed, returning 0 -- Executing [2351681@default:2] Hangup("SIP/sipgate.de-0a1ac990", "") in new stack == Spawn extension (default, 2351681, 2) exited non-zero on 'SIP/sipgate.de-0a1ac990'

more tries (second server running)(as the server did not recognize the hangup, there are multiple processes):

Asterisk 1.4.21.2~dfsg-3, Copyright (C) 1999 - 2008 Digium, Inc. and others.
Created by Mark Spencer <markster@digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'core show license' for details.
=========================================================================
This package has been modified for the Debian GNU/Linux distribution
Please report all bugs to [bugs.debian.org/asterisk](http://bugs.debian.org/asterisk)
=========================================================================
  == Parsing '/etc/asterisk/asterisk.conf': Found
  == Parsing '/etc/asterisk/extconfig.conf': Found
Connected to Asterisk 1.4.21.2~dfsg-3 currently running on tc1 (pid = 25790)
Verbosity is at least 14
[Sep 27 19:25:14] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:25:30] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:25:46] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:26:02] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:26:18] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:26:34] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Executing [2351681@default:1] AGI("SIP/sipgate.de-0a1a2150", "start.php|7|tc1") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  start.php|7|tc1: Array
  start.php|7|tc1: (
  start.php|7|tc1:     [code] => 200
  start.php|7|tc1:     [result] => 1
  start.php|7|tc1:     [data] => 091284441 <091284441>
  start.php|7|tc1: )
  start.php|7|tc1:
  start.php|7|tc1: Channel 7
  start.php|7|tc1: session 2224
    -- Playing '/var/spool/asterisk//tmp//swift_101c1cf757b40874effcafbec68fbe07' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
[Sep 27 19:26:50] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a2150> Playing 'beep' (language 'en')
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:05] NOTICE[983]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:07] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- ast_get_srv: SRV lookup for '_sip._udp.sipgate.de' mapped to host sipgate.de, port 5060
    -- <SIP/sipgate.de-0a1a2150> Playing 'beep' (language 'en')
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:21] NOTICE[983]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:23] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a2150> Playing 'beep' (language 'en')
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:37] NOTICE[983]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:39] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a2150> Playing 'beep' (language 'en')
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Executing [2351681@default:1] AGI("SIP/sipgate.de-0a1b24f0", "start.php|7|tc1") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  start.php|7|tc1: Array
  start.php|7|tc1: (
  start.php|7|tc1:     [code] => 200
  start.php|7|tc1:     [result] => 1
  start.php|7|tc1:     [data] => 091284441 <091284441>
  start.php|7|tc1: )
  start.php|7|tc1:
  start.php|7|tc1: Channel 7
  start.php|7|tc1: session 2226
    -- Playing '/var/spool/asterisk//tmp//swift_101c1cf757b40874effcafbec68fbe07' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:27:53] NOTICE[983]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1b24f0> Playing 'beep' (language 'en')
[Sep 27 19:27:55] NOTICE[972]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
    -- <SIP/sipgate.de-0a1a2150> Playing 'beep' (language 'en')
    -- <SIP/sipgate.de-0a1a7b38> Playing 'beep' (language 'en')
    -- Playing '/var/spool/asterisk//tmp//swift_1e063c27fd0f19329e685ffa061fac40' (escape_digits=) (sample_offset 0)
[Sep 27 19:28:05] NOTICE[990]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms?
    -- Playing '/var/spool/asterisk//tmp//swift_4c94da570535559a114f9a0b34f2b068' (escape_digits=) (sample_offset 0)
tc1*CLI>

Second server:

Asterisk 1.2.13, Copyright (C) 1999 - 2006 Digium, Inc. and others.
Created by Mark Spencer <markster@digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'show license' for details.
=========================================================================
Connected to Asterisk 1.2.13 currently running on miraculix (pid = 4577)
Verbosity was 0 and is now 14
    -- Executing AGI("SIP/sipgate.de-0816bf08", "start.php|7|miraculix") in new                                                                              stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-08                                                                             16bf08'
Sep 27 19:16:23 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the                                                                              channel lock for SIP/sipgate.de-0816bf08!
Sep 27 19:16:23 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGN                                                                             ORED: ACK
Sep 27 19:16:23 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
    -- Executing AGI("SIP/sipgate.de-0816bf08", "start.php|7|miraculix") in new                                                                              stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-08                                                                             16bf08'
Sep 27 19:17:18 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the                                                                              channel lock for SIP/sipgate.de-0816bf08!
Sep 27 19:17:18 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGN                                                                             ORED: ACK
Sep 27 19:17:18 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- Executing AGI("SIP/sipgate.de-0816bf08", "start.php|7|miraculix") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-0816bf08'
Sep 27 19:18:29 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the channel lock for SIP/sipgate.de-0816bf08!
Sep 27 19:18:29 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGNORED: ACK
Sep 27 19:18:29 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- Executing AGI("SIP/sipgate.de-081a6408", "start.php|7|miraculix") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-081a6408'
Sep 27 19:19:33 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the channel lock for SIP/sipgate.de-081a6408!
Sep 27 19:19:33 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGNORED: ACK
Sep 27 19:19:33 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
Sep 27 19:23:59 WARNING[4582]: res_musiconhold.c:421 spawn_mp3: Found no files in '/usr/share/asterisk/mohmp3'
Sep 27 19:23:59 WARNING[4582]: res_musiconhold.c:493 monmp3thread: Unable to spawn mp3player
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- Executing AGI("SIP/sipgate.de-081a6408", "start.php|7|miraculix") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  start.php|7|miraculix: Array
  start.php|7|miraculix: (
  start.php|7|miraculix:     [code] => 200
  start.php|7|miraculix:     [result] => 1
  start.php|7|miraculix:     [data] => 091284441 <091284441>
  start.php|7|miraculix: )
  start.php|7|miraculix:
  start.php|7|miraculix: Channel 7
  start.php|7|miraculix: session 2223
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-081a6408'
Sep 27 19:24:28 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the channel lock for SIP/sipgate.de-081a6408!
Sep 27 19:24:28 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGNORED: ACK
Sep 27 19:24:28 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
Sep 27 19:24:48 WARNING[4587]: chan_sip.c:1229 retrans_pkt: Maximum retries exceeded on transmission [1e2390085b6a28e067154e834be98111@sipgate.de](mailto:1e2390085b6a28e067154e834be98111@sipgate.de) for seqno 102 (Critical Response)
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- Executing AGI("SIP/sipgate.de-081a6408", "start.php|7|miraculix") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  start.php|7|miraculix: Array
  start.php|7|miraculix: (
  start.php|7|miraculix:     [code] => 200
  start.php|7|miraculix:     [result] => 1
  start.php|7|miraculix:     [data] => 091284441 <091284441>
  start.php|7|miraculix: )
  start.php|7|miraculix:
  start.php|7|miraculix: Channel 7
  start.php|7|miraculix: session 2225
Sep 27 19:26:18 WARNING[10540]: file.c:587 ast_readaudio_callback: Failed to write frame
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-081a6408'
Sep 27 19:26:38 WARNING[4587]: chan_sip.c:1229 retrans_pkt: Maximum retries exceeded on transmission [72c9509668ec25b04d29f12b350b87e0@sipgate.de](mailto:72c9509668ec25b04d29f12b350b87e0@sipgate.de) for seqno 102 (Critical Response)
    -- Executing AGI("SIP/sipgate.de-0816bf08", "start.php|7|miraculix") in new stack
    -- Launched AGI Script /usr/share/asterisk/agi-bin/start.php
  start.php|7|miraculix: Array
  start.php|7|miraculix: (
  start.php|7|miraculix:     [code] => 200
  start.php|7|miraculix:     [result] => 1
  start.php|7|miraculix:     [data] => 091284441 <091284441>
  start.php|7|miraculix: )
  start.php|7|miraculix:
  start.php|7|miraculix: Channel 7
  start.php|7|miraculix: session 2227
  == Spawn extension (default, 2351681, 1) exited non-zero on 'SIP/sipgate.de-0816bf08'
Sep 27 19:27:18 ERROR[4587]: chan_sip.c:11440 sipsock_read: We could NOT get the channel lock for SIP/sipgate.de-0816bf08!
Sep 27 19:27:18 ERROR[4587]: chan_sip.c:11441 sipsock_read: SIP MESSAGE JUST IGNORED: ACK
Sep 27 19:27:18 ERROR[4587]: chan_sip.c:11442 sipsock_read: BAD! BAD! BAD!
Sep 27 19:27:38 WARNING[4587]: chan_sip.c:1229 retrans_pkt: Maximum retries exceeded on transmission [7d815ce6313f739078ae5398582a61f5@sipgate.de](mailto:7d815ce6313f739078ae5398582a61f5@sipgate.de) for seqno 102 (Critical Response)
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060
    -- parse_srv: SRV mapped to host sipgate.de, port 5060

assachs · February 16, 2010, 9:38pm

Hi,
the problem still exists with both servers on 1.4.21.

Short description of the problem:
to asterisk servers are connected to a sip vpovier and waiting for calls. One of both servers should get the call (the one answering first). This works for some calls but after some calls the caller inputs are not received by the server.

I have some new facts.

Both servers receive a SIP INVITE
Both server send back INVITE
Both servers call the AGI script.
AGI->answer() return 0 on both servers.
Both servers start playback of a sound file.
Server 1 receives CANCEL.
Server 2 receives ACK
SERVER 1 sends CANCEL
SERVER 1 receives ACK
AGI-Script is still running on Server 1 and asks for caller input
caller inputs some dial tones.
Server 1 receives dial tones.
Server 1 answers and script exists
AGI on server 2 is still running.
Server 2 plays soundfile and asks for caller input
Caller input some dial tones but server2 don’t get them.
Server 2 plays soundfile and asks for caller input
Caller input some dial tones but server2 don’t get them.
…
Caller hangup
Server1 receives BYE
Server2 still playing soundfile (endless loop)
BYE never receives at server 2

For testing i inserted a wait in the dial plan of server1 . The cancel now arrives before the agi-script is called. with this configuration it is working.
There seems to be a problem if the call is already answered with a agi-script and then a CANCEL arrives. I don’t understand why both servers get a positive result code on ->answer(). I expected that only the first servre will get a positive result.

Thanks
Andi

Topic		Replies	Views
Unable to receive incoming calls via SIP Asterisk SIP	11	395	September 10, 2024
Strange delay Asterisk Support	0	260	May 28, 2007
[SOLVED]Asterisk can't answer the phone now Asterisk SIP	3	1253	April 2, 2019
PLEASE HELP!- Asterisk hungs up after 2 seconds Asterisk Support	7	836	November 6, 2015
Problem picking up a call in asterisk Asterisk Support	4	375	March 10, 2011

Redundancy problem with sip

This package has been modified for the Debian GNU/Linux distribution Please report all bugs to bugs.debian.org/asterisk

Related topics

This package has been modified for the Debian GNU/Linux distribution
Please report all bugs to bugs.debian.org/asterisk