CASE 3: Channel sleeps CLI: 3455923361 Channel: Zap/218-1 [Jan 13 19:27:10] VERBOSE[4557] logger.c: -- Accepting call from '3455923361' to '4554900444' on channel 0/1, span 9 [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [4554900444@default:1] Set("Zap/218-1", "__DEST=444") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [4554900444@default:2] SetCDRUserField("Zap/218-1", "444") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [4554900444@default:3] Goto("Zap/218-1", "MUSIC_STATION1|s|1") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Goto (MUSIC_STATION1,s,1) [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:1] Answer("Zap/218-1", "") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:2] Set("Zap/218-1", "__DB_USER_ID=1200234430") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:3] Set("Zap/218-1", "__DB_CLI=3455923361") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:4] Playback("Zap/218-1", "/efclub/prompts/music/music_welcome") in new stack [Jan 13 19:27:10] VERBOSE[9821] logger.c: -- Playing '/efclub/prompts/music/music_welcome' (language 'en') >>>>>>> the channel seems to go into sleep mode, the user has initiated several new calls, no sound is played (in new calls) [Jan 13 19:27:58] VERBOSE[4555] logger.c: -- Accepting call from '3455923361' to '4554900444' on channel 0/15, span 7 [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [4554900444@default:1] Set("Zap/170-1", "__DEST=444") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [4554900444@default:2] SetCDRUserField("Zap/170-1", "444") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [4554900444@default:3] Goto("Zap/170-1", "MUSIC_STATION1|s|1") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Goto (MUSIC_STATION1,s,1) [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [s@MUSIC_STATION1:1] Answer("Zap/170-1", "") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [s@MUSIC_STATION1:2] Set("Zap/170-1", "__DB_USER_ID=1200234478") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [s@MUSIC_STATION1:3] Set("Zap/170-1", "__DB_CLI=3455923361") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Executing [s@MUSIC_STATION1:4] Playback("Zap/170-1", "/efclub/prompts/music/music_welcome") in new stack [Jan 13 19:27:58] VERBOSE[9953] logger.c: -- Playing '/efclub/prompts/music/music_welcome' (language 'en') [Jan 13 19:28:04] VERBOSE[4555] logger.c: -- Channel 0/15, span 7 got hangup request, cause 16 [Jan 13 19:28:04] VERBOSE[9953] logger.c: == Spawn extension (MUSIC_STATION1, s, 4) exited non-zero on 'Zap/170-1' [Jan 13 19:28:04] DEBUG[9953] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/170-1 [Jan 13 19:28:04] DEBUG[9953] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 13 19:28:04] DEBUG[9953] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/170-1 [Jan 13 19:28:04] VERBOSE[9953] logger.c: -- Hungup 'Zap/170-1' [Jan 13 19:28:10] VERBOSE[4557] logger.c: -- Accepting call from '3455923361' to '45549007775' on channel 0/25, span 9 [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [45549007775@default:1] Set("Zap/242-1", "__DEST=7775") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [45549007775@default:2] SetCDRUserField("Zap/242-1", "7775") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [45549007775@default:3] Goto("Zap/242-1", "TEL_AKHBAR|s|1") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Goto (TEL_AKHBAR,s,1) [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:1] Answer("Zap/242-1", "") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:2] Set("Zap/242-1", "__PLAN=/efclub") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:3] Set("Zap/242-1", "__PROMPTS=/efclub/prompts") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:4] Set("Zap/242-1", "__RECORDINGS=/efclub/recordings") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:5] Set("Zap/242-1", "__RECORD_FILE_NAME=na") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:6] Set("Zap/242-1", "__MAIN_CNTXT=TEL_AKHBAR") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:7] Set("Zap/242-1", "__MAIN_EXT=s") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:8] Set("Zap/242-1", "__MAIN_PRI=start") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:9] Set("Zap/242-1", "__PREV_EXT=s") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:10] Set("Zap/242-1", "__PREV_PRI=start") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:11] Set("Zap/242-1", "__CALL_CNTXT=TEL_AKHBAR") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:12] Set("Zap/242-1", "__CALL_PRI=start") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:13] Set("Zap/242-1", "__CALL_EXT=s") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:14] Set("Zap/242-1", "__WAIT_EXTEN=0") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:15] Set("Zap/242-1", "__DB_USER_ID=1200234490") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:16] Set("Zap/242-1", "__DB_CLI=3455923361") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Executing [s@TEL_AKHBAR:17] Playback("Zap/242-1", "/efclub/prompts/akhbar/welcome") in new stack [Jan 13 19:28:10] VERBOSE[10041] logger.c: -- Playing '/efclub/prompts/akhbar/welcome' (language 'en') [Jan 13 19:28:24] VERBOSE[4557] logger.c: -- Channel 0/25, span 9 got hangup request, cause 16 [Jan 13 19:28:24] VERBOSE[10041] logger.c: == Spawn extension (TEL_AKHBAR, s, 17) exited non-zero on 'Zap/242-1' [Jan 13 19:28:24] DEBUG[10041] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/242-1 [Jan 13 19:28:24] DEBUG[10041] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 13 19:28:24] DEBUG[10041] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/242-1 [Jan 13 19:28:24] VERBOSE[10041] logger.c: -- Hungup 'Zap/242-1' [Jan 13 19:28:29] VERBOSE[4556] logger.c: -- Accepting call from '3455923361' to '4554900444' on channel 0/9, span 8 [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [4554900444@default:1] Set("Zap/195-1", "__DEST=444") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [4554900444@default:2] SetCDRUserField("Zap/195-1", "444") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [4554900444@default:3] Goto("Zap/195-1", "MUSIC_STATION1|s|1") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Goto (MUSIC_STATION1,s,1) [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [s@MUSIC_STATION1:1] Answer("Zap/195-1", "") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [s@MUSIC_STATION1:2] Set("Zap/195-1", "__DB_USER_ID=1200234509") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [s@MUSIC_STATION1:3] Set("Zap/195-1", "__DB_CLI=3455923361") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Executing [s@MUSIC_STATION1:4] Playback("Zap/195-1", "/efclub/prompts/music/music_welcome") in new stack [Jan 13 19:28:29] VERBOSE[10080] logger.c: -- Playing '/efclub/prompts/music/music_welcome' (language 'en') [Jan 13 19:28:36] VERBOSE[4556] logger.c: -- Channel 0/9, span 8 got hangup request, cause 16 [Jan 13 19:28:36] VERBOSE[10080] logger.c: == Spawn extension (MUSIC_STATION1, s, 4) exited non-zero on 'Zap/195-1' [Jan 13 19:28:36] DEBUG[10080] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/195-1 [Jan 13 19:28:36] DEBUG[10080] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 13 19:28:36] DEBUG[10080] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/195-1 [Jan 13 19:28:36] VERBOSE[10080] logger.c: -- Hungup 'Zap/195-1' >>>>>>> there are many events where a call is dropped because the channel is busy eg [Jan 13 19:29:09] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:30:04] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:30:59] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:31:51] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. >>>>>>> and then the original channel wakes up, note that the caller is has already hungup [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:5] Set("Zap/218-1", "__EXPCUST_GIFTED_LIST=0") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:6] Set("Zap/218-1", "__VALID_CUST=no") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:7] Set("Zap/218-1", "__EXP_CUST=no") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:8] Set("Zap/218-1", "__NOT_CUST_NOGT=no") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:9] Set("Zap/218-1", "__NOT_CUST_HVGT=no") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:10] Set("Zap/218-1", "__BALANCE=0") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:11] AGI("Zap/218-1", "regusers.agi|3455923361") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/regusers.agi [Jan 13 19:32:26] VERBOSE[9821] logger.c: regusers.agi|3455923361: hangup callback set............. [Jan 13 19:32:26] VERBOSE[9821] logger.c: regusers.agi|3455923361: .......user cell no is >>>03455923361............. [Jan 13 19:32:26] VERBOSE[9821] logger.c: regusers.agi|3455923361: .........User already Exists................ [Jan 13 19:32:26] VERBOSE[9821] logger.c: regusers.agi|3455923361: .........playliststs User already Exists................ [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- AGI Script regusers.agi completed, returning 0 [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:12] AGI("Zap/218-1", "jbxValidCust.agi|3455923361") in new stack [Jan 13 19:32:26] VERBOSE[9821] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/jbxValidCust.agi [Jan 13 19:32:27] VERBOSE[9821] logger.c: jbxValidCust.agi|3455923361: ......Valid Customer and balance is 1000000000........ [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- AGI Script jbxValidCust.agi completed, returning 0 [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@MUSIC_STATION1:13] ExecIf("Zap/218-1", "1|Goto|VALID_CUSTOMER|s|1") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Goto (VALID_CUSTOMER,s,1) [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:1] Answer("Zap/218-1", "") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:2] Set("Zap/218-1", "__PLAN=/efclub") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:3] Set("Zap/218-1", "__PROMPTS=/efclub/prompts/music") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:4] Set("Zap/218-1", "__RECORDINGS=/efclub/recordings/music") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:5] Set("Zap/218-1", "__MAIN_CNTXT=VALID_CUSTOMER") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:6] Set("Zap/218-1", "__PREV_CNTXT=VALID_CUSTOMER") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:7] Set("Zap/218-1", "__ERR_CNTXT=VALID_CUSTOMER") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:8] Set("Zap/218-1", "__MAIN_EXT=s") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:9] Set("Zap/218-1", "__PREV_EXT=s") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:10] Set("Zap/218-1", "__ERR_EXT=s") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:11] Set("Zap/218-1", "__MAIN_PRI=start") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:12] Set("Zap/218-1", "__PREV_PRI=start") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:13] Set("Zap/218-1", "__ERR_PRI=menu") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:14] Set("Zap/218-1", "__ERR_COUNT=0") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:15] Set("Zap/218-1", "__MENU_COUNT=0") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:16] UserEvent("Zap/218-1", "SubscriberConnected|subChannel: Zap/218-1|cli: 3455923361") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:17] UserEvent("Zap/218-1", "SubscriberStart|subChannel: Zap/218-1|timeout: 1000000000") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:18] BackGround("Zap/218-1", "/efclub/prompts/music/music_menu") in new stack [Jan 13 19:32:27] VERBOSE[9821] logger.c: -- Playing '/efclub/prompts/music/music_menu' (language 'en') [Jan 13 19:32:41] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:19] Set("Zap/218-1", "__MENU_COUNT=0+1") in new stack [Jan 13 19:32:41] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:20] ExecIf("Zap/218-1", "0|Goto|1|1") in new stack [Jan 13 19:32:41] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:21] BackGround("Zap/218-1", "silence/2") in new stack [Jan 13 19:32:41] VERBOSE[9821] logger.c: -- Playing 'silence/2' (language 'en') [Jan 13 19:32:43] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:22] BackGround("Zap/218-1", "/efclub/prompts/music/idle_cond") in new stack [Jan 13 19:32:43] VERBOSE[9821] logger.c: -- Playing '/efclub/prompts/music/idle_cond' (language 'en') >>>>>>> and here is another event where a call is dropped because the channel is busy [Jan 13 19:32:45] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:32:50] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:23] Goto("Zap/218-1", "menu") in new stack [Jan 13 19:32:50] VERBOSE[9821] logger.c: -- Goto (VALID_CUSTOMER,s,18) [Jan 13 19:32:50] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:18] BackGround("Zap/218-1", "/efclub/prompts/music/music_menu") in new stack [Jan 13 19:32:50] VERBOSE[9821] logger.c: -- Playing '/efclub/prompts/music/music_menu' (language 'en') [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:19] Set("Zap/218-1", "__MENU_COUNT=0+1+1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@VALID_CUSTOMER:20] ExecIf("Zap/218-1", "1|Goto|1|1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Goto (VALID_CUSTOMER,1,1) [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [1@VALID_CUSTOMER:1] Set("Zap/218-1", "__VALID_CUSTOMER=1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [1@VALID_CUSTOMER:2] ResetCDR("Zap/218-1", "w") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [1@VALID_CUSTOMER:3] SetCDRUserField("Zap/218-1", "444-MOBILE_RADIO") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [1@VALID_CUSTOMER:4] Goto("Zap/218-1", "MOBILE_RADIO|s|1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Goto (MOBILE_RADIO,s,1) [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:1] Answer("Zap/218-1", "") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:2] Set("Zap/218-1", "__PLAN=/efclub") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:3] Set("Zap/218-1", "__PROMPTS=/efclub/prompts/music/radio") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:4] Set("Zap/218-1", "__RECORDINGS=/efclub/recordings/music/radio") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:5] Set("Zap/218-1", "__MAIN_CNTXT=MUSIC_STATION1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:6] Set("Zap/218-1", "__PREV_CNTXT=MUSIC_STATION1") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:7] Set("Zap/218-1", "__MAIN_EXT=s") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:8] Set("Zap/218-1", "__PREV_EXT=s") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:9] Set("Zap/218-1", "__MAIN_PRI=start") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:10] Set("Zap/218-1", "__PREV_PRI=start") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:11] BackGround("Zap/218-1", "/efclub/prompts/music/radio/radio_menu") in new stack [Jan 13 19:33:04] VERBOSE[9821] logger.c: -- Playing '/efclub/prompts/music/radio/radio_menu' (language 'en') [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@MOBILE_RADIO:12] Goto("Zap/218-1", "RADIO_ROOM|s|start") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Goto (RADIO_ROOM,s,1) [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:1] Answer("Zap/218-1", "") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:2] Set("Zap/218-1", "__MAIN_CNTXT=MUSIC_STATION1") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:3] Set("Zap/218-1", "__PREV_CNTXT=MUSIC_STATION1") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:4] Set("Zap/218-1", "__MAIN_EXT=s") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:5] Set("Zap/218-1", "__PREV_EXT=s") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:6] Set("Zap/218-1", "__MAIN_PRI=start") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:7] Set("Zap/218-1", "__PREV_PRI=start") in new stack [Jan 13 19:33:17] VERBOSE[9821] logger.c: -- Executing [s@RADIO_ROOM:8] MeetMe("Zap/218-1", "100|mqXM1|mute") in new stack [Jan 13 19:33:17] DEBUG[9821] app_meetme.c: Placed channel Zap/218-1 in ZAP conf 1023 >>>>>>> there are many events where a call is dropped because the channel is busy eg [Jan 13 19:33:39] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:34:30] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:35:25] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. [Jan 13 19:36:02] DEBUG[4557] chan_zap.c: Ring requested on channel 0/1 already in use or previously requested on span 9. Attempting to renegotiating channel. >>>>>>> meanwhile the user has made a new call [Jan 13 19:36:10] VERBOSE[4553] logger.c: -- Accepting call from '3455923361' to '4554900444' on channel 0/10, span 5 [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [4554900444@default:1] Set("Zap/103-1", "__DEST=444") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [4554900444@default:2] SetCDRUserField("Zap/103-1", "444") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [4554900444@default:3] Goto("Zap/103-1", "MUSIC_STATION1|s|1") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Goto (MUSIC_STATION1,s,1) [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [s@MUSIC_STATION1:1] Answer("Zap/103-1", "") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [s@MUSIC_STATION1:2] Set("Zap/103-1", "__DB_USER_ID=1200234970") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [s@MUSIC_STATION1:3] Set("Zap/103-1", "__DB_CLI=3455923361") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Executing [s@MUSIC_STATION1:4] Playback("Zap/103-1", "/efclub/prompts/music/music_welcome") in new stack [Jan 13 19:36:10] VERBOSE[11828] logger.c: -- Playing '/efclub/prompts/music/music_welcome' (language 'en') [Jan 13 19:36:55] VERBOSE[4553] logger.c: -- Channel 0/10, span 5 got hangup request, cause 16 [Jan 13 19:36:55] VERBOSE[11828] logger.c: == Spawn extension (MUSIC_STATION1, s, 4) exited non-zero on 'Zap/103-1' [Jan 13 19:36:55] DEBUG[11828] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/103-1 [Jan 13 19:36:55] DEBUG[11828] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 13 19:36:55] DEBUG[11828] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/103-1 [Jan 13 19:36:55] VERBOSE[11828] logger.c: -- Hungup 'Zap/103-1' >>>>>>> the channel is cleared only when asterisk is restarted [Jan 13 19:47:18] VERBOSE[9821] logger.c: == Spawn extension (RADIO_ROOM, s, 8) exited non-zero on 'Zap/218-1' [Jan 13 19:47:18] DEBUG[9821] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/218-1 [Jan 13 19:47:18] DEBUG[9821] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 13 19:47:18] DEBUG[9821] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/218-1 [Jan 13 19:47:18] VERBOSE[9821] logger.c: -- Hungup 'Zap/218-1'