[asterisk-users] channel stay up when extension unreachable

[Anton Raharja]

Hi,

We are using asterisk 1.4.34, ubuntu 10.4, below is suspicious activity
recorded in our full log. Could you help us to explain what had
happened. Thanks.

=== my friend, 801, from his room did a test by dialing echo test in
freepbx, *43:

[Aug 20 14:42:46] VERBOSE[14427] logger.c:     -- Executing
[*43 at from-internal:1] Answer("SIP/801-000003f5", "") in new stack
[Aug 20 14:42:46] VERBOSE[14427] logger.c:     -- Executing
[*43 at from-internal:2] Wait("SIP/801-000003f5", "1") in new stack
[Aug 20 14:42:47] VERBOSE[14427] logger.c:     -- Executing
[*43 at from-internal:3] Playback("SIP/801-000003f5", "demo-echotest") in
new stack
[Aug 20 14:42:47] VERBOSE[14427] logger.c:     -- <SIP/801-000003f5>
Playing 'demo-echotest' (language 'en')
[Aug 20 14:43:07] VERBOSE[14427] logger.c:     -- Executing
[*43 at from-internal:4] Echo("SIP/801-000003f5", "") in new stack

=== electricity down in 801's room and 801 became unreachable:

[Aug 20 14:46:45] NOTICE[8052] chan_sip.c: Peer '801' is now
UNREACHABLE!  Last qualify: 7

=== after 25 minutes power restored and 801 re-registered. 801 continue
testing, dialed several other destinations, also dialed *43 several
times. He didn't noticed any suspicious log and didn't bother to check
it coz 801 worked, calls were made and seems to be completed normally.

[Aug 20 15:13:04] VERBOSE[8052] logger.c:     -- Registered SIP '801' at
xxx.xxx.xxx.xxx port 1806
[Aug 20 15:13:04] VERBOSE[8052] logger.c:     -- Saved useragent "X-Lite
release 1104o stamp 56125" for peer 801
[Aug 20 15:13:04] NOTICE[8052] chan_sip.c: Peer '801' is now Reachable.
(17ms / 2000ms)

=== tonight, in our server, I noticed that I have a channel associated
with 801 elapsed for at least 81 hours after a "core show channels",
while theres no way 801 still available or making that call

=== later on after soft hangup:

[Aug 23 23:52:01] VERBOSE[14427] logger.c:   == Spawn extension
(from-internal, *43, 4) exited non-zero on 'SIP/801-000003f5'
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[h at from-internal:1] Macro("SIP/801-000003f5", "hangupcall") in new stack
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:1] ResetCDR("SIP/801-000003f5", "w") in new stack
[Aug 23 23:52:01] DEBUG[14427] app_macro.c: Executed application: ResetCDR
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:2] NoCDR("SIP/801-000003f5", "") in new stack
[Aug 23 23:52:01] DEBUG[14427] app_macro.c: Executed application: NoCDR
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:3] GotoIf("SIP/801-000003f5", "1?skiprg") in new stack
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Goto
(macro-hangupcall,s,6)
[Aug 23 23:52:01] DEBUG[14427] app_macro.c: Executed application: GotoIf
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:6] GotoIf("SIP/801-000003f5", "1?skipblkvm") in new
stack
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Goto
(macro-hangupcall,s,9)
[Aug 23 23:52:01] DEBUG[14427] app_macro.c: Executed application: GotoIf
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:9] GotoIf("SIP/801-000003f5", "1?theend") in new stack
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Goto
(macro-hangupcall,s,11)
[Aug 23 23:52:01] DEBUG[14427] app_macro.c: Executed application: GotoIf
[Aug 23 23:52:01] VERBOSE[14427] logger.c:     -- Executing
[s at macro-hangupcall:11] Hangup("SIP/801-000003f5", "") in new stack
[Aug 23 23:52:01] VERBOSE[14427] logger.c:   == Spawn extension
(macro-hangupcall, s, 11) exited non-zero on 'SIP/801-000003f5' in macro
'hangupcall'
[Aug 23 23:52:01] VERBOSE[14427] logger.c:   == Spawn extension
(from-internal, h, 1) exited non-zero on 'SIP/801-000003f5'

anton