Weird behavior incoming call rings twice, heard on two extensions

f3d3 · February 4, 2012, 1:11pm

Hi all,

I have this weird behavior (happens every now and then):

An incoming call rings the default ring group (782) (one extension (713) first and after 12 seconds, other extensions (including 713) ring). Sometimes extension 713 picks up the call but another extension (711) is also able to pickup the call. The caller can be heard on both extensions.

My setup: pbxinaflash 1.7.5.6 (incredible pbx for asterisk Ver. 1.8.4.1 and freepbx 2.8.1.0). I have several sip trunks and two PSTN trunks via two SPA3102. The incoming call with the problem is received by one SPA3102. Extension 713 is on one FXS of the same SPA3102. Extension 711 is a Siemens DECT IP phone (A580IP).

I would greatly appreciate any help!

Thanks,

Here are some logs:

32.
2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
s
SIP/713-00…
ANSWERED
08:59
33.

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27

[2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: [2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: [2012-01-18 11:32:55] VERBOSE[11346] pbx.c: [2012-01-18 11:32:55] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11348] manager.c: [2012-01-18 11:32:56] VERBOSE[11348] manager.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:32:56] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:00] VERBOSE[11346] pbx.c: [2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: [2012-01-18 11:33:09] VERBOSE[11346] pbx.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:10] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: [2012-01-18 11:33:15] VERBOSE[11346] pbx.c: [2012-01-18 11:33:15] VERBOSE[11346] pbx.c: [2012-01-18 11:33:38] NOTICE[4915] [2012-01-18 11:33:38] NOTICE[4920] [2012-01-18 11:33:38] NOTICE[4925] [2012-01-18 11:33:38] NOTICE[4919] [2012-01-18 11:34:06] VERBOSE[11346] res_musiconhold.c: [2012-01-18 11:34:06] VERBOSE[11346] file.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] pbx.c: [2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: [2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: [2012-01-18 11:34:11] VERBOSE[11355] app_dial.c: [2012-01-18 11:34:11] VERBOSE[11346] features.c: [2012-01-18 11:34:12] VERBOSE[11355] app_dial.c: [2012-01-18 11:34:12] VERBOSE[11346] features.c: [2012-01-18 11:34:15] VERBOSE[11355] app_dial.c: [2012-01-18 11:34:15] VERBOSE[11355] pbx.c: [2012-01-18 11:34:15] VERBOSE[11355] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: [2012-01-18 11:34:22] VERBOSE[11346] res_musiconhold.c: [2012-01-18 11:34:22] VERBOSE[11346] file.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: [2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: [2012-01-18 11:34:22] VERBOSE[11346] pbx.c: [2012-01-18 11:36:01] VERBOSE[4604] asterisk.c: [2012-01-18 11:36:01] VERBOSE[11397] asterisk.c: == Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Executing [915YYYYYY@from-trunk:1] Set(“SIP/4-telefonica-00000233”, “__FROM_DID=915YYYYYY”) in new stack
– Executing [915YYYYYY@from-trunk:2] Gosub(“SIP/4-PSTN-00000233”, “cidlookup,cidlookup_3,1”) in new stack
== Manager ‘admin’ logged on from 127.0.0.1
== Manager ‘admin’ logged off from 127.0.0.1
– Executing [cidlookup_3@cidlookup:1] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
– Executing [cidlookup_3@cidlookup:2] Return(“SIP/4-PSTN-00000233”, “”) in new stack
– Executing [915YYYYYY@from-trunk:3] Gosub(“SIP/4-PSTN-00000233”, “app-blacklist-check,s,1”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/4-PSTN-00000233”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/4-PSTN-00000233”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/4-PSTN-00000233”, “”) in new stack
– Executing [915YYYYYY@from-trunk:4] Set(“SIP/4-PSTN-00000233”, “CHANNEL(language)=es”) in new stack
– Executing [915YYYYYY@from-trunk:5] ExecIf(“SIP/4-PSTN-00000233”, “0 ?Set(CALLERID(name)=627617XXX)”) in new stack
– Executing [915YYYYYY@from-trunk:6] Set(“SIP/4-PSTN-00000233”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [915YYYYYY@from-trunk:7] Set(“SIP/4-PSTN-00000233”, “CALLERPRES()=allowed_not_screened”) in new stack
– Executing [915YYYYYY@from-trunk:8] Set(“SIP/4-PSTN-00000233”, “FAX_DEST=ext-miscdests^2^1”) in new stack
– Executing [915YYYYYY@from-trunk:9] Answer(“SIP/4-PSTN-00000233”, “”) in new stack
– Executing [915YYYYYY@from-trunk:10] Wait(“SIP/4-PSTN-00000233”, “4”) in new stack
– Executing [915YYYYYY@from-trunk:11] Goto(“SIP/4-PSTN-00000233”, “ext-group,782,1”) in new stack
– Goto (ext-group,782,1)
– Executing [782@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “1?Set(REALCALLERIDNUM=627617XXX)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
– Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
– Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
– Executing [782@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “1?skipdb”) in new stack
– Goto (ext-group,782,4)
– Executing [782@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
– Executing [782@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/782/SIP/4-PSTN-00000233”) in new stack
– Executing [782@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=782”) in new stack
– Executing [782@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/782/SIP/4-PSTN-00000233)=TRUE”) in new stack
– Executing [782@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
– Executing [782@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=782”) in new stack
– Executing [782@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
– Executing [782@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
– Executing [782@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,713,Group”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
– Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
– Goto (macro-record-enable,s,6)
– Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=1”) in new stack
– Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
– Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-record-enable,s,13)
– Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
– Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
– Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
– Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
– Executing [782@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
– Executing [782@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,8,Ttr,713”) in new stack
– Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
dialparties.agi: Methodology of ring is ‘ringall’
– dialparties.agi: Added extension 713 to extension map
– dialparties.agi: Extension 713 cf is disabled
– dialparties.agi: Extension 713 do not disturb is disabled
dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
dialparties.agi: Extension 713 has ExtensionState: 0
– dialparties.agi: Checking CW and CFB status for extension 713
– dialparties.agi: dbset CALLTRACE/713 to 627617XXX
– dialparties.agi: Filtered ARG3: 713
– <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/713,8,TtrM(auto-blkvm)”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 713
– SIP/713-00000234 is ringing
– Nobody picked up in 8000 ms
– Executing [s@macro-dial:8] Set(“SIP/4-PSTN-00000233”, “DIALSTATUS=NOANSWER”) in new stack
– Executing [s@macro-dial:9] GosubIf(“SIP/4-PSTN-00000233”, “0?NOANSWER,1”) in new stack
– Executing [782@ext-group:15] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=”) in new stack
– Executing [782@ext-group:16] GotoIf(“SIP/4-PSTN-00000233”, “0?nodest”) in new stack
– Executing [782@ext-group:17] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
– Executing [782@ext-group:18] NoOp(“SIP/4-PSTN-00000233”, “Deleting: BLKVM/782/SIP/4-PSTN-00000233 TRUE”) in new stack
– Executing [782@ext-group:19] Goto(“SIP/4-PSTN-00000233”, “ext-group,779,1”) in new stack
– Goto (ext-group,779,1)
– Executing [779@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “0?Set(REALCALLERIDNUM=627617XXX)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=63”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
– Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
– Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
– Executing [779@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “0?skipdb”) in new stack
– Executing [779@ext-group:3] GotoIf(“SIP/4-PSTN-00000233”, “0?skipov”) in new stack
– Executing [779@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
– Executing [779@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/779/SIP/4-PSTN-00000233”) in new stack
– Executing [779@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=779”) in new stack
– Executing [779@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/779/SIP/4-PSTN-00000233)=TRUE”) in new stack
– Executing [779@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
– Executing [779@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=779”) in new stack
– Executing [779@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
– Executing [779@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
– Executing [779@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,708-718-728-713,Group”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
– Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
– Goto (macro-record-enable,s,6)
– Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=4”) in new stack
– Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
– Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-record-enable,s,13)
– Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
– Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
– Goto (macro-record-enable,s,8)
– Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-record-enable,s,13)
– Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=3”) in new stack
– Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
– Goto (macro-record-enable,s,8)
– Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-record-enable,s,13)
– Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=4”) in new stack
– Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
– Goto (macro-record-enable,s,8)
– Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
– Goto (macro-record-enable,s,13)
– Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=5”) in new stack
– Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
– Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
– Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
– Executing [779@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
– Executing [779@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,30,Ttr,708-718-728-713”) in new stack
– Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
dialparties.agi: Methodology of ring is ‘ringall’
– dialparties.agi: Added extension 708 to extension map
– dialparties.agi: Added extension 718 to extension map
– dialparties.agi: Added extension 728 to extension map
– dialparties.agi: Added extension 713 to extension map
– dialparties.agi: Extension 708 cf is disabled
– dialparties.agi: Extension 718 cf is disabled
– dialparties.agi: Extension 728 cf is disabled
– dialparties.agi: Extension 713 cf is disabled
– dialparties.agi: Extension 708 do not disturb is disabled
– dialparties.agi: Extension 718 do not disturb is disabled
– dialparties.agi: Extension 728 do not disturb is disabled
– dialparties.agi: Extension 713 do not disturb is disabled
– dialparties.agi: dbset CALLTRACE/708 to 627617XXX
– dialparties.agi: dbset CALLTRACE/718 to 627617XXX
– dialparties.agi: dbset CALLTRACE/728 to 627617XXX
dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
dialparties.agi: Extension 713 has ExtensionState: 0
– dialparties.agi: Checking CW and CFB status for extension 713
– dialparties.agi: dbset CALLTRACE/713 to 627617XXX
– dialparties.agi: Filtered ARG3: 708-718-728-713
– <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/708&SIP/718&SIP/728&SIP/713,30,TtrM(auto-blkvm)”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 708
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 718
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 728
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 713
– SIP/713-00000238 is ringing
– SIP/708-00000235 is ringing
– SIP/718-00000236 is ringing
– SIP/713-00000238 connected line has changed. Saving it until answer for SIP/4-PSTN-00000233
– SIP/713-00000238 answered SIP/4-PSTN-00000233
– Executing [s@macro-auto-blkvm:1] Set(“SIP/713-00000238”, “__MACRO_RESULT=”) in new stack
– Executing [s@macro-auto-blkvm:2] NoOp(“SIP/713-00000238”, “Deleting: BLKVM/779/SIP/4-PSTN-00000233 TRUE”) in new stack
chan_iax2.c: Peer ‘iax-fax0’ is not dynamic (from 127.0.0.1)
chan_iax2.c: Peer ‘iax-fax1’ is not dynamic (from 127.0.0.1)
chan_iax2.c: Peer ‘iax-fax3’ is not dynamic (from 127.0.0.1)
chan_iax2.c: Peer ‘iax-fax2’ is not dynamic (from 127.0.0.1)
– Started music on hold, class ‘default’, on SIP/4-PSTN-00000233
– <SIP/713-00000238> Playing ‘pbx-transfer.ulaw’ (language ‘es’)
– Executing [723@from-internal-xfer:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “exten-vm,723,723”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “AMPUSER=779”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [s@macro-user-callerid:10] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“Local/723@from-internal-xfer-5f0d;2”, “__TTL=62”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(number)=779”) in new stack
– Executing [s@macro-user-callerid:20] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(name)=”) in new stack
– Executing [s@macro-user-callerid:21] NoOp(“Local/723@from-internal-xfer-5f0d;2”, “Using CallerID “” <779>”) in new stack
– Executing [s@macro-exten-vm:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “VMBOX=723”) in new stack
– Executing [s@macro-exten-vm:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “__EXTTOCALL=723”) in new stack
– Executing [s@macro-exten-vm:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFUEXT=”) in new stack
– Executing [s@macro-exten-vm:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFBEXT=”) in new stack
– Executing [s@macro-exten-vm:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “RT=20”) in new stack
– Executing [s@macro-exten-vm:8] Macro(“Local/723@from-internal-xfer-5f0d;2”, “record-enable,723,IN”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?MacroExit()”) in new stack
– Executing [s@macro-record-enable:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Group:OUT”) in new stack
– Goto (macro-record-enable,s,15)
– Executing [s@macro-record-enable:15] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?IN”) in new stack
– Goto (macro-record-enable,s,20)
– Executing [s@macro-record-enable:20] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “1?MacroExit()”) in new stack
– Executing [s@macro-exten-vm:9] Macro(“Local/723@from-internal-xfer-5f0d;2”, “dial-one,20,Ttr,723”) in new stack
– Executing [s@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEXTEN=723”) in new stack
– Executing [s@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:3] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?screen,1”) in new stack
– Executing [s@macro-dial-one:4] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?cf,1”) in new stack
– Executing [s@macro-dial-one:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,8)
– Executing [s@macro-dial-one:8] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
– Executing [s@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “EXTHASCW=”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,12)
– Executing [s@macro-dial-one:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?docfu:skip3”) in new stack
– Goto (macro-dial-one,s,16)
– Executing [s@macro-dial-one:16] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next2:continue”) in new stack
– Goto (macro-dial-one,s,17)
– Executing [s@macro-dial-one:17] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [s@macro-dial-one:25] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:26] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?dstring,1:dlocal,1”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEVICES=723”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(DEVICES=23)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
– Executing [dstring@macro-dial-one:8] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?zap2dahdi,1”) in new stack
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
– Executing [zap2dahdi@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=”) in new stack
– Executing [zap2dahdi@macro-dial-one:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISPART2=SIP/723”) in new stack
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(THISPART2=DAHDI/723)”) in new stack
– Executing [zap2dahdi@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=SIP/723&”) in new stack
– Executing [zap2dahdi@macro-dial-one:8] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=2”) in new stack
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin2”) in new stack
– Executing [zap2dahdi@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
– Executing [zap2dahdi@macro-dial-one:11] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
– Executing [dstring@macro-dial-one:9] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723&”) in new stack
– Executing [dstring@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:12] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723”) in new stack
– Executing [dstring@macro-dial-one:13] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
– Executing [s@macro-dial-one:27] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skiptrace”) in new stack
– Goto (macro-dial-one,s,30)
– Executing [s@macro-dial-one:30] Set(“Local/723@from-internal-xfer-5f0d;2”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
– Executing [s@macro-dial-one:31] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
– Executing [s@macro-dial-one:32] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader()”) in new stack
– Executing [s@macro-dial-one:33] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:34] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?qwait,1”) in new stack
– Executing [s@macro-dial-one:35] Set(“Local/723@from-internal-xfer-5f0d;2”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:36] Set(“Local/723@from-internal-xfer-5f0d;2”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:37] Dial(“Local/723@from-internal-xfer-5f0d;2”, “SIP/723,20,TtrM(auto-blkvm)”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 723
– Local/723@from-internal-xfer-5f0d;1 is ringing
– SIP/723-00000239 is ringing
– Local/723@from-internal-xfer-5f0d;1 is ringing
– SIP/723-00000239 answered Local/723@from-internal-xfer-5f0d;2
– Executing [s@macro-auto-blkvm:1] Set(“SIP/723-00000239”, “__MACRO_RESULT=”) in new stack
– Executing [s@macro-auto-blkvm:2] NoOp(“SIP/723-00000239”, "Deleting: BLKVM/779/SIP/4-PSTN-00000233 ") in new stack
– Executing [h@macro-dial:1] Macro(“SIP/713-00000238”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/713-00000238”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] GotoIf(“SIP/713-00000238”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [s@macro-hangupcall:7] GotoIf(“SIP/713-00000238”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [s@macro-hangupcall:9] Hangup(“SIP/713-00000238”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/713-00000238’ in macro ‘hangupcall’
– Stopped music on hold on SIP/4-PSTN-00000233
– <Local/723@from-internal-xfer-5f0d;1> Playing ‘beep.ulaw’ (language ‘es’)
– Executing [h@macro-dial:1] Macro(“Transfered/SIP/4-PSTN-00000233”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [s@macro-hangupcall:7] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [s@macro-hangupcall:9] Hangup(“Transfered/SIP/4-PSTN-00000233”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘hangupcall’
== Spawn extension (macro-dial, s, 7) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘dial’
== Spawn extension (ext-group, 779, 14) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’
– Remote UNIX connection
– Remote UNIX connection disconnected

cosmicwombat · February 4, 2012, 5:29pm

Was this empty post a mistake ? You might want to include such details as ISO used to build the PBX and current version plus a little about what your dialplan looks like and what you are attempting to make work. Also, the type of phones you are using might be worth mentioning.

Simply typing “Weird behavior incoming call rings twice, heard on two extensions” is so vague it boggles the mind.

f3d3 · February 4, 2012, 6:05pm

Hi to all,

Sometimes I am having an incoming call which rings my default ring group (rings extension 713 for 12 seconds), then rings a second group (which includes extension 713) and the call is answered by two extensions at the same time (713 and 711) and both extensions can hear the caller. The incoming trunk is PSTN which is connected via a SPA3102. Extension 713 is also connected to the FXS of the SPA3102. Extension 711 is a Siemens DECT IP phone (A580IP).

I am running pbx in a flash 1.7.5.6 (asterisk 1.8.4.1) / freepbx 2.8.1.0

Thanks for any help,

Some logs:

32.
2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
s
SIP/713-00…
ANSWERED
08:59
33.

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27

[2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:32:55] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:1] Set(“SIP/4-telefonica-00000233”, “__FROM_DID=915YYYYYY”) in new stack
[2012-01-18 11:32:55] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:2] Gosub(“SIP/4-PSTN-00000233”, “cidlookup,cidlookup_3,1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11348] manager.c: == Manager ‘admin’ logged on from 127.0.0.1
[2012-01-18 11:32:56] VERBOSE[11348] manager.c: == Manager ‘admin’ logged off from 127.0.0.1
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [cidlookup_3@cidlookup:1] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [cidlookup_3@cidlookup:2] Return(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:3] Gosub(“SIP/4-PSTN-00000233”, “app-blacklist-check,s,1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/4-PSTN-00000233”, “0?blacklisted”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/4-PSTN-00000233”, “CALLED_BLACKLIST=1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:4] Set(“SIP/4-PSTN-00000233”, “CHANNEL(language)=es”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:5] ExecIf(“SIP/4-PSTN-00000233”, “0 ?Set(CALLERID(name)=627617XXX)”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:6] Set(“SIP/4-PSTN-00000233”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:7] Set(“SIP/4-PSTN-00000233”, “CALLERPRES()=allowed_not_screened”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:8] Set(“SIP/4-PSTN-00000233”, “FAX_DEST=ext-miscdests^2^1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:9] Answer(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:10] Wait(“SIP/4-PSTN-00000233”, “4”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:11] Goto(“SIP/4-PSTN-00000233”, “ext-group,782,1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (ext-group,782,1)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “1?Set(REALCALLERIDNUM=627617XXX)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=64”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “1?skipdb”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (ext-group,782,4)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/782/SIP/4-PSTN-00000233”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=782”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/782/SIP/4-PSTN-00000233)=TRUE”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=782”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,713,Group”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,6)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,8,Ttr,713”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-dial,s,3)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 713 to extension map
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 cf is disabled
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 do not disturb is disabled
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Extension 713 has ExtensionState: 0
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Checking CW and CFB status for extension 713
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/713 to 627617XXX
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Filtered ARG3: 713
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/713,8,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – Called 713
[2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – SIP/713-00000234 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Nobody picked up in 8000 ms
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:8] Set(“SIP/4-PSTN-00000233”, “DIALSTATUS=NOANSWER”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:9] GosubIf(“SIP/4-PSTN-00000233”, “0?NOANSWER,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:15] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:16] GotoIf(“SIP/4-PSTN-00000233”, “0?nodest”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:17] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:18] NoOp(“SIP/4-PSTN-00000233”, “Deleting: BLKVM/782/SIP/4-PSTN-00000233 TRUE”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:19] Goto(“SIP/4-PSTN-00000233”, “ext-group,779,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (ext-group,779,1)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “0?Set(REALCALLERIDNUM=627617XXX)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=63”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “0?skipdb”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:3] GotoIf(“SIP/4-PSTN-00000233”, “0?skipov”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/779/SIP/4-PSTN-00000233”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=779”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/779/SIP/4-PSTN-00000233)=TRUE”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=779”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,708-718-728-713,Group”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,6)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=4”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=3”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=4”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=5”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,30,Ttr,708-718-728-713”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-dial,s,3)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 708 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 718 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 728 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 713 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 708 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 718 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 728 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 708 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 718 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 728 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/708 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/718 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/728 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Extension 713 has ExtensionState: 0
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Checking CW and CFB status for extension 713
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/713 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Filtered ARG3: 708-718-728-713
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/708&SIP/718&SIP/728&SIP/713,30,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 708
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 718
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 728
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 713
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/713-00000238 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/708-00000235 is ringing
[2012-01-18 11:33:10] VERBOSE[11346] app_dial.c: – SIP/718-00000236 is ringing
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 connected line has changed. Saving it until answer for SIP/4-PSTN-00000233
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 answered SIP/4-PSTN-00000233
[2012-01-18 11:33:15] VERBOSE[11346] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/713-00000238”, “__MACRO_RESULT=”) in new stack
[2012-01-18 11:33:15] VERBOSE[11346] pbx.c: – Executing [s@macro-auto-blkvm:2] NoOp(“SIP/713-00000238”, “Deleting: BLKVM/779/SIP/4-PSTN-00000233 TRUE”) in new stack
[2012-01-18 11:33:38] NOTICE[4915] chan_iax2.c: Peer ‘iax-fax0’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4920] chan_iax2.c: Peer ‘iax-fax1’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4925] chan_iax2.c: Peer ‘iax-fax3’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4919] chan_iax2.c: Peer ‘iax-fax2’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:34:06] VERBOSE[11346] res_musiconhold.c: – Started music on hold, class ‘default’, on SIP/4-PSTN-00000233
[2012-01-18 11:34:06] VERBOSE[11346] file.c: – <SIP/713-00000238> Playing ‘pbx-transfer.ulaw’ (language ‘es’)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [723@from-internal-xfer:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “exten-vm,723,723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “user-callerid,”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “AMPUSER=779”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?report”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:11] Set(“Local/723@from-internal-xfer-5f0d;2”, “__TTL=62”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:19] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(number)=779”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:20] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(name)=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“Local/723@from-internal-xfer-5f0d;2”, “Using CallerID “” <779>”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “RingGroupMethod=none”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “VMBOX=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “__EXTTOCALL=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFUEXT=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFBEXT=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “RT=20”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:8] Macro(“Local/723@from-internal-xfer-5f0d;2”, “record-enable,723,IN”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?check”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?MacroExit()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Group:OUT”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,15)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?IN”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,20)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:20] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “1?MacroExit()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:9] Macro(“Local/723@from-internal-xfer-5f0d;2”, “dial-one,20,Ttr,723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEXTEN=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DIALSTATUS_CW=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?screen,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?cf,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skip1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,8)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “EXTHASCW=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next1:cwinusebusy”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,12)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?docfu:skip3”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,16)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:16] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next2:continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,17)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:17] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,25)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?dstring,1:dlocal,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEVICES=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(DEVICES=23)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?zap2dahdi,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT2=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISPART2=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(THISPART2=DAHDI/723)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=SIP/723&”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723&”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skiptrace”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,30)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:30] Set(“Local/723@from-internal-xfer-5f0d;2”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?qwait,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:35] Set(“Local/723@from-internal-xfer-5f0d;2”, “__CWIGNORE=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:36] Set(“Local/723@from-internal-xfer-5f0d;2”, “__KEEPCID=TRUE”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:37] Dial(“Local/723@from-internal-xfer-5f0d;2”, “SIP/723,20,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:34:11] VERBOSE[11355] app_dial.c: – Called 723
[2012-01-18 11:34:11] VERBOSE[11346] features.c: – Local/723@from-internal-xfer-5f0d;1 is ringing
[2012-01-18 11:34:12] VERBOSE[11355] app_dial.c: – SIP/723-00000239 is ringing
[2012-01-18 11:34:12] VERBOSE[11346] features.c: – Local/723@from-internal-xfer-5f0d;1 is ringing
[2012-01-18 11:34:15] VERBOSE[11355] app_dial.c: – SIP/723-00000239 answered Local/723@from-internal-xfer-5f0d;2
[2012-01-18 11:34:15] VERBOSE[11355] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/723-00000239”, “__MACRO_RESULT=”) in new stack
[2012-01-18 11:34:15] VERBOSE[11355] pbx.c: – Executing [s@macro-auto-blkvm:2] NoOp(“SIP/723-00000239”, "Deleting: BLKVM/779/SIP/4-PSTN-00000233 ") in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/713-00000238”, “hangupcall”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/713-00000238”, “1?skiprg”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,4)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/713-00000238”, “1?skipblkvm”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,7)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/713-00000238”, “1?theend”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,9)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/713-00000238”, “”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/713-00000238’ in macro ‘hangupcall’
[2012-01-18 11:34:22] VERBOSE[11346] res_musiconhold.c: – Stopped music on hold on SIP/4-PSTN-00000233
[2012-01-18 11:34:22] VERBOSE[11346] file.c: – <Local/723@from-internal-xfer-5f0d;1> Playing ‘beep.ulaw’ (language ‘es’)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [h@macro-dial:1] Macro(“Transfered/SIP/4-PSTN-00000233”, “hangupcall”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skiprg”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,4)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skipblkvm”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,7)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?theend”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,9)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“Transfered/SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘hangupcall’
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘dial’
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: == Spawn extension (ext-group, 779, 14) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’
[2012-01-18 11:36:01] VERBOSE[4604] asterisk.c: – Remote UNIX connection
[2012-01-18 11:36:01] VERBOSE[11397] asterisk.c: – Remote UNIX connection disconnected

f3d3 · February 4, 2012, 6:09pm

Hi to all,

Sometimes I am having an incoming call which rings my default ring group (rings extension 713 for 12 seconds), then rings a second group (which includes extension 713) and the call is answered by two extensions at the same time (713 and 711) and both extensions can hear the caller. The incoming trunk is PSTN which is connected via a SPA3102. Extension 713 is also connected to the FXS of the SPA3102. Extension 711 is a Siemens DECT IP phone (A580IP).

I am running pbx in a flash 1.7.5.6 (asterisk 1.8.4.1) / freepbx 2.8.1.0

Thanks for any help,

Some logs:
32.
2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
s
SIP/713-00…
ANSWERED
08:59
33.

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27

[2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:32:55] VERBOSE[4745] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:32:55] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:1] Set(“SIP/4-telefonica-00000233”, “__FROM_DID=915YYYYYY”) in new stack
[2012-01-18 11:32:55] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:2] Gosub(“SIP/4-PSTN-00000233”, “cidlookup,cidlookup_3,1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11348] manager.c: == Manager ‘admin’ logged on from 127.0.0.1
[2012-01-18 11:32:56] VERBOSE[11348] manager.c: == Manager ‘admin’ logged off from 127.0.0.1
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [cidlookup_3@cidlookup:1] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [cidlookup_3@cidlookup:2] Return(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:3] Gosub(“SIP/4-PSTN-00000233”, “app-blacklist-check,s,1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/4-PSTN-00000233”, “0?blacklisted”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/4-PSTN-00000233”, “CALLED_BLACKLIST=1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:4] Set(“SIP/4-PSTN-00000233”, “CHANNEL(language)=es”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:5] ExecIf(“SIP/4-PSTN-00000233”, “0 ?Set(CALLERID(name)=627617XXX)”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:6] Set(“SIP/4-PSTN-00000233”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:7] Set(“SIP/4-PSTN-00000233”, “CALLERPRES()=allowed_not_screened”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:8] Set(“SIP/4-PSTN-00000233”, “FAX_DEST=ext-miscdests^2^1”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:9] Answer(“SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:32:56] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:10] Wait(“SIP/4-PSTN-00000233”, “4”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [915YYYYYY@from-trunk:11] Goto(“SIP/4-PSTN-00000233”, “ext-group,782,1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (ext-group,782,1)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “1?Set(REALCALLERIDNUM=627617XXX)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=64”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “1?skipdb”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (ext-group,782,4)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/782/SIP/4-PSTN-00000233”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=782”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/782/SIP/4-PSTN-00000233)=TRUE”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=782”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,713,Group”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,6)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [782@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,8,Ttr,713”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Goto (macro-dial,s,3)
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 713 to extension map
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 cf is disabled
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 do not disturb is disabled
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: dialparties.agi: Extension 713 has ExtensionState: 0
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Checking CW and CFB status for extension 713
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/713 to 627617XXX
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – dialparties.agi: Filtered ARG3: 713
[2012-01-18 11:33:00] VERBOSE[11346] res_agi.c: – <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
[2012-01-18 11:33:00] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/713,8,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:00] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – Called 713
[2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – SIP/713-00000234 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Nobody picked up in 8000 ms
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:8] Set(“SIP/4-PSTN-00000233”, “DIALSTATUS=NOANSWER”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:9] GosubIf(“SIP/4-PSTN-00000233”, “0?NOANSWER,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:15] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:16] GotoIf(“SIP/4-PSTN-00000233”, “0?nodest”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:17] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:18] NoOp(“SIP/4-PSTN-00000233”, “Deleting: BLKVM/782/SIP/4-PSTN-00000233 TRUE”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [782@ext-group:19] Goto(“SIP/4-PSTN-00000233”, “ext-group,779,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (ext-group,779,1)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:1] Macro(“SIP/4-PSTN-00000233”, “user-callerid,”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4-PSTN-00000233”, “AMPUSER=627617XXX”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4-PSTN-00000233”, “0?report”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4-PSTN-00000233”, “0?Set(REALCALLERIDNUM=627617XXX)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4-PSTN-00000233”, “AMPUSER=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4-PSTN-00000233”, “AMPUSERCIDNAME=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4-PSTN-00000233”, “1?report”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4-PSTN-00000233”, “0?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/4-PSTN-00000233”, “__TTL=63”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4-PSTN-00000233”, “CALLERID(number)=627617XXX”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4-PSTN-00000233”, “CALLERID(name)=(N/A)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4-PSTN-00000233”, “Using CallerID “(N/A)” <627617958>”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:2] GotoIf(“SIP/4-PSTN-00000233”, “0?skipdb”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:3] GotoIf(“SIP/4-PSTN-00000233”, “0?skipov”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:4] Set(“SIP/4-PSTN-00000233”, “__NODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:5] Set(“SIP/4-PSTN-00000233”, “__BLKVM_OVERRIDE=BLKVM/779/SIP/4-PSTN-00000233”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:6] Set(“SIP/4-PSTN-00000233”, “__BLKVM_BASE=779”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:7] Set(“SIP/4-PSTN-00000233”, “DB(BLKVM/779/SIP/4-PSTN-00000233)=TRUE”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:8] Set(“SIP/4-PSTN-00000233”, “RRNODEST=”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:9] Set(“SIP/4-PSTN-00000233”, “__NODEST=779”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:10] GosubIf(“SIP/4-PSTN-00000233”, “0?sub-rgsetcid,s,1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:11] Set(“SIP/4-PSTN-00000233”, “RecordMethod=Group”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:12] Macro(“SIP/4-PSTN-00000233”, “record-enable,708-718-728-713,Group”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4-PSTN-00000233”, “1?check”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4-PSTN-00000233”, “0?MacroExit()”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4-PSTN-00000233”, “1?Group:OUT”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,6)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:6] Set(“SIP/4-PSTN-00000233”, “LOOPCNT=4”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:7] Set(“SIP/4-PSTN-00000233”, “ITER=1”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=2”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=3”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=4”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “1?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,8)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:8] GotoIf(“SIP/4-PSTN-00000233”, “1?continue”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-record-enable,s,13)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:13] Set(“SIP/4-PSTN-00000233”, “ITER=5”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:14] GotoIf(“SIP/4-PSTN-00000233”, “0?begin”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4-PSTN-00000233”, “0?IN”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/4-PSTN-00000233”, “1?MacroExit()”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:13] Set(“SIP/4-PSTN-00000233”, “RingGroupMethod=ringall”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [779@ext-group:14] Macro(“SIP/4-PSTN-00000233”, “dial,30,Ttr,708-718-728-713”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/4-PSTN-00000233”, “1?dial”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Goto (macro-dial,s,3)
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/4-PSTN-00000233”, “dialparties.agi”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Caller ID name is ‘(N/A)’ number is ‘627617XXX’
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Methodology of ring is ‘ringall’
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 708 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 718 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 728 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Added extension 713 to extension map
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 708 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 718 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 728 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 cf is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 708 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 718 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 728 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Extension 713 do not disturb is disabled
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/708 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/718 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/728 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: dialparties.agi: Extension 713 has ExtensionState: 0
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Checking CW and CFB status for extension 713
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: dbset CALLTRACE/713 to 627617XXX
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – dialparties.agi: Filtered ARG3: 708-718-728-713
[2012-01-18 11:33:09] VERBOSE[11346] res_agi.c: – <SIP/4-PSTN-00000233>AGI Script dialparties.agi completed, returning 0
[2012-01-18 11:33:09] VERBOSE[11346] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/4-PSTN-00000233”, “SIP/708&SIP/718&SIP/728&SIP/713,30,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 708
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 718
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 728
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:33:09] VERBOSE[11346] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Called 713
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/713-00000238 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/708-00000235 is ringing
[2012-01-18 11:33:10] VERBOSE[11346] app_dial.c: – SIP/718-00000236 is ringing
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 connected line has changed. Saving it until answer for SIP/4-PSTN-00000233
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 answered SIP/4-PSTN-00000233
[2012-01-18 11:33:15] VERBOSE[11346] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/713-00000238”, “__MACRO_RESULT=”) in new stack
[2012-01-18 11:33:15] VERBOSE[11346] pbx.c: – Executing [s@macro-auto-blkvm:2] NoOp(“SIP/713-00000238”, “Deleting: BLKVM/779/SIP/4-PSTN-00000233 TRUE”) in new stack
[2012-01-18 11:33:38] NOTICE[4915] chan_iax2.c: Peer ‘iax-fax0’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4920] chan_iax2.c: Peer ‘iax-fax1’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4925] chan_iax2.c: Peer ‘iax-fax3’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:33:38] NOTICE[4919] chan_iax2.c: Peer ‘iax-fax2’ is not dynamic (from 127.0.0.1)
[2012-01-18 11:34:06] VERBOSE[11346] res_musiconhold.c: – Started music on hold, class ‘default’, on SIP/4-PSTN-00000233
[2012-01-18 11:34:06] VERBOSE[11346] file.c: – <SIP/713-00000238> Playing ‘pbx-transfer.ulaw’ (language ‘es’)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [723@from-internal-xfer:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “exten-vm,723,723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“Local/723@from-internal-xfer-5f0d;2”, “user-callerid,”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “AMPUSER=779”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?report”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-user-callerid,s,10)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:11] Set(“Local/723@from-internal-xfer-5f0d;2”, “__TTL=62”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-user-callerid,s,19)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:19] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(number)=779”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:20] Set(“Local/723@from-internal-xfer-5f0d;2”, “CALLERID(name)=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“Local/723@from-internal-xfer-5f0d;2”, “Using CallerID “” <779>”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “RingGroupMethod=none”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “VMBOX=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “__EXTTOCALL=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFUEXT=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “CFBEXT=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “RT=20”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:8] Macro(“Local/723@from-internal-xfer-5f0d;2”, “record-enable,723,IN”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?check”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,4)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?MacroExit()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Group:OUT”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,15)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?IN”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-record-enable,s,20)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-record-enable:20] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “1?MacroExit()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-exten-vm:9] Macro(“Local/723@from-internal-xfer-5f0d;2”, “dial-one,20,Ttr,723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEXTEN=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DIALSTATUS_CW=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?screen,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?cf,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skip1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,8)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “EXTHASCW=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next1:cwinusebusy”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,12)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:12] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?docfu:skip3”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,16)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:16] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?next2:continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,17)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:17] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?continue”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,25)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?dstring,1:dlocal,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “DEVICES=723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(DEVICES=23)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “1?zap2dahdi,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Return()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“Local/723@from-internal-xfer-5f0d;2”, “LOOPCNT2=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISPART2=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(THISPART2=DAHDI/723)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“Local/723@from-internal-xfer-5f0d;2”, “NEWDIAL=SIP/723&”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER2=2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “THISDIAL=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723&”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“Local/723@from-internal-xfer-5f0d;2”, “ITER=2”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?begin”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“Local/723@from-internal-xfer-5f0d;2”, “DSTRING=SIP/723”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“Local/723@from-internal-xfer-5f0d;2”, “”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “0?nodial”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“Local/723@from-internal-xfer-5f0d;2”, “1?skiptrace”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Goto (macro-dial-one,s,30)
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:30] Set(“Local/723@from-internal-xfer-5f0d;2”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?SIPAddHeader()”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“Local/723@from-internal-xfer-5f0d;2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“Local/723@from-internal-xfer-5f0d;2”, “0?qwait,1”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:35] Set(“Local/723@from-internal-xfer-5f0d;2”, “__CWIGNORE=”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:36] Set(“Local/723@from-internal-xfer-5f0d;2”, “__KEEPCID=TRUE”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] pbx.c: – Executing [s@macro-dial-one:37] Dial(“Local/723@from-internal-xfer-5f0d;2”, “SIP/723,20,TtrM(auto-blkvm)”) in new stack
[2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: == Using SIP RTP TOS bits 184
[2012-01-18 11:34:11] VERBOSE[11355] netsock2.c: == Using SIP RTP CoS mark 5
[2012-01-18 11:34:11] VERBOSE[11355] app_dial.c: – Called 723
[2012-01-18 11:34:11] VERBOSE[11346] features.c: – Local/723@from-internal-xfer-5f0d;1 is ringing
[2012-01-18 11:34:12] VERBOSE[11355] app_dial.c: – SIP/723-00000239 is ringing
[2012-01-18 11:34:12] VERBOSE[11346] features.c: – Local/723@from-internal-xfer-5f0d;1 is ringing
[2012-01-18 11:34:15] VERBOSE[11355] app_dial.c: – SIP/723-00000239 answered Local/723@from-internal-xfer-5f0d;2
[2012-01-18 11:34:15] VERBOSE[11355] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/723-00000239”, “__MACRO_RESULT=”) in new stack
[2012-01-18 11:34:15] VERBOSE[11355] pbx.c: – Executing [s@macro-auto-blkvm:2] NoOp(“SIP/723-00000239”, "Deleting: BLKVM/779/SIP/4-PSTN-00000233 ") in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/713-00000238”, “hangupcall”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/713-00000238”, “1?skiprg”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,4)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/713-00000238”, “1?skipblkvm”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,7)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/713-00000238”, “1?theend”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,9)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/713-00000238”, “”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/713-00000238’ in macro ‘hangupcall’
[2012-01-18 11:34:22] VERBOSE[11346] res_musiconhold.c: – Stopped music on hold on SIP/4-PSTN-00000233
[2012-01-18 11:34:22] VERBOSE[11346] file.c: – <Local/723@from-internal-xfer-5f0d;1> Playing ‘beep.ulaw’ (language ‘es’)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [h@macro-dial:1] Macro(“Transfered/SIP/4-PSTN-00000233”, “hangupcall”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skiprg”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,4)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?skipblkvm”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,7)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“Transfered/SIP/4-PSTN-00000233”, “1?theend”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Goto (macro-hangupcall,s,9)
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“Transfered/SIP/4-PSTN-00000233”, “”) in new stack
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘hangupcall’
[2012-01-18 11:34:22] VERBOSE[11346] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’ in macro ‘dial’
[2012-01-18 11:34:22] VERBOSE[11346] pbx.c: == Spawn extension (ext-group, 779, 14) exited non-zero on ‘Transfered/SIP/4-PSTN-00000233’
[2012-01-18 11:36:01] VERBOSE[4604] asterisk.c: – Remote UNIX connection
[2012-01-18 11:36:01] VERBOSE[11397] asterisk.c: – Remote UNIX connection disconnected

cosmicwombat · February 4, 2012, 6:49pm

Looks funky. What part does “telefonica” play in this ? Also, what kind of install is this ?

1st ring group is hitting one ext and this looks ok:
2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – Called 713
[2012-01-18 11:33:00] VERBOSE[11346] app_dial.c: – SIP/713-00000234 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – Nobody picked up in 8000 ms

Second ring group shows ringing four ext, with 713 the analog answering it:
2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/713-00000238 is ringing
[2012-01-18 11:33:09] VERBOSE[11346] app_dial.c: – SIP/708-00000235 is ringing
[2012-01-18 11:33:10] VERBOSE[11346] app_dial.c: – SIP/718-00000236 is ringing
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 connected line has changed. Saving it until answer for SIP/4-PSTN-00000233
[2012-01-18 11:33:15] VERBOSE[11346] app_dial.c: – SIP/713-00000238 answered SIP/4-PSTN-00000233

So, yes 713 would ring twice. I think the timeout of ring group one could be the issue. Try making it more like 24 seconds and see if that helps.

I also wonder if the FXO and FXS are both at port 5060. If they are you might want to put one of them at 5061.

f3d3 · February 4, 2012, 7:28pm

Sorry, Telefonica=PSTN, I changed the names in the log for clarity and forgot that line.

FXO & FXS are on different ports (5061 & 5060).

713 ringing twice is normal, however, 711 being able to pickup at the same time and both being able to listen to the caller is the real problem. I will try with 24 seconds see if it fixes the issue.

Thanks a lot!

f3d3 · February 4, 2012, 8:05pm

ext 718 is an extension on the Siemens phones which rings several of them (including 711), this was done to overcome a bug in the Siemens phone.

What I find weird is the CDR:

32. 2012-01-18 11:32:55 SIP/4-PSTN… 627617XXX “(N/A)” <627617XXX> s SIP/713-00… ANSWERED 08:59

33. 2012-01-18 11:32:55 SIP/4-PSTN… 627617XXX “(N/A)” <627617XXX> 779 SIP/713-00… ANSWERED 01:27

Thanks again

Weird behavior incoming call rings twice, heard on two extensions

2012-01-18 11:32:55 SIP/4-PSTN… 627617XXX "(N/A)" <627617XXX> 779 SIP/713-00… ANSWERED 01:27

2012-01-18 11:32:55 SIP/4-PSTN… 627617XXX "(N/A)" <627617XXX> 779 SIP/713-00… ANSWERED 01:27

2012-01-18 11:32:55 SIP/4-PSTN… 627617XXX "(N/A)" <627617XXX> 779 SIP/713-00… ANSWERED 01:27

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27

2012-01-18 11:32:55
SIP/4-PSTN…
627617XXX
"(N/A)" <627617XXX>
779
SIP/713-00…
ANSWERED
01:27